Package: udev Version: 175-3.1 Severity: important -----BEGIN PGP SIGNED MESSAGE----- Hash: SHA512
Dear Maintainer, This bug issue first came to light after upgrading the kernel from 3.0.1 to 3.3.4, both home-build versions from the kernel.org source. Switching back to 3.0.1 stops this behaviour, but since the problems all appear to point to udev doing something odd, I thought this was the correct place to report the bug. Please do correct me if you disagree. After changing to kernel 3.3.4, the system became unresponsive on booting, at the point where udev was being started. 120 seconds later, the system then continued booting, but the CPU usage of all three cores of my machine are at about 70% each, split approximately 2:1 system:user. The first few lines from top illustrate this: >>> Tasks: 185 total, 2 running, 183 sleeping, 0 stopped, 0 zombie %Cpu0 : 31.4 us, 44.1 sy, 0.0 ni, 24.5 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st %Cpu1 : 26.2 us, 50.5 sy, 0.0 ni, 20.4 id, 0.0 wa, 0.0 hi, 2.9 si, 0.0 st %Cpu2 : 23.3 us, 37.9 sy, 0.0 ni, 36.9 id, 0.0 wa, 0.0 hi, 1.9 si, 0.0 st Kb Mem: 2052848 total, 1282356 used, 770492 free, 34752 buffers Kb Swap: 2097148 total, 0 used, 2097148 free, 594576 cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 1367 root 20 0 21404 1288 620 S 14.9 0.1 4:46.76 udevd 1368 root 20 0 21404 1280 616 S 14.6 0.1 4:45.65 udevd 1369 root 20 0 21404 1276 612 R 14.6 0.1 4:47.38 udevd 1370 root 20 0 21404 1260 596 S 14.6 0.1 4:47.26 udevd 1352 root 20 0 21672 1652 808 S 7.0 0.1 2:16.53 udevd 5707 root 20 0 47764 2056 1716 S 2.7 0.1 0:49.78 odccm 6029 dh 20 0 238m 14m 10m S 1.3 0.7 0:24.55 gkrellm <<< A large number of udev processes appear to be running as well: >>> $ ps faux|grep udev root 1352 6.9 0.0 21672 1652 ? Ss 15:33 2:22 udevd --daemon root 1367 14.5 0.0 21404 1288 ? S 15:33 4:59 \_ udevd --daemon root 1368 14.4 0.0 21404 1280 ? S 15:33 4:57 \_ udevd --daemon root 370 0.0 0.0 29144 1520 ? R 16:08 0:00 | \_ /lib/udev/udisks-part-id /dev/ubd root 1369 14.5 0.0 21404 1276 ? S 15:33 4:59 \_ udevd --daemon root 371 0.0 0.0 29140 1532 ? D 16:08 0:00 | \_ /lib/udev/udisks-part-id /dev/ubb root 1370 14.5 0.0 21404 1260 ? S 15:33 4:59 \_ udevd --daemon root 1372 0.0 0.0 21404 1220 ? S 15:33 0:00 \_ udevd --daemon root 1374 0.0 0.0 21404 1180 ? S 15:33 0:00 \_ udevd --daemon root 1375 0.0 0.0 21404 1204 ? S 15:33 0:00 \_ udevd --daemon root 1377 0.0 0.0 21404 1204 ? S 15:33 0:00 \_ udevd --daemon root 1378 0.0 0.0 21404 1184 ? S 15:33 0:00 \_ udevd --daemon root 1379 0.0 0.0 21404 1144 ? S 15:33 0:00 \_ udevd --daemon root 1380 0.0 0.0 21404 1184 ? S 15:33 0:00 \_ udevd --daemon root 1381 0.0 0.0 21404 1192 ? S 15:33 0:00 \_ udevd --daemon root 1382 0.0 0.0 21404 1208 ? S 15:33 0:00 \_ udevd --daemon root 1383 0.0 0.0 21404 1092 ? S 15:33 0:00 \_ udevd --daemon root 1384 0.0 0.0 21404 1136 ? S 15:33 0:00 \_ udevd --daemon root 1385 0.0 0.0 21404 1192 ? S 15:33 0:00 \_ udevd --daemon root 1386 0.0 0.0 21404 1120 ? S 15:33 0:00 \_ udevd --daemon root 1387 0.0 0.0 21404 1120 ? S 15:33 0:00 \_ udevd --daemon root 1388 0.0 0.0 21404 1128 ? S 15:33 0:00 \_ udevd --daemon root 1389 0.0 0.0 21404 1156 ? S 15:33 0:00 \_ udevd --daemon root 1390 0.0 0.0 21404 1140 ? S 15:33 0:00 \_ udevd --daemon root 1391 0.0 0.0 21404 1152 ? S 15:33 0:00 \_ udevd --daemon root 1392 0.0 0.0 21404 1128 ? S 15:33 0:00 \_ udevd --daemon root 1393 0.0 0.0 21404 1132 ? S 15:33 0:00 \_ udevd --daemon root 1394 0.0 0.0 21404 1124 ? S 15:33 0:00 \_ udevd --daemon root 1395 0.0 0.0 21404 1128 ? S 15:33 0:00 \_ udevd --daemon root 1396 0.0 0.0 21404 1116 ? S 15:33 0:00 \_ udevd --daemon root 1397 0.0 0.0 21404 1116 ? S 15:33 0:00 \_ udevd --daemon root 1398 0.0 0.0 21404 1100 ? S 15:33 0:00 \_ udevd --daemon root 1399 0.0 0.0 21404 1100 ? S 15:33 0:00 \_ udevd --daemon root 1400 0.0 0.0 21404 1076 ? S 15:33 0:00 \_ udevd --daemon root 1401 0.0 0.0 21404 1072 ? S 15:33 0:00 \_ udevd --daemon root 1402 0.0 0.0 21404 1076 ? S 15:33 0:00 \_ udevd --daemon root 1403 0.0 0.0 21404 1076 ? S 15:33 0:00 \_ udevd --daemon root 1463 0.0 0.0 21668 1240 ? S 15:33 0:00 \_ udevd --daemon root 1464 0.0 0.0 21668 1148 ? S 15:33 0:00 \_ udevd --daemon root 1465 0.0 0.0 21404 1052 ? S 15:33 0:00 \_ udevd --daemon root 1466 0.0 0.0 21668 1240 ? S 15:33 0:00 \_ udevd --daemon <<< There are also a large number of entries being sent to syslog of the following form: >>> May 7 15:48:10 scrat udevd[1369]: symlink '../../ubc' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:48:25 scrat udevd[1368]: symlink '../../ubc' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:49:26 scrat udevd[1369]: symlink '../../uba' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:49:41 scrat udevd[1367]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:49:59 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:50:23 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:50:59 scrat udevd[1367]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:51:28 scrat udevd[1367]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:51:40 scrat udevd[1369]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:51:58 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:52:59 scrat udevd[1368]: symlink '../../ubb' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:53:13 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:54:00 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:54:52 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:54:52 scrat udevd[1368]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:55:30 scrat udevd[1368]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:55:36 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:55:38 scrat udevd[1367]: symlink '../../ubc' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:56:21 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:56:48 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:56:48 scrat udevd[1370]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:58:15 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:58:25 scrat udevd[1369]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:58:31 scrat udevd[1367]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 15:58:57 scrat udevd[1369]: symlink '../../ubb' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 15:59:07 scrat udevd[1369]: symlink '../../ubc' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 16:00:01 scrat udevd[1369]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 16:00:18 scrat udevd[1368]: symlink '../../ubb' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 16:00:40 scrat udevd[1368]: symlink '../../uba' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 16:01:06 scrat udevd[1368]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 16:01:41 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 16:01:53 scrat udevd[1370]: symlink '../../ubd' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists May 7 16:02:23 scrat udevd[1369]: rename '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0' failed: No such file or directory May 7 16:02:23 scrat udevd[1368]: symlink '../../ubb' '/dev/disk/by-path/pci-0000:00:04.1-usb-0:3:1.0.udev-tmp' failed: File exists <<< The filenames pointed to there seem to indicate that it's trying to set up a USB multi-card reader, which presents itself as a USB mass storage device with multiple LUNs. The device details are here: >>> $ lsusb -d 058f:6362 -v Bus 002 Device 003: ID 058f:6362 Alcor Micro Corp. Flash Card Reader/Writer Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 0 (Defined at Interface level) bDeviceSubClass 0 bDeviceProtocol 0 bMaxPacketSize0 64 idVendor 0x058f Alcor Micro Corp. idProduct 0x6362 Flash Card Reader/Writer bcdDevice 1.26 iManufacturer 1 iProduct 2 iSerial 3 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 32 bNumInterfaces 1 bConfigurationValue 1 iConfiguration 0 bmAttributes 0x80 (Bus Powered) MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 2 bInterfaceClass 8 Mass Storage bInterfaceSubClass 6 SCSI bInterfaceProtocol 80 Bulk-Only iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x01 EP 1 OUT bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x82 EP 2 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0200 1x 512 bytes bInterval 0 Device Status: 0xb810 (Bus Powered) <<< If I now execute "sudo /etc/init.d/udev restart", the CPU usage drops back down to zero and I get a much more sane looking number of udev processes showing up: >>> $ ps faux|grep udev root 8144 0.1 0.0 21376 1364 ? Ss 16:15 0:00 udevd --daemon root 8165 0.0 0.0 21372 1152 ? S 16:15 0:00 \_ udevd --daemon root 8210 0.0 0.0 29140 1524 ? D 16:15 0:00 | \_ /lib/udev/udisks-part-id /dev/ubb root 8173 0.0 0.0 21372 1144 ? S 16:15 0:00 \_ udevd --daemon root 8196 0.0 0.0 29140 1524 ? D 16:15 0:00 | \_ /lib/udev/udisks-part-id /dev/uba root 8181 0.0 0.0 21372 1152 ? S 16:15 0:00 \_ udevd --daemon root 8202 0.0 0.0 29140 1524 ? D 16:15 0:00 \_ /lib/udev/udisks-part-id /dev/ubc <<< In summary, three things seem to work around the bug, though none of them are anywhere close to ideal: * Boot without the USB card reader present. This is particularly impractical as it is an internal device. * Boot kernel 3.0.1 * Put up with the initial timeout, then re-start udev once booted I'd be happy to perform any further tests if it would be useful in getting to the bottom of this problem. All the best, - -DH. - -- System Information: Debian Release: wheezy/sid APT prefers unstable APT policy: (550, 'unstable'), (550, 'testing'), (450, 'stable'), (445, 'experimental') Architecture: amd64 (x86_64) Kernel: Linux 3.3.4 (SMP w/3 CPU cores) Locale: LANG=en_GB, LC_CTYPE=en_GB (charmap=ISO-8859-1) Shell: /bin/sh linked to /bin/bash Versions of packages udev depends on: ii debconf [debconf-2.0] 1.5.42 ii libc6 2.13-32 ii libselinux1 2.1.9-4 ii libudev0 175-3.1 ii lsb-base 4.1+Debian2 ii util-linux 2.20.1-4 Versions of packages udev recommends: ii pciutils 1:3.1.9-2 ii usbutils 1:005-3 udev suggests no packages. - -- debconf information: udev/title/upgrade: udev/new_kernel_needed: false udev/sysfs_deprecated_incompatibility: udev/reboot_needed: -----BEGIN PGP SIGNATURE----- Version: GnuPG v1.4.12 (GNU/Linux) iQIcBAEBCgAGBQJPp+j1AAoJEBIA1yCB7VsRrxIP/0PNZuH5SF6SJ4zq/OxWbPrt IQgN0wKEQCNZ49w5pCDZ3ac/D1uCCsrHqWdp7CSSKp65MbkiFdpLVRSy4B5Huf2o 6y48vK9ORgl13htfW5ibz3Ird26oeQ4ajQHNApXPyZKe+q2q7oJYV+jFh1KlYQmJ +OXUNhL9Sk0XaOQeZotwUSQjVRs/Ya0U4uYtKPOjXl/rgvZvUcN5pRXXag5v5/p/ mhXfPlAQe6acSuXdBj7uJ6cV68EYMMuRXAGqCU/3xekIA1GKJmYa3dQWG1nRqQzF GM4WvkCznzIbr2H8gmiOkhPOxgFp2R61Gx4zIlaCz9nI6eavDDvr4JaQAhiK5vZw bcsCWA/r/D19RmVfnG4ylGQiUKn8nq+DYy8lwQvQ5hIgkGTBERo6/rYnkosKCwYj a21W5fIlw2YVssUevsbs5jxp5yGCgpx1dTKCCqWbaGNcz9jcnNQwvmutQYR3lHhs EpljTK4ItC6JCk0IlBW/kAMC9UryiZnhGUhUUDVNo71FOBN6YG4zw5rQ3IjzLYLL +CxZF9qiUFpvcnKVqz3lAkSIQ2gCAqBgtHAx4k9qW+I/2BoyLTm2lM7HSWFr/84P g94YdMXm0iBDQ8cjLAbK09YQGkYENS9XAntKjLZRR2fV8Szp49FCHaGLUe2QaxLr 5NrzJ5bMeSkR6O9V1xMp =HsG+ -----END PGP SIGNATURE----- -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org