Package: udev-udeb Version: 157-1 Severity: important User: debian-...@lists.debian.org UserTags: debian-edu
Since some days ago, the debian-installer run in Squeeze is very slow some times. Looking at the process list, I was able to trace it to the calls to 'udevadm settle' being done several times during installation. For example removing lvm partitions currently take 3 minutes _each_ because of this. I did an strace of such udevadm run to try to figure out what is going on. Here is the full strace log: execve("/sbin/udevadm", ["udevadm", "settle"], [/* 14 vars */]) = 0 brk(0) = 0x8fa0000 access("/etc/ld.so.nohwcap", F_OK) = -1 ENOENT (No such file or directory) mmap2(NULL, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb8095000 access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory) open("/etc/ld.so.cache", O_RDONLY) = -1 ENOENT (No such file or directory) open("/lib/tls/i686/sse2/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/i686/sse2/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/i686/sse2/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/i686/sse2", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/i686/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/i686/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/i686/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/i686", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/sse2/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/sse2/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/sse2/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/sse2", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/tls/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/tls", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/i686/sse2/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686/sse2/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/i686/sse2/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686/sse2", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/i686/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/i686/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/i686", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/sse2/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/sse2/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/sse2/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/sse2", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/cmov/libc.so.6", O_RDONLY) = -1 ENOENT (No such file or directory) stat64("/lib/cmov", 0xbfcedf4c) = -1 ENOENT (No such file or directory) open("/lib/libc.so.6", O_RDONLY) = 3 read(3, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\320m\1\0004\0\0\0"..., 512) = 512 fstat64(3, {st_mode=S_IFREG|0755, st_size=1315008, ...}) = 0 mmap2(NULL, 1325384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0xb7f51000 mmap2(0xb808f000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x13d) = 0xb808f000 mmap2(0xb8092000, 10568, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0xb8092000 close(3) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f50000 set_thread_area({entry_number:-1 -> 6, base_addr:0xb7f508d0, limit:1048575, seg_32bit:1, contents:0, read_exec_only:0, limit_in_pages:1, seg_not_present:0, useable:1}) = 0 mprotect(0xb808f000, 8192, PROT_READ) = 0 mprotect(0xb80b3000, 4096, PROT_READ) = 0 brk(0) = 0x8fa0000 brk(0x8fc1000) = 0x8fc1000 open("/etc/udev/udev.conf", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=15, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4f000 read(3, "udev_log=\"err\"\n", 4096) = 15 read(3, "", 4096) = 0 close(3) = 0 munmap(0xb7f4f000, 4096) = 0 rt_sigaction(SIGALRM, {0x8051df8, [], 0}, NULL, 8) = 0 rt_sigaction(SIGUSR1, {0x8051df8, [], 0}, NULL, 8) = 0 rt_sigprocmask(SIG_UNBLOCK, [USR1 ALRM], NULL, 8) = 0 alarm(180) = 0 getuid32() = 0 socket(PF_FILE, SOCK_DGRAM, 0) = 3 rt_sigprocmask(SIG_BLOCK, [USR1 ALRM], [], 8) = 0 sendto(3, "udev-157\0\0\0\0\0\0\0\0\352\35\255\336\7\0\0\0\0\0\0\0\0\0\0\0"..., 280, 0, {sa_family=AF_FILE, path=@"/org/kernel/udev/udevd"}, 25) = 280 rt_sigsuspend([]) = ? ERESTARTNOHAND (To be restarted) --- SIGALRM (Alarm clock) @ 0 (0) --- sigreturn() = ? (mask now [USR1 ALRM]) rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0 close(3) = 0 open("/dev/.udev/queue.bin", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=2030, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4f000 read(3, "5\"\0\0\0\0\0\0006\"\0\0\0\0\0\0\33\0/devices/virtu"..., 4096) = 2030 read(3, "", 4096) = 0 open("/sys/kernel/uevent_seqnum", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 4 read(4, "8798\n", 32) = 5 close(4) = 0 close(3) = 0 munmap(0xb7f4f000, 4096) = 0 open("/dev/.udev/queue.bin", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 3 fstat64(3, {st_mode=S_IFREG|0644, st_size=2030, ...}) = 0 mmap2(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0xb7f4f000 read(3, "5\"\0\0\0\0\0\0006\"\0\0\0\0\0\0\33\0/devices/virtu"..., 4096) = 2030 read(3, "", 4096) = 0 close(3) = 0 munmap(0xb7f4f000, 4096) = 0 exit_group(0) = ? The process hang after the sendto() call and the rt_sigsuspend() call, and time out with SIGALRM after what I suspect is 3 minutes. Here is a fragment from the installation syslog showing the effect of these slow calls: Jun 19 00:38:18 partman: Found volume group "vg_system" using metadata type lvm2 Jun 19 00:38:19 partman-lvm: 9 logical volume(s) in volume group "vg_system" now active Jun 19 00:44:22 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:44:22 partman-lvm: Logical volume "opt" successfully removed Jun 19 00:47:22 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:47:22 partman-lvm: Logical volume "root" successfully removed Jun 19 00:50:22 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:50:22 partman-lvm: Logical volume "skole+backup" successfully removed Jun 19 00:53:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:53:23 partman-lvm: Logical volume "skole+tjener+home0" successfully removed Jun 19 00:56:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:56:23 partman-lvm: Logical volume "swap_1" successfully removed Jun 19 00:59:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 00:59:23 partman-lvm: Logical volume "usr" successfully removed Jun 19 01:02:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 01:02:23 partman-lvm: Logical volume "var" successfully removed Jun 19 01:05:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 01:05:23 partman-lvm: Logical volume "var+opt+ltsp+swapfiles" successfully removed Jun 19 01:08:23 partman-lvm: /dev/cdrom: open failed: Read-only file system Jun 19 01:08:23 partman-lvm: Logical volume "var+spool+squid" successfully removed Jun 19 01:08:23 partman-lvm: 0 logical volume(s) in volume group "vg_system" now active Jun 19 01:11:23 partman-lvm: Volume group "vg_system" successfully removed Notice how there is a 3 minutes delay between each removal. Any ideas how to debug or fix this? Setting severity to important as this affect debian-installer badly without breaking the installation completely. Happy hacking, -- Petter Reinholdtsen -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org