[Pkg-utopia-maintainers] Bug#728798: [udisks] udisks-daemon: randomly starts using 100% CPU

Török Edwin edwin at etorok.net
Tue Nov 5 16:01:18 UTC 2013


Package: udisks
Version: 1.0.4-8+b1
Severity: normal

--- Please enter the report below this line. ---

Almost every other day udisks-daemon starts using 100% CPU (I notice because the CPU fan becomes louder).
I didn't plug/unplug or otherwise modify the state of any of my disks when that happens, and I don't have a reliable way to reproduce it either (other than wait a day or two to see if it starts using 100% CPU), hence I called it a random bug.

I usually just kill udisks-daemon when this happens, but this time I took a stacktrace and strace:

gdb stacktrace:

Thread 3 (Thread 0x7f4b24318700 (LWP 4309)):
#0  0x00000033be6dd24d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000003ee6c48694 in g_main_context_poll (priority=2147483647, n_fds=3, fds=0x7f4b1c0010e0, timeout=-1, context=0x16a73d0)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:4006
#2  g_main_context_iterate (context=0x16a73d0, block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3707
#3  0x0000003ee6c48afa in g_main_loop_run (loop=0x16a7360) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3906
#4  0x00000033e70cb9d6 in gdbus_shared_thread_func (user_data=0x16a73a0)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./gio/gdbusprivate.c:278
#5  0x0000003ee6c6d0e5 in g_thread_proxy (data=0x16a9450) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gthread.c:798
#6  0x00000033bf207e0e in start_thread (arg=0x7f4b24318700) at pthread_create.c:311
#7  0x00000033be6e89ed in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Thread 2 (Thread 0x7f4b23b17700 (LWP 5149)):
#0  0x00000033be6dd24d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000003ee6c48694 in g_main_context_poll (priority=2147483647, n_fds=1, fds=0x7f4b140008c0, timeout=-1, context=0x1714b00)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:4006
#2  g_main_context_iterate (context=context at entry=0x1714b00, block=block at entry=1, dispatch=dispatch at entry=1, 
    self=<optimized out>) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3707
#3  0x0000003ee6c4879c in g_main_context_iteration (context=0x1714b00, may_block=may_block at entry=1)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3773
#4  0x0000003ee6c487e9 in glib_worker_main (data=<optimized out>) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:5472
#5  0x0000003ee6c6d0e5 in g_thread_proxy (data=0x16a98a0) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gthread.c:798
#6  0x00000033bf207e0e in start_thread (arg=0x7f4b23b17700) at pthread_create.c:311
#7  0x00000033be6e89ed in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113

Thread 1 (Thread 0x7f4b24319800 (LWP 4297)):
#0  0x00000033be6dd24d in poll () at ../sysdeps/unix/syscall-template.S:81
#1  0x0000003ee6c48694 in g_main_context_poll (priority=2147483647, n_fds=6, fds=0x16945a0, timeout=663425, context=0x1690aa0)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:4006
#2  g_main_context_iterate (context=0x1690aa0, block=block at entry=1, dispatch=dispatch at entry=1, self=<optimized out>)
    at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3707
#3  0x0000003ee6c48afa in g_main_loop_run (loop=0x16c1e40) at /build/glib2.0-m8PF51/glib2.0-2.38.0/./glib/gmain.c:3906
#4  0x0000000000406f7c in ?? ()
#5  0x00000033be621995 in __libc_start_main (main=0x406d70, argc=1, ubp_av=0x7fffbe72ac28, init=<optimized out>, 
    fini=<optimized out>, rtld_fini=<optimized out>, stack_end=0x7fffbe72ac18) at libc-start.c:260
#6  0x00000000004070d5 in ?? ()


strace shows that only poll is called, apparently in a tight loop:

Process 4297 attached - interrupt to quit
1383666498.282777 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.282936 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283044 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283146 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283241 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283337 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283433 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363008) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283549 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363007) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])
1383666498.283647 poll([{fd=5, events=POLLIN}, {fd=8, events=POLLIN}, {fd=10, events=0}, {fd=26, events=POLLIN}, {fd=23, events=POLLIN}, {fd=3, events=POLLIN}], 6, 1363007) = 2 ([{fd=26, revents=POLLHUP}, {fd=23, revents=POLLHUP}])


pstree -p looks like this, 4297 is the PID of the inflooping udisks-daemon:
        |-udisks-daemon(4297)-+-udisks-daemon(4302)
        |                     |-udisks-helper-a(24793)
        |                     |-{udisks-daemon}(4309)
        |                     `-{udisks-daemon}(5149)


FD 26 and 23 are a pipe:
# ls -l /proc/4297/fd
lrwx------ 1 root root 64 Nov  5 17:48 0 -> /dev/null
lrwx------ 1 root root 64 Nov  5 17:48 1 -> /dev/null
lr-x------ 1 root root 64 Nov  5 17:48 10 -> /proc/4297/mountinfo
lrwx------ 1 root root 64 Nov  5 17:48 11 -> anon_inode:[eventfd]
lrwx------ 1 root root 64 Nov  5 17:48 2 -> /dev/null
lr-x------ 1 root root 64 Nov  5 17:48 23 -> pipe:[3561954]
lr-x------ 1 root root 64 Nov  5 17:48 26 -> pipe:[3561955]
lrwx------ 1 root root 64 Nov  5 17:48 3 -> socket:[9649]
l-wx------ 1 root root 64 Nov  5 17:48 4 -> pipe:[9647]
lrwx------ 1 root root 64 Nov  5 17:48 5 -> anon_inode:[eventfd]
lrwx------ 1 root root 64 Nov  5 17:48 6 -> socket:[7401]
lrwx------ 1 root root 64 Nov  5 17:48 7 -> anon_inode:[eventfd]
lrwx------ 1 root root 64 Nov  5 17:48 8 -> socket:[9650]
lrwx------ 1 root root 64 Nov  5 17:48 9 -> anon_inode:[eventfd]

I noticed that I have a libglib2.0-0 newer than in unstable (probably some package from experimental pulled it in at some point), I'll try downgrading it to the version in experimental to see what happens.

Tips on how to debug this / what information to gather are welcome.

--- System information. ---
Architecture: amd64
Kernel:       Linux 3.12.0

Debian Release: jessie/sid
  500 unstable        ftp.ro.debian.org 
  500 stable          security.debian.org 
  500 stable          ftp.ro.debian.org 
    1 experimental    ftp.ro.debian.org 

--- Package information. ---
Depends                        (Version) | Installed
========================================-+-===============
libatasmart4                   (>= 0.13) | 0.19-3
libc6                          (>= 2.14) | 
libdbus-1-3                   (>= 1.0.2) | 
libdbus-glib-1-2               (>= 0.88) | 
libdevmapper1.02.1        (>= 2:1.02.20) | 
libglib2.0-0                 (>= 2.24.0) | 
libgudev-1.0-0                  (>= 146) | 
liblvm2app2.2               (>= 2.02.98) | 
libparted0debian1             (>= 2.2-1) | 
libpolkit-gobject-1-0          (>= 0.99) | 
libsgutils2-2                  (>= 1.27) | 
libudev1                        (>= 183) | 
udev                                     | 
dbus                                     | 


Recommends          (Version) | Installed
=============================-+-===========
policykit-1                   | 0.105-4
hdparm                        | 9.43-1
dosfstools                    | 3.0.16-2
ntfs-3g                       | 1:2013.1.13AR.1-2
eject                         | 2.1.5+deb1+cvs20081104-13
cryptsetup-bin                | 2:1.6.1-1


Suggests           (Version) | Installed
============================-+-===========
xfsprogs                     | 
reiserfsprogs                | 
mdadm                        | 



More information about the Pkg-utopia-maintainers mailing list