Your message dated Sun, 07 Feb 2016 22:43:09 +0000
with message-id <E1aSY2v-0006JQ-Io@deadeye>
and subject line Closing bugs assigned to linux-2.6 package
has caused the Debian Bug report #671859,
regarding udev: Udev hangs on boot for 120 seconds, times out then eats CPU
failing to rename files
to be marked as done.
This means that you claim that the problem has been dealt with.
If this is not the case it is now your responsibility to reopen the
Bug report if necessary, and/or fix the problem forthwith.
(NB: If you are a system administrator and have no idea what this
message is talking about, this may indicate a serious mail system
misconfiguration somewhere. Please contact ow...@bugs.debian.org
immediately.)
--
671859: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=671859
Debian Bug Tracking System
Contact ow...@bugs.debian.org with problems
--- Begin Message ---
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-----
--- End Message ---
--- Begin Message ---
Version: 3.4.1-1~experimental.1+rm
Debian 6.0 Long Term Support has now ended, and the 'linux-2.6' source
package will no longer be updated. This bug is being closed on the
assumption that it does not affect the kernel versions in newer Debian
releases.
If you can still reproduce this bug in a newer release, please reopen
the bug report and reassign it to 'src:linux' and the affected version
of the package. You can find the package version for the running
kernel by running:
uname -v
or the versions of all installed kernel packages by running:
dpkg -l 'linux-image-[34]*' | grep ^.i
and looking at the third column.
I apologise that we weren't able to provide a specific resolution for
this bug.
Ben.
--
Ben Hutchings - Debian developer, member of Linux kernel and LTS teams
--- End Message ---
