[Date Prev][Date Next] [Thread Prev][Thread Next] [Date Index] [Thread Index]

Bug#586404: marked as done (d-i must not mix udev packages from different releases)



Your message dated Tue, 27 Jul 2010 02:35:20 -0300
with message-id <AANLkTim4fDG-gguwMp7tcbM1NaXcOdbUGhudpTAPnukT@mail.gmail.com>
and subject line Re: Bug#586404: udev-udeb: Very slow installation in Squeeze caused  by udevadm settle
has caused the Debian Bug report #586404,
regarding d-i must not mix udev packages from different releases
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 owner@bugs.debian.org
immediately.)


-- 
586404: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=586404
Debian Bug Tracking System
Contact owner@bugs.debian.org with problems
--- Begin Message ---
Package:  udev-udeb
Version:  157-1
Severity: important
User:     debian-edu@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



--- End Message ---
--- Begin Message ---
Package: debian-installer
Version: 20100722

On Sat, Jul 24, 2010 at 3:54 PM, Marco d'Itri <md@linux.it> wrote:
>> I agree with you; this shouldn't be fixed on udev but a new installer
>> version to be released.
> Looks like there are no objections about this.
> Now the package will log a warning when messages from udevadm are
> ignored.

We have a new installer version built and it is in sync with udev version.

Closing this bug.

-- 
Otavio Salvador                  O.S. Systems
E-mail: otavio@ossystems.com.br  http://www.ossystems.com.br
Mobile: +55 53 9981-7854         http://projetos.ossystems.com.br


--- End Message ---

Reply to: