Re: Running two processes rapidly makes Emacs eat 100% CPU on w32

[Slawomir Nowaczyk <slawomir.nowaczyk.847@student.lu.se>]

On Thu, 12 Oct 2006 06:47:19 -0400
Eli Zaretskii <eliz@gnu.org> wrote:

#> > Date: Thu, 12 Oct 2006 10:44:48 +0200
#> > From: Slawomir Nowaczyk <slawomir.nowaczyk.847@student.lu.se>
#> > 
#> > What is the best way to debug such problem?
#> 
#> Try to figure out what happens inside w32proc.c:sys_select would be a
#> beginning, I think. There are already quite a few DebPrint statements
#> in that function; compiling with EMACSDEBUG defined will activate
#> them. You should be able to see the strings emitted by DebPrint with
#> any debugger; or you can install DbgView as a lightweight solution.

Thanks for the advice, I managed to activate DebPrint. I have added one
which prints the return value of w32proc:sys_select, and it is "1"
consistently. None of the DebPrint statements already present in this
function gets executed, neither in normal work nor when Emacs eats all
the CPU.

Your guess that sys_select is to be blamed was likely correct, though,
as (under normal circumstances) my newly added DebPrint executes a
couple of times per second, while after I execute the problematic code,
it gets called thousands of times per second.

There were two DebPrint statements guarded by FULL_DEBUG, but I have
activated those as well. Now the one from line 1175:
		DebPrint (("select waiting on child %d fd %d\n",
			   cp-child_procs, i));
keeps printing "select waiting on child 0 fd 3" (thousands of times per
second, every time sys_select is called.

Anyway, the log of DebPrints looks like this:

return 1                                           ;; this part corresponds to correctly working emacs
return 1
...
return 1                                           ;; there are a couple (1-10) of those per second
return 1
                                                   ;; now I executed (progn (start-process "" nil "ls") (call-process "ls"))
"select waiting on child 0 fd 3"
"select calling SIGCHLD handler for pid 1668"      ;; observe that this line only happens ONCE
return 1                                           
"select waiting on child 0 fd 3"                   ;; and this repeats, thousands of times per second
return 1                                           ;;    I got about 40.000 of those in 7 seconds
"select waiting on child 0 fd 3"
return 1
...
"select waiting on child 0 fd 3"
return 1

#> Once you have this in place, add DebPrint as needed to see what is
#> going on there.

w32proc:sys_select is much too complex for me to understand quickly. I
will try to look at the code and do some more debugging tomorrow evening
if I have time...

In the meantime, if anyone has any ideas as to where would be a good
place to put some DebPrint statements, I would be grateful.

-- 
 Best wishes,
   Slawomir Nowaczyk
     ( slawomir.nowaczyk.847@student.lu.se )

I plan on living forever. So far, so good.