[Pkg-utopia-maintainers] Bug#596721: On kfreebsd, upowerd tries to consume 100% CPU on boot *before* user logs into GNOME.
Michael Dorrington
michael.dorrington at gmail.com
Sat Oct 30 18:00:54 UTC 2010
Package: upower
Version: 0.9.5-3
Severity: normal
On kfreebsd, on some boots of my kvm system, upowerd tries to consume
100% CPU on boot *before* the user logs into GNOME. This does not happen
on every boot on my kvm system, only about 1 in 3. I think this is the
same issue as #596721.
After the correct user details have been entered into the gdm3 login,
but before the desktop is displayed, a pop up window (see attached file
kfreebsd_upowerd_warning_during_login.ppm.bz2) appears saying:
A program is still running:
Power Manager
Not responding
Waiting for the program to finish. Interrupting
the program may cause you to lose work.
[ Lock Screen ] [ Cancel ] [Log Out Anyway]
It is strange having the "Log Out Anyway" button because the user is not
in the process of logging out.
> Which desktop are you using?
GNOME from tasksel.
> Do you login via gdm or startx?
Login via gdm3.
> do you have policykit-1-gnome installed?
Yes.
# dpkg-query --show policykit-1-gnome
policykit-1-gnome 0.96-2
> Is polkit-gnome-authentication-agent-1 running?
Yes.
# ps -flww -C polkit-gnome-authentication-agent-1
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 S mcd 1073 967 0 188 - - 5578 - 16:59 ? 00:00:00 /usr/lib/policykit-1-gnome/polkit-gnome-authentication-agent-1
0 S 105 800 1 0 188 - - 5444 - 16:58 ? 00:00:00 /usr/lib/policykit-1-gnome/polkit-gnome-authentication-agent-1
Debugging using gdb and ktrace (in place of strace):
# ps -flw -C upowerd
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 R root 859 1 88 261 - - 1257 - 16:58 ? 00:04:16 /usr/lib/upower/upowerd
# apt-get install zlib1g-dbg libc0.1-dbg libdbus-glib-1-2-dbg libglib2.0-0-dbg libglib2.0-0-refdbg libdbus-glib-1-2-dbg python-dbus-dbg dbus-1-dbg libframeworkd-glib-20100512-dbg libfso-glib-dbg libhildonmime0-dbg python-qt4-dbus-dbg libc0.1-dbg libglib2.0-0-dbg libpcre3-dbg
[snip]
# gdb
[snip]
(gdb) set logging file gdb-upowerd.txt
(gdb) set logging on
Copying output to gdb-upowerd.txt.
(gdb) handle SIG33 pass nostop noprint
Signal Stop Print Pass to program Description
SIG33 No No Yes Real-time event 33
(gdb) set pagination 0
(gdb) attach 859
[snipped, see attached gdb-upowerd.txt]
(gdb) backtrace
#0 0x282e6907 in gettimeofday () at ../sysdeps/unix/syscall-template.S:82
#1 0x2812f813 in _dbus_get_current_time (tv_sec=0xbfbfe6f4, tv_usec=0xbfbfe6f0) at dbus-sysdeps-unix.c:2060
#2 0x28112a2f in _dbus_connection_block_pending_call (pending=0x80722f8) at dbus-connection.c:2367
#3 0x28120301 in dbus_pending_call_block (pending=0x0) at dbus-pending-call.c:705
#4 0x283a757b in egg_dbus_connection_pending_call_block () from /usr/lib/libeggdbus-1.so.0
#5 0x280be471 in polkit_authority_check_authorization_sync () from /usr/lib/libpolkit-gobject-1.so.0
#6 0x0804da76 in ?? ()
#7 0x0804e6e2 in ?? ()
#8 0x28169248 in IA__g_cclosure_marshal_VOID__POINTER (closure=0xbfbfe9b0, return_value=0x0, n_param_values=2, param_values=0x806c5a0, invocation_hint=0x0, marshal_data=0x8074020) at /build/buildd-glib2.0_2.24.2-1-kfreebsd-i386-CLgKW4/glib2.0-2.24.2/gobject/gmarshal.c:601
#9 0x280ef5dc in invoke_object_method (connection=0x8067588, message=0x80677b0, user_data=0x8066820) at dbus-gobject.c:1724
#10 object_registration_message (connection=0x8067588, message=0x80677b0, user_data=0x8066820) at dbus-gobject.c:1944
#11 0x2811f833 in _dbus_object_tree_dispatch_and_unlock (tree=0x8067340, message=0x80677b0) at dbus-object-tree.c:856
#12 0x2811247c in dbus_connection_dispatch (connection=0x8067588) at dbus-connection.c:4492
#13 0x280eb21d in message_queue_dispatch (source=0x8068ec0, callback=0, user_data=0x0) at dbus-gmain.c:101
#14 0x281cb415 in g_main_dispatch (context=0x8068e40) at /build/buildd-glib2.0_2.24.2-1-kfreebsd-i386-CLgKW4/glib2.0-2.24.2/glib/gmain.c:1960
#15 IA__g_main_context_dispatch (context=0x8068e40) at /build/buildd-glib2.0_2.24.2-1-kfreebsd-i386-CLgKW4/glib2.0-2.24.2/glib/gmain.c:2513
#16 0x281cf018 in g_main_context_iterate (context=0x8068e40, block=<value optimized out>, dispatch=1, self=0x8061780) at /build/buildd-glib2.0_2.24.2-1-kfreebsd-i386-CLgKW4/glib2.0-2.24.2/glib/gmain.c:2591
#17 0x281cf557 in IA__g_main_loop_run (loop=0x8075058) at /build/buildd-glib2.0_2.24.2-1-kfreebsd-i386-CLgKW4/glib2.0-2.24.2/glib/gmain.c:2799
#18 0x080578a9 in ?? ()
#19 0x2827837b in __libc_start_main (main=0x80574f0, argc=1, ubp_av=0xbfbfee08, init=0x805b450, fini=0x805b440, rtld_fini=0x2806d4f0 <_dl_fini>, stack_end=0xbfbfedfc) at libc-start.c:257
#20 0x0804ce91 in ?? ()
(gdb) continue
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x282e6907 in gettimeofday () at ../sysdeps/unix/syscall-template.S:82
82 in ../sysdeps/unix/syscall-template.S
(gdb) backtrace
[snipped, see attached gdb-upowerd.txt]
(gdb) continue
Continuing.
^C
Program received signal SIGINT, Interrupt.
0x282e6907 in gettimeofday () at ../sysdeps/unix/syscall-template.S:82
82 in ../sysdeps/unix/syscall-template.S
(gdb) backtrace
[snipped, see attached gdb-upowerd.txt]
(gdb) backtrace full
[snipped, see attached gdb-upowerd.txt]
(gdb) info registers
[snipped, see attached gdb-upowerd.txt]
(gdb) x/16i $pc
[snipped, see attached gdb-upowerd.txt]
(gdb) thread apply all backtrace
[snipped, see attached gdb-upowerd.txt]
(gdb) quit
A debugging session is active.
Inferior 1 [process 859] will be detached.
Quit anyway? (y or n) y
Detaching from program: /usr/lib/upower/upowerd, process 859
# ps -flw -C upowerd
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 R root 859 1 62 246 - - 1257 - 16:58 ? 00:05:17 /usr/lib/upower/upowerd
# ktrace -f upowerd.ktrace -d -p 859; sleep 2; ktrace -c -p 859
# ls -sh upowerd.ktrace
4.2M upowerd.ktrace
# kdump -f upowerd.ktrace -m 4096 | wc -l
76035
# kdump -f upowerd.ktrace -m 4096 | head
859 upowerd RET gettimeofday 0
859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75f)
859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75f)
859 upowerd RET poll -1 errno 22 Invalid argument
859 upowerd CALL gettimeofday(0xbfbfe648,0)
859 upowerd CALL gettimeofday(0xbfbfe648,0)
859 upowerd RET gettimeofday 0
859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75f)
859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75f)
859 upowerd RET poll -1 errno 22 Invalid argument
# kdump -f upowerd.ktrace -m 4096 | sort | uniq -c | sort -nr | head
25344 859 upowerd CALL gettimeofday(0xbfbfe648,0)
12673 859 upowerd RET gettimeofday 0
12672 859 upowerd RET poll -1 errno 22 Invalid argument
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75e)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a75c)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a759)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a757)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a756)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a755)
14 859 upowerd CALL poll(0xbfbfe5d4,0x1,0xd6e5a753)
# ps -flw -C upowerd
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 R root 859 1 91 262 - - 1257 - 16:58 ? 01:16:53 /usr/lib/upower/upowerd
# kill 859
# ps -flw -C upowerd
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
#
Start "Power Management" application (System->Preferences->Power Management).
This causes upowerd to be started and now upowerd is well behaved.
# ps -flw -C upowerd
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
0 S root 18438 1 0 188 - - 1257 - 18:42 ? 00:00:00 /usr/lib/upower/upowerd
Could this be a race condition on boot that causes upowerd to get in a
spin (perhaps with dbus)?
Regards,
Mike.
-- System Information:
Debian Release: squeeze/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: kfreebsd-i386 (i686)
Kernel: kFreeBSD 8.1-1-686
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Versions of packages upower depends on:
ii dbus 1.2.24-3 simple interprocess messaging syst
ii libc0.1 2.11.2-6 Embedded GNU C Library: Shared lib
ii libdbus-1-3 1.2.24-3 simple interprocess messaging syst
ii libdbus-glib-1-2 0.88-2 simple interprocess messaging syst
ii libglib2.0-0 2.24.2-1 The GLib library of C routines
ii libkvm0 8.1-5 FreeBSD kvm (kernel memory interfa
ii libpolkit-gobject-1-0 0.96-3 PolicyKit Authorization API
ii libupower-glib1 0.9.5-3 abstraction for power management -
Versions of packages upower recommends:
pn pm-utils <none> (no description available)
ii policykit-1 0.96-3 framework for managing administrat
upower suggests no packages.
-- no debconf information
-------------- next part --------------
A non-text attachment was scrubbed...
Name: kfreebsd_upowerd_warning_during_login.ppm.bz2
Type: application/x-bzip
Size: 60554 bytes
Desc: not available
URL: <http://lists.alioth.debian.org/pipermail/pkg-utopia-maintainers/attachments/20101030/be0e312b/attachment-0001.bin>
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: gdb-upowerd.txt
URL: <http://lists.alioth.debian.org/pipermail/pkg-utopia-maintainers/attachments/20101030/be0e312b/attachment-0001.txt>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 898 bytes
Desc: OpenPGP digital signature
URL: <http://lists.alioth.debian.org/pipermail/pkg-utopia-maintainers/attachments/20101030/be0e312b/attachment-0001.pgp>
More information about the Pkg-utopia-maintainers
mailing list