Emacs in CVS plus GTK patches hogs CPU

Emacs in CVS plus GTK patches hogs CPU

[Simon Josefsson]

I've been using the #2 GTK patch for several days with some heavy use,
and this is my first problem.  I'm not positive it is GTK related.

Emacs is unresponsive to C-g and consumes all CPU.  Attaching with gdb
and breaking alternatively generates two different backtraces (see
below).  At the time I was reading mail from a IMAP group using Gnus
(i.e., likely both network activity and keyboard activity).

I'll keep the process running if someone has any ideas what to
investigate.

(gdb) c
Continuing.

Program received signal SIGINT, Interrupt.
0x0815b21f in wait_reading_process_input (time_limit=0, microsecs=0,
    read_kbd=268435455, do_display=1) at process.c:4259
4259                }
(gdb) bt
#0  0x0815b21f in wait_reading_process_input (time_limit=0, microsecs=0,
    read_kbd=268435455, do_display=1) at process.c:4259
#1  0x080db18c in kbd_buffer_get_event (kbp=0xbffff450,
    used_mouse_menu=0xbffff670) at keyboard.c:3750
#2  0x080d9b86 in read_char (commandflag=1, nmaps=5, maps=0xbffff614,
    prev_event=405433596, used_mouse_menu=0xbffff670) at keyboard.c:2720
#3  0x080e0140 in read_key_sequence (keybuf=0xbffff774, bufsize=30,
    prompt=405433596, dont_downcase_last=0, can_return_switch_frame=1,
    fix_current_buffer=1) at keyboard.c:8508
#4  0x080d7a88 in command_loop_1 () at keyboard.c:1473
#5  0x0812c079 in internal_condition_case (bfun=0x80d7780 <command_loop_1>,
    handlers=405530204, hfun=0x80d7394 <cmd_error>) at eval.c:1352
#6  0x080d7658 in command_loop_2 () at keyboard.c:1274
#7  0x0812bc0d in internal_catch (tag=405491508,
    func=0x80d7634 <command_loop_2>, arg=405433596) at eval.c:1112
#8  0x080d7603 in command_loop () at keyboard.c:1253
#9  0x080d7150 in recursive_edit_1 () at keyboard.c:969
#10 0x080d7280 in Frecursive_edit () at keyboard.c:1025
#11 0x080d6113 in main (argc=1, argv=0xbffffd44) at emacs.c:1647
(gdb) c
Continuing.

Program received signal SIGINT, Interrupt.
0x4066d7ee in select () from /lib/libc.so.6
(gdb) bt
#0  0x4066d7ee in select () from /lib/libc.so.6
#1  0xbffff23c in ?? ()
#2  0x080db18c in kbd_buffer_get_event (kbp=0xbffff450,
    used_mouse_menu=0xbffff670) at keyboard.c:3750
#3  0x080d9b86 in read_char (commandflag=1, nmaps=5, maps=0xbffff614,
    prev_event=405433596, used_mouse_menu=0xbffff670) at keyboard.c:2720
#4  0x080e0140 in read_key_sequence (keybuf=0xbffff774, bufsize=30,
    prompt=405433596, dont_downcase_last=0, can_return_switch_frame=1,
    fix_current_buffer=1) at keyboard.c:8508
#5  0x080d7a88 in command_loop_1 () at keyboard.c:1473
#6  0x0812c079 in internal_condition_case (bfun=0x80d7780 <command_loop_1>,
    handlers=405530204, hfun=0x80d7394 <cmd_error>) at eval.c:1352
#7  0x080d7658 in command_loop_2 () at keyboard.c:1274
#8  0x0812bc0d in internal_catch (tag=405491508,
    func=0x80d7634 <command_loop_2>, arg=405433596) at eval.c:1112
#9  0x080d7603 in command_loop () at keyboard.c:1253
#10 0x080d7150 in recursive_edit_1 () at keyboard.c:969
#11 0x080d7280 in Frecursive_edit () at keyboard.c:1025
#12 0x080d6113 in main (argc=1, argv=0xbffffd44) at emacs.c:1647
(gdb)

Re: Emacs in CVS plus GTK patches hogs CPU

[Jan D.]

> I've been using the #2 GTK patch for several days with some heavy use,
> and this is my first problem.  I'm not positive it is GTK related.
> 
> Emacs is unresponsive to C-g and consumes all CPU.  Attaching with gdb
> and breaking alternatively generates two different backtraces (see
> below).  At the time I was reading mail from a IMAP group using Gnus
> (i.e., likely both network activity and keyboard activity).
> 
> I'll keep the process running if someone has any ideas what to
> investigate.

I have Motif and GTK versions running side by side, the GTK version
actually takes *less* CPU for me.

Can you strace or truss the Emacs process to see if is in some sort of busy
wait?  A very short timeout perhaps?

	Jan D.

Re: Emacs in CVS plus GTK patches hogs CPU

[Simon Josefsson]

"Jan D." <jan.h.d@swipnet.se> writes:

>> I've been using the #2 GTK patch for several days with some heavy use,
>> and this is my first problem.  I'm not positive it is GTK related.
>> 
>> Emacs is unresponsive to C-g and consumes all CPU.  Attaching with gdb
>> and breaking alternatively generates two different backtraces (see
>> below).  At the time I was reading mail from a IMAP group using Gnus
>> (i.e., likely both network activity and keyboard activity).
>> 
>> I'll keep the process running if someone has any ideas what to
>> investigate.
>
> I have Motif and GTK versions running side by side, the GTK version
> actually takes *less* CPU for me.

Yes, normally I have no problems, but this emacs instance is
completely lost in a busy wait.  No redisplay, C-g doesn't work.

> Can you strace or truss the Emacs process to see if is in some sort of busy
> wait?  A very short timeout perhaps?

Yes, it is a busy wait:

...
kill(17005, SIGIO)                      = 0
gettimeofday({1042058269, 284790}, NULL) = 0
select(8, [3 7], NULL, NULL, {0, 451252}) = 1 (in [7], left {0, 453096})
gettimeofday({1042058269, 284976}, NULL) = 0
getpid()                                = 17005
kill(17005, SIGIO)                      = 0
gettimeofday({1042058269, 285079}, NULL) = 0
select(8, [3 7], NULL, NULL, {0, 450963}) = 1 (in [7], left {0, 451143})
gettimeofday({1042058269, 285265}, NULL) = 0
getpid()                                = 17005
kill(17005, SIGIO)                      = 0
gettimeofday({1042058269, 285368}, NULL) = 0
select(8, [3 7], NULL, NULL, {0, 450674}) = 1 (in [7], left {0, 451143})
gettimeofday({1042058269, 285554}, NULL) = 0
...

This doesn't look GTK related, but rather network process related,
though.  Hm.  17005 is the pid of the emacs process itself.  Does GTK
catch SIGIO or something?

Re: Emacs in CVS plus GTK patches hogs CPU

[Jan D.]

> 
> "Jan D." <jan.h.d@swipnet.se> writes:
> 
> > Can you strace or truss the Emacs process to see if is in some sort of busy
> > wait?  A very short timeout perhaps?
> 
> Yes, it is a busy wait:
> 
> ...
> kill(17005, SIGIO)                      = 0
> gettimeofday({1042058269, 284790}, NULL) = 0
> select(8, [3 7], NULL, NULL, {0, 451252}) = 1 (in [7], left {0, 453096})
> gettimeofday({1042058269, 284976}, NULL) = 0
> getpid()                                = 17005
> kill(17005, SIGIO)                      = 0
> gettimeofday({1042058269, 285079}, NULL) = 0
> select(8, [3 7], NULL, NULL, {0, 450963}) = 1 (in [7], left {0, 451143})
> gettimeofday({1042058269, 285265}, NULL) = 0
> getpid()                                = 17005
> kill(17005, SIGIO)                      = 0
> gettimeofday({1042058269, 285368}, NULL) = 0
> select(8, [3 7], NULL, NULL, {0, 450674}) = 1 (in [7], left {0, 451143})
> gettimeofday({1042058269, 285554}, NULL) = 0
> 
> This doesn't look GTK related, but rather network process related,
> though.  Hm.  17005 is the pid of the emacs process itself.  Does GTK
> catch SIGIO or something?

I could not find anything in the GTK source.  This looks like fd 7 is ready
for reading everytime select is called and then select returns immediately.
The X connection is usually a very low fd, 3 or 4 so I guess 3 is the
X connection and 7 is some network connection that for example Gnus
has open.  Could it be that Gnus/Emacs doesn't read from it or
perhaps it is closed at the other side, but Gnus/Emacs does not close
this side?  As seen above, there is no read between the selects even though
7 clearly is readable.

You could try to start emacs, and strace it to see if this other fd 7
is opened with Gnus or something else.

	Jan D.

Re: Emacs in CVS plus GTK patches hogs CPU

[Simon Josefsson]

"Jan D." <jan.h.d@swipnet.se> writes:

>> 
>> "Jan D." <jan.h.d@swipnet.se> writes:
>> 
>> > Can you strace or truss the Emacs process to see if is in some sort of busy
>> > wait?  A very short timeout perhaps?
>> 
>> Yes, it is a busy wait:
>> 
>> ...
>> kill(17005, SIGIO)                      = 0
>> gettimeofday({1042058269, 284790}, NULL) = 0
>> select(8, [3 7], NULL, NULL, {0, 451252}) = 1 (in [7], left {0, 453096})
>> gettimeofday({1042058269, 284976}, NULL) = 0
>> getpid()                                = 17005
>> kill(17005, SIGIO)                      = 0
>> gettimeofday({1042058269, 285079}, NULL) = 0
>> select(8, [3 7], NULL, NULL, {0, 450963}) = 1 (in [7], left {0, 451143})
>> gettimeofday({1042058269, 285265}, NULL) = 0
>> getpid()                                = 17005
>> kill(17005, SIGIO)                      = 0
>> gettimeofday({1042058269, 285368}, NULL) = 0
>> select(8, [3 7], NULL, NULL, {0, 450674}) = 1 (in [7], left {0, 451143})
>> gettimeofday({1042058269, 285554}, NULL) = 0
>> 
>> This doesn't look GTK related, but rather network process related,
>> though.  Hm.  17005 is the pid of the emacs process itself.  Does GTK
>> catch SIGIO or something?
>
> I could not find anything in the GTK source.  This looks like fd 7 is ready
> for reading everytime select is called and then select returns immediately.
> The X connection is usually a very low fd, 3 or 4 so I guess 3 is the
> X connection and 7 is some network connection that for example Gnus
> has open.

Yup.

> Could it be that Gnus/Emacs doesn't read from it or perhaps it is
> closed at the other side, but Gnus/Emacs does not close this side?
> As seen above, there is no read between the selects even though 7
> clearly is readable.

The process isn't running elisp any more, so Gnus has no chance to
read from the process.  It is simply inflooping around trying to read
from a (by now likely) dead process.

> You could try to start emacs, and strace it to see if this other fd 7
> is opened with Gnus or something else.

lsof on the emacs process says it is a socket, and it is the last
socket allocated so it most likely Gnus related.

OK, I'm killing the debugger (I did cvs up so source tracing in the
debugger is lost anyway) and forgetting the problem until I see it
again.

Re: Emacs in CVS plus GTK patches hogs CPU

[Richard Stallman]

    Yes, it is a busy wait:
    ...
    kill(17005, SIGIO)                      = 0
    gettimeofday({1042058269, 284790}, NULL) = 0
    select(8, [3 7], NULL, NULL, {0, 451252}) = 1 (in [7], left {0, 453096})

That looks like call trace output.  That rarely gives any useful
information.  How about debugging it as suggested in etc/DEBUG?

Re: Emacs in CVS plus GTK patches hogs CPU

[Simon Josefsson]

Richard Stallman <rms@gnu.org> writes:

>     Yes, it is a busy wait:
>     ...
>     kill(17005, SIGIO)                      = 0
>     gettimeofday({1042058269, 284790}, NULL) = 0
>     select(8, [3 7], NULL, NULL, {0, 451252}) = 1 (in [7], left {0, 453096})
>
> That looks like call trace output.  That rarely gives any useful
> information.  How about debugging it as suggested in etc/DEBUG?

Yes, I will if it happens again (it has only happened once so far).  I
have reverted to non-GTK to make sure it isn't GTK related.

Re: Emacs in CVS plus GTK patches hogs CPU

[Kim F. Storm]

"Jan D." <jan.h.d@swipnet.se> writes:

> > 
> > This doesn't look GTK related, but rather network process related,
> > though.  Hm.  17005 is the pid of the emacs process itself.  Does GTK
> > catch SIGIO or something?

On some systems, you may do "ls -l /proc/17005/fd/7" to see what type of
object fd 7 is.

-- 
Kim F. Storm <storm@cua.dk> http://www.cua.dk