After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 172491 - gdm-binary causes high cpu load
gdm-binary causes high cpu load
Status: RESOLVED FIXED
Product: gdm
Classification: Core
Component: general
2.6.0.x
Other All
: Normal normal
: ---
Assigned To: GDM maintainers
GDM maintainers
Depends on:
Blocks:
 
 
Reported: 2005-04-03 08:19 UTC by Uwe Laverenz
Modified: 2005-05-13 18:06 UTC
See Also:
GNOME target: ---
GNOME version: 2.9/2.10



Description Uwe Laverenz 2005-04-03 08:19:09 UTC
Please describe the problem:
When disconnecting from a remote gdm session, the gdm-binary process causes high
cpu load (100%).

Steps to reproduce:
1. connect to gdm via xdmcp
2. login into remote system
3. logout from remote system


Actual results:
gdm-binary causes high cpu load after logout

Expected results:


Does this happen every time?
yes

Other information:
The system running gdm is a FreeBSD RELENG_5 machine with gnome 2.10 and gdm
2.6.0.8 installed from FreeBSD ports. This behaviour was reported from several
people on the FreeBSD-gnome mailing list.
Comment 1 Brian Cameron 2005-04-12 18:16:03 UTC
Could you turn on "enable=true" in the debug section of your gdm.conf file and
see if any interesting messages get sent to the system messages file, might
highlight why the daemon is spinning.  Also, running trace or truss on the
process might highlight what GDM is doing that is inappropriate.  Do you have
time to look into
this a bit?
Comment 2 Uwe Laverenz 2005-04-14 06:26:56 UTC
Hi Brian,

ok, i turned on debugging in gdm.conf and started a short session from a remote
computer. One more thing: gdm does not start a local X-server, the machine is
running headless. The machine running gdm is "zoot", the remote machine is "animal".

The messages from gdm:

Apr 14 08:17:00 zoot gdm[651]: gdm_xdmcp_decode: Received opcode BROADCAST_QUERY
from client 192.168.12.85
Apr 14 08:17:00 zoot gdm[651]: gdm_xdmcp_handle_query: Opcode 1 from 192.168.12.85
Apr 14 08:17:00 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:00 zoot gdm[651]: gdm_xdmcp_send_willing: Sending WILLING to
192.168.12.85
Apr 14 08:17:02 zoot gdm[651]: gdm_xdmcp_decode: Received opcode BROADCAST_QUERY
from client 192.168.12.85
Apr 14 08:17:02 zoot gdm[651]: gdm_xdmcp_handle_query: Opcode 1 from 192.168.12.85
Apr 14 08:17:02 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:02 zoot gdm[651]: gdm_xdmcp_send_willing: Sending WILLING to
192.168.12.85
Apr 14 08:17:04 zoot gdm[651]: gdm_xdmcp_decode: Received opcode BROADCAST_QUERY
from client 192.168.12.85
Apr 14 08:17:04 zoot gdm[651]: gdm_xdmcp_handle_query: Opcode 1 from 192.168.12.85
Apr 14 08:17:04 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:04 zoot gdm[651]: gdm_xdmcp_send_willing: Sending WILLING to
192.168.12.85
Apr 14 08:17:10 zoot gdm[651]: gdm_xdmcp_decode: Received opcode QUERY from
client 192.168.12.85
Apr 14 08:17:10 zoot gdm[651]: gdm_xdmcp_handle_query: Opcode 2 from 192.168.12.85
Apr 14 08:17:10 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:10 zoot gdm[651]: gdm_xdmcp_send_willing: Sending WILLING to
192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_decode: Received opcode REQUEST from
client 192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_handle_request: Got REQUEST from
192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_handle_request: xdmcp_pending=0,
MaxPending=4, xdmcp_sessions=0, MaxSessions=16, ManufacturerID=
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_display_dispose_check
(animal.molkerei-ammerland.de:0)
Apr 14 08:17:18 zoot gdm[651]: gdm_auth_secure_display: Setting up access for
animal.molkerei-ammerland.de:0
Apr 14 08:17:18 zoot gdm[651]: gdm_auth_secure_display: Setting up access
Apr 14 08:17:18 zoot gdm[651]: gdm_auth_secure_display: Setting up access for
animal.molkerei-ammerland.de:0 - 1 entries
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_display_alloc:
display=animal.molkerei-ammerland.de:0, session id=-427985142, xdmcp_pending=1
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_send_accept: Sending ACCEPT to
192.168.12.85 with SessionID=-427985142
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_decode: Received opcode MANAGE from
client 192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_handle_manage: Got MANAGE from
192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_host_allow: client->hostname is
animal.molkerei-ammerland.de
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_handle_manage: Got Display=0,
SessionID=-427985142 Class=MIT-unspecified from 192.168.12.85
Apr 14 08:17:18 zoot gdm[651]: gdm_xdmcp_handle_manage: Looked up
animal.molkerei-ammerland.de:0
Apr 14 08:17:18 zoot gdm[651]: gdm_choose_indirect_lookup: Host 192.168.12.85
not found
Apr 14 08:17:18 zoot gdm[651]: gdm_forward_query_lookup: Host 192.168.12.85 not
found
Apr 14 08:17:18 zoot gdm[651]: gdm_display_manage: Managing
animal.molkerei-ammerland.de:0
Apr 14 08:17:18 zoot gdm[651]: loop check: last_start 0, last_loop 0, now:
1113459438, retry_count: 0
Apr 14 08:17:18 zoot gdm[651]: Resetting counts for loop of death detection
Apr 14 08:17:18 zoot gdm[651]: gdm_display_manage: Forked slave: 13941
Apr 14 08:17:18 zoot gdm[13941]: gdm_slave_start: Starting slave process for
animal.molkerei-ammerland.de:0
Apr 14 08:17:18 zoot gdm[13941]: gdm_slave_start: Loop Thingie
Apr 14 08:17:18 zoot gdm[13941]: gdm_slave_run: Opening display
animal.molkerei-ammerland.de:0
Apr 14 08:17:19 zoot gdm[13941]: gdm_slave_greeter: Running greeter on
animal.molkerei-ammerland.de:0
Apr 14 08:17:19 zoot gdm[651]: (child 13941) gdm_slave_child_handler
Apr 14 08:17:19 zoot gdm[13941]: gdm_slave_greeter: Greeter on pid 13947
Apr 14 08:17:19 zoot gdm[13941]: Sending GREETPID == 13947 for slave 13941
Apr 14 08:17:19 zoot gdm[13941]: Sending GREETPID 13941 13947
Apr 14 08:17:19 zoot gdm[651]: Handling message: 'GREETPID 13941 13947'
Apr 14 08:17:19 zoot gdm[651]: Got GREETPID == 13947
Apr 14 08:17:19 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:27 zoot gdm[13941]: gdm_slave_wait_for_login: In loop
Apr 14 08:17:33 zoot gdm[13941]: Sending QUERYLOGIN == laverenz for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending QUERYLOGIN 13941 laverenz
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'QUERYLOGIN 13941 laverenz'
Apr 14 08:17:33 zoot gdm[651]: Got QUERYLOGIN laverenz
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[13941]: gdm_slave_wait_for_login: end verify for 'laverenz'
Apr 14 08:17:33 zoot gdm[13941]: gdm_slave_wait_for_login: got_login for 'laverenz'
Apr 14 08:17:33 zoot gdm[13941]: Sending LOGGED_IN == 1 for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending LOGGED_IN 13941 1
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'LOGGED_IN 13941 1'
Apr 14 08:17:33 zoot gdm[651]: Got logged in == TRUE
Apr 14 08:17:33 zoot gdm[13941]: Sending LOGIN == laverenz for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending LOGIN 13941 laverenz
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'LOGIN 13941 laverenz'
Apr 14 08:17:33 zoot gdm[651]: Got LOGIN == laverenz
Apr 14 08:17:33 zoot gdm[13941]: gdm_slave_session_start: Attempting session for
user 'laverenz'
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[13941]: Initial setting: session: 'gnome' language:
'de_DE.UTF-8'
Apr 14 08:17:33 zoot gdm[13941]: gdm_slave_session_start: Authentication
completed. Whacking greeter
Apr 14 08:17:33 zoot gdm[13941]: slave_waitpid: waiting on 13947
Apr 14 08:17:33 zoot gdm[13941]: slave_waitpid: done_waiting
Apr 14 08:17:33 zoot gdm[13941]: Sending GREETPID == 0 for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending GREETPID 13941 0
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_child_handler
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_child_handler: 13947 died
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_child_handler: 13947
returned 0
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'GREETPID 13941 0'
Apr 14 08:17:33 zoot gdm[651]: Got GREETPID == 0
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[13941]: gdm_auth_user_add: Adding cookie for 2001
Apr 14 08:17:33 zoot gdm[13941]: get_local_auths: Setting up network access
Apr 14 08:17:33 zoot gdm[13941]: get_local_auths: Setting up access for
animal.molkerei-ammerland.de:0 - 2 entries
Apr 14 08:17:33 zoot gdm[13941]: gdm_auth_user_add: Using
/home/laverenz/.Xauthority for cookies
Apr 14 08:17:33 zoot gdm[13941]: gdm_auth_purge: animal.molkerei-ammerland.de:0
Apr 14 08:17:33 zoot gdm[13941]: gdm_auth_user_add: Done
Apr 14 08:17:33 zoot gdm[13941]: Sending WRITE_X_SERVERS == 0 for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending WRITE_X_SERVERS 13941 0
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'WRITE_X_SERVERS 13941 0'
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[13941]: Sending SESSPID == 13948 for slave 13941
Apr 14 08:17:33 zoot gdm[13941]: Sending SESSPID 13941 13948
Apr 14 08:17:33 zoot gdm[651]: Handling message: 'SESSPID 13941 13948'
Apr 14 08:17:33 zoot gdm[651]: Got SESSPID == 13948
Apr 14 08:17:33 zoot gdm[13941]: slave_waitpid: waiting on 13948
Apr 14 08:17:33 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:17:33 zoot gdm[13948]: Running /usr/X11R6/etc/gdm/Xsession
gnome-session  for laverenz on animal.molkerei-ammerland.de:0
Apr 14 08:17:34 zoot gdm[651]: (child 13941) gdm_slave_alrm_handler:
animal.molkerei-ammerland.de:0 got ARLM signal, to ping display
Apr 14 08:18:04 zoot last message repeated 2 times
Apr 14 08:18:19 zoot gdm[651]: (child 13941) gdm_slave_alrm_handler:
animal.molkerei-ammerland.de:0 got ARLM signal, to ping display
Apr 14 08:18:31 zoot gdm[651]: gdm_socket_handler: Accepting new connection fd 9
Apr 14 08:18:31 zoot gdm[651]: Handling user message: 'VERSION'
Apr 14 08:18:34 zoot gdm[651]: (child 13941) gdm_slave_alrm_handler:
animal.molkerei-ammerland.de:0 got ARLM signal, to ping display
Apr 14 08:18:35 zoot gdm[651]: gdm_socket_handler: Accepting new connection fd 11
Apr 14 08:18:35 zoot gdm[651]: Handling user message: 'VERSION'
Apr 14 08:18:36 zoot gdm[13941]: slave_waitpid: done_waiting
Apr 14 08:18:36 zoot gdm[13941]: Session: start_time: 1113459453 end_time:
1113459516
Apr 14 08:18:36 zoot gdm[13941]: Sending SESSPID == 0 for slave 13941
Apr 14 08:18:36 zoot gdm[13941]: Sending SESSPID 13941 0
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_child_handler
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_child_handler: 13948 died
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_child_handler: 13948
returned 0
Apr 14 08:18:36 zoot gdm[651]: Handling message: 'SESSPID 13941 0'
Apr 14 08:18:36 zoot gdm[651]: Got SESSPID == 0
Apr 14 08:18:36 zoot gdm[13941]: gdm_slave_session_stop: laverenz on
animal.molkerei-ammerland.de:0
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:18:36 zoot gdm[13941]: gdm_slave_session_stop: Running post session script
Apr 14 08:18:36 zoot gdm[13941]: gdm_auth_user_remove: Removing cookie from
/home/laverenz/.Xauthority (0)
Apr 14 08:18:36 zoot gdm[13941]: gdm_auth_purge: animal.molkerei-ammerland.de:0
Apr 14 08:18:36 zoot gdm[13941]: Running gdm_verify_cleanup and pamh != NULL
Apr 14 08:18:36 zoot gdm[13941]: Running pam_close_session
Apr 14 08:18:36 zoot gdm[13941]: Running pam_setcred with PAM_DELETE_CRED
Apr 14 08:18:36 zoot gdm[13941]: gdm_slave_session_start: Session ended OK (now
all finished)
Apr 14 08:18:36 zoot gdm[13941]: Sending LOGGED_IN == 0 for slave 13941
Apr 14 08:18:36 zoot gdm[13941]: Sending LOGGED_IN 13941 0
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_child_handler
Apr 14 08:18:36 zoot gdm[651]: Handling message: 'LOGGED_IN 13941 0'
Apr 14 08:18:36 zoot gdm[651]: Got logged in == FALSE
Apr 14 08:18:36 zoot gdm[13941]: Sending LOGIN ==  for slave 13941
Apr 14 08:18:36 zoot gdm[13941]: Sending LOGIN 13941
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:18:36 zoot gdm[651]: Handling message: 'LOGIN 13941 '
Apr 14 08:18:36 zoot gdm[651]: Got LOGIN ==
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal
Apr 14 08:18:36 zoot gdm[13941]: Sending XPID == 0 for slave 13941
Apr 14 08:18:36 zoot gdm[13941]: Sending XPID 13941 0
Apr 14 08:18:36 zoot gdm[651]: Handling message: 'XPID 13941 0'
Apr 14 08:18:36 zoot gdm[651]: Got XPID == 0
Apr 14 08:18:36 zoot gdm[13941]: gdm_slave_quick_exit: Will kill everything from
the display
Apr 14 08:18:36 zoot gdm[13941]: gdm_slave_quick_exit: Killed everything from
the display
Apr 14 08:18:36 zoot gdm[651]: mainloop_sig_callback: Got signal 20
Apr 14 08:18:36 zoot gdm[651]: gdm_cleanup_children: child 13941 returned 2
Apr 14 08:18:36 zoot gdm[651]: gdm_child_action: In remanage
Apr 14 08:18:36 zoot gdm[651]: gdm_display_unmanage: Stopping
animal.molkerei-ammerland.de:0 (slave pid: 0)
Apr 14 08:18:36 zoot gdm[651]: gdm_display_dispose: Disposing
animal.molkerei-ammerland.de:0
Apr 14 08:18:36 zoot gdm[651]: gdm_display_unmanage: Display stopped
Apr 14 08:18:36 zoot gdm[651]: (child 13941) gdm_slave_usr2_handler:
animal.molkerei-ammerland.de:0 got USR2 signal


I will try to run trace/truss once I figured out how to use them. :)

Thank you,
Uwe
Comment 3 Uwe Laverenz 2005-04-14 07:05:15 UTC
Hi Brian,

I ran trace and truss on another two sessions (this time from "janice"), I hope
I did it right:

# truss -d -o /var/tmp/gdm_truss -p 14104

and:

# ktrace -i -f /var/tmp/gdm_trace -p 14549

Both files are quite large (truss: 61MB, trace: 190MB), so I compressed them
with bzip2. You could fetch them here:

truss (compressed  5MB): http://www.laverenz.de/gdm_truss.bz2
trace (compressed 15MB): http://www.laverenz.de/gdm_trace.bz2

I hope this is what you wanted.

Thank you,
Uwe
Comment 4 Uwe Laverenz 2005-05-12 11:59:21 UTC
Hi,

Joe Marcus Clarke has posted a fix for this problem in the FreeBSD-Gnome
mailing list:

http://www.marcuscom.com/downloads/patch-daemon_gdm-net.c

Put this into /usr/ports/x11/gdm/files and reinstall the gdm port.

Thank you Joe Marcus!
Comment 5 Joe Marcus Clarke 2005-05-12 13:20:39 UTC
The problem is common to all BSDs and MacOS X.  Upon getting EOF on a socket,
pipe, etc., G_IO_IN is always set, and G_IO_HUP may not be set.  Therefore, the
0 return from read() is important.  Therefore, if we get a length <= 0 from
read(), we force the socket to be closed.
Comment 6 Brian Cameron 2005-05-13 18:06:53 UTC
Fixed in CVS head.