Attachment 153306 Details for Bug 225487 – strace -f -s 200 of dmeventd while running test case

strace -f -s 200 of dmeventd while running test case

dmeventd.strace (text/plain), 15.23 KB, created by Nate Straz on 2007-04-23 19:11:39 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: Nate Straz

Created: 2007-04-23 19:11:39 UTC

Size: 15.23 KB

patch

obsolete

>4673  select(6, [5], NULL, NULL, {0, 238000} <unfinished ...>
>5069  ioctl(6, DM_DEV_WAIT <unfinished ...>
>4673  <... select resumed> )            = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {0, 367000})
>4673  read(5, "\0\0\0\10\0\0\0\r", 8)   = 8
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {1, 0})
>4673  read(5, "5073:0 HELLO\0", 13)     = 13
>4673  select(5, NULL, [4], NULL, NULL)  = 1 (out [4])
>4673  write(4, "\0\0\0\0\0\0\0\0235073:0 HELLO HELLO\0", 27) = 27
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {0, 999000})
>4673  read(5, "\0\0\0\4\0\0\0u", 8)     = 8
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {1, 0})
>4673  read(5, "5073:1 libdevmapper-event-lvm2mirror.so LVM-YAV4d0sANCjwEvnoKMHQXvXczypwCzEQFDKfQRSThI0s7OA2h26jDt2FzgZxcufJ 65280 0\0", 117) = 117
>4673  futex(0x505f80, FUTEX_WAKE, 1)    = 0
>4673  select(5, NULL, [4], NULL, NULL)  = 1 (out [4])
>4673  write(4, "\0\0\0\0\0\0\0s5073:1 libdevmapper-event-lvm2mirror.so LVM-YAV4d0sANCjwEvnoKMHQXvXczypwCzEQFDKfQRSThI0s7OA2h26jDt2FzgZxcufJ 65280\0", 123) = 123
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {0, 999000})
>4673  read(5, "\0\0\0\10\0\0\0\r", 8)   = 8
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {1, 0})
>4673  read(5, "5073:2 HELLO\0", 13)     = 13
>4673  select(5, NULL, [4], NULL, NULL)  = 1 (out [4])
>4673  write(4, "\0\0\0\0\0\0\0\0235073:2 HELLO HELLO\0", 27) = 27
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {0, 999000})
>4673  read(5, "\0\0\0\3\0\0\0u", 8)     = 8
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {1, 0})
>4673  read(5, "5073:3 libdevmapper-event-lvm2mirror.so LVM-YAV4d0sANCjwEvnoKMHQXvXczypwCzEQFDKfQRSThI0s7OA2h26jDt2FzgZxcufJ 65280 0\0", 117) = 117
>4673  select(5, NULL, [4], NULL, NULL)  = 1 (out [4])
>4673  write(4, "\0\0\0\0\0\0\0\0175073:3 Success\0", 23) = 23
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {0, 999000})
>4673  read(5, "\0\0\0\10\0\0\0\r", 8)   = 8
>4673  select(6, [5], NULL, NULL, {1, 0}) = 1 (in [5], left {1, 0})
>4673  read(5, "5073:4 HELLO\0", 13)     = 13
>4673  select(5, NULL, [4], NULL, NULL)  = 1 (out [4])
>4673  write(4, "\0\0\0\0\0\0\0\0235073:4 HELLO HELLO\0", 27) = 27
>4673  tgkill(4673, 5069, SIGALRM <unfinished ...>
>5069  <... ioctl resumed> , 0x531270)   = ? ERESTARTSYS (To be restarted)
>4673  <... tgkill resumed> )            = 0
>5069  --- SIGALRM (Alarm clock) @ 0 (0) ---
>4673  select(6, [5], NULL, NULL, {1, 0} <unfinished ...>
>5069  rt_sigreturn(0xe)                 = -1 EINTR (Interrupted system call)
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>4673  <... select resumed> )            = 1 (in [5], left {0, 999000})
>5069  stat("/etc/localtime",  <unfinished ...>
>4673  read(5,  <unfinished ...>
>5069  <... stat resumed> {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>4673  <... read resumed> "\0\0\0\4\0\0\0u", 8) = 8
>5069  sendto(7, "<13>Apr 23 14:06:31 lvm[4673]: dm_task_run failed, errno = 4, Interrupted system call", 85, MSG_NOSIGNAL, NULL, 0 <unfinished ...>
>4673  select(6, [5], NULL, NULL, {1, 0} <unfinished ...>
>5069  <... sendto resumed> )            = 85
>4673  <... select resumed> )            = 1 (in [5], left {1, 0})
>5069  rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT KILL TERM STOP RTMIN RT_1],  <unfinished ...>
>4673  read(5,  <unfinished ...>
>5069  <... rt_sigprocmask resumed> NULL, 8) = 0
>4673  <... read resumed> "5073:5 libdevmapper-event-lvm2mirror.so LVM-YAV4d0sANCjwEvnoKMHQXvXczypwCzEQFDKfQRSThI0s7OA2h26jDt2FzgZxcufJ 65280 0\0", 117) = 117
>5069  rt_sigprocmask(SIG_UNBLOCK, [ALRM],  <unfinished ...>
>4673  select(5, NULL, [4], NULL, NULL <unfinished ...>
>5069  <... rt_sigprocmask resumed> ~[HUP INT QUIT KILL TERM STOP RTMIN RT_1], 8) = 0
>4673  <... select resumed> )            = 1 (out [4])
>5069  ioctl(6, DM_DEV_WAIT <unfinished ...>
>4673  write(4, "\377\377\377\376\0\0\0!5073:5 No such file or directory\0", 41) = 41
>4673  tgkill(4673, 5069, SIGALRM <unfinished ...>
>5069  <... ioctl resumed> , 0x531270)   = ? ERESTARTSYS (To be restarted)
>4673  <... tgkill resumed> )            = 0
>5069  --- SIGALRM (Alarm clock) @ 0 (0) ---
>4673  select(6, [5], NULL, NULL, {1, 0} <unfinished ...>
>5069  rt_sigreturn(0xe)                 = -1 EINTR (Interrupted system call)
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<13>Apr 23 14:06:31 lvm[4673]: dm_task_run failed, errno = 4, Interrupted system call", 85, MSG_NOSIGNAL, NULL, 0) = 85
>5069  rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT KILL TERM STOP RTMIN RT_1], NULL, 8) = 0
>5069  rt_sigprocmask(SIG_UNBLOCK, [ALRM], ~[HUP INT QUIT KILL TERM STOP RTMIN RT_1], 8) = 0
>5069  ioctl(6, DM_DEV_WAIT, 0x531270)   = 0
>5069  rt_sigprocmask(SIG_SETMASK, ~[HUP INT QUIT KILL TERM STOP RTMIN RT_1], NULL, 8) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<14>Apr 23 14:06:31 lvm[4673]: No longer monitoring mirror device linear_7_2848-linear_7_28480 for events\n", 106, MSG_NOSIGNAL, NULL, 0) = 106
>5069  munlockall()                      = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Unlocking memory", 47, MSG_NOSIGNAL, NULL, 0) = 47
>5069  brk(0x556000)                     = 0x556000
>5069  setpriority(PRIO_PROCESS, 0, 4294967278) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: memlock_count dec to 0", 53, MSG_NOSIGNAL, NULL, 0) = 53
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Dumping persistent device cache to /etc/lvm/.cache", 81, MSG_NOSIGNAL, NULL, 0) = 81
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Locking /etc/lvm/.cache (F_WRLCK, 1)", 67, MSG_NOSIGNAL, NULL, 0) = 67
>5069  open("/etc/lvm/.cache", O_RDWR|O_CREAT, 0777) = 8
>5069  fcntl(8, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
>5069  fstat(8, {st_mode=S_IFREG|0600, st_size=1369, ...}) = 0
>5069  stat("/etc/lvm/.cache", {st_mode=S_IFREG|0600, st_size=1369, ...}) = 0
>5069  stat("/etc/lvm/.cache", {st_mode=S_IFREG|0600, st_size=1369, ...}) = 0
>5069  stat("/etc/lvm/.cache", {st_mode=S_IFREG|0600, st_size=1369, ...}) = 0
>5069  open("/etc/lvm/.cache", O_RDONLY) = 9
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Opened /etc/lvm/.cache RO", 56, MSG_NOSIGNAL, NULL, 0) = 56
>5069  mmap(NULL, 1369, PROT_READ, MAP_PRIVATE, 9, 0) = 0x2a9556c000
>5069  munmap(0x2a9556c000, 1369)        = 0
>5069  stat("/dev/ram11", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 11), ...}) = 0
>5069  stat("/dev/VolGroup00/LogVol01", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 1), ...}) = 0
>5069  stat("/dev/ram10", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 10), ...}) = 0
>5069  stat("/dev/ram", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 1), ...}) = 0
>5069  stat("/dev/VolGroup00/LogVol00", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 0), ...}) = 0
>5069  stat("/dev/ram12", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 12), ...}) = 0
>5069  stat("/dev/ram6", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 6), ...}) = 0
>5069  stat("/dev/ram13", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 13), ...}) = 0
>5069  stat("/dev/ram14", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 14), ...}) = 0
>5069  stat("/dev/ram5", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 5), ...}) = 0
>5069  stat("/dev/mapper/VolGroup00-LogVol00", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 0), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023abe154:0x0000000000000000-part3", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 19), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023abe154:0x0000000000000000-part4", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 20), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023ac1ac2:0x0000000000000000-part3", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 35), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023ac1ac2:0x0000000000000000-part4", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 36), ...}) = 0
>5069  stat("/dev/ram1", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 1), ...}) = 0
>5069  stat("/dev/sdb1", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 17), ...}) = 0
>5069  stat("/dev/sdc1", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 33), ...}) = 0
>5069  stat("/dev/ramdisk", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 0), ...}) = 0
>5069  stat("/dev/mapper/VolGroup00-LogVol01", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 1), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023abe154:0x0000000000000000-part2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 18), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023ac1ac2:0x0000000000000000-part2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 34), ...}) = 0
>5069  stat("/dev/ram0", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 0), ...}) = 0
>5069  stat("/dev/root", {st_mode=S_IFBLK|0660, st_rdev=makedev(253, 0), ...}) = 0
>5069  stat("/dev/dm-1", {st_mode=S_IFBLK|0640, st_rdev=makedev(253, 1), ...}) = 0
>5069  stat("/dev/ram2", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 2), ...}) = 0
>5069  stat("/dev/ram8", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 8), ...}) = 0
>5069  stat("/dev/ram9", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 9), ...}) = 0
>5069  stat("/dev/sdb2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 18), ...}) = 0
>5069  stat("/dev/sdc2", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 34), ...}) = 0
>5069  stat("/dev/dm-0", {st_mode=S_IFBLK|0640, st_rdev=makedev(253, 0), ...}) = 0
>5069  stat("/dev/ram15", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 15), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023abe154:0x0000000000000000-part1", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 17), ...}) = 0
>5069  stat("/dev/disk/by-path/pci-0000:02:00.0-fc-0x210000d023ac1ac2:0x0000000000000000-part1", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 33), ...}) = 0
>5069  stat("/dev/ram3", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 3), ...}) = 0
>5069  stat("/dev/ram4", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 4), ...}) = 0
>5069  stat("/dev/ram7", {st_mode=S_IFBLK|0660, st_rdev=makedev(1, 7), ...}) = 0
>5069  stat("/dev/sdb3", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 19), ...}) = 0
>5069  stat("/dev/sdb4", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 20), ...}) = 0
>5069  stat("/dev/sdc3", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 35), ...}) = 0
>5069  stat("/dev/sdc4", {st_mode=S_IFBLK|0660, st_rdev=makedev(8, 36), ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Loaded persistent filter cache from /etc/lvm/.cache", 82, MSG_NOSIGNAL, NULL, 0) = 82
>5069  open("/etc/lvm/.cache.tmp", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 10
>5069  fstat(10, {st_mode=S_IFREG|0600, st_size=0, ...}) = 0
>5069  mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x2a9556c000
>5069  write(10, "# This file is automatically maintained by lvm.\n\npersistent_filter_cache {\n\tvalid_devices=[\n\t\t\"/dev/ram11\",\n\t\t\"/dev/VolGroup00/LogVol01\",\n\t\t\"/dev/ram10\",\n\t\t\"/dev/ram\",\n\t\t\"/dev/VolGroup00/LogVol00\",\n\t\t"..., 1369) = 1369
>5069  close(10)                         = 0
>5069  munmap(0x2a9556c000, 4096)        = 0
>5069  rename("/etc/lvm/.cache.tmp", "/etc/lvm/.cache") = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Unlocking fd 8", 45, MSG_NOSIGNAL, NULL, 0) = 45
>5069  fcntl(8, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
>5069  close(8)                          = 0
>5069  close(9)                          = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Closed /etc/lvm/.cache", 53, MSG_NOSIGNAL, NULL, 0) = 53
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=1279, ...}) = 0
>5069  sendto(7, "<15>Apr 23 14:06:31 lvm[4673]: Wiping internal VG cache", 55, MSG_NOSIGNAL, NULL, 0) = 55
>5069  close(6)                          = 0
>5069  close(7)                          = 0
>5069  _exit(0)                          = ?
>4673  <... select resumed> )            = 0 (Timeout)
>4673  munmap(0x2a95de4000, 1055944)     = 0
>4673  munmap(0x2a95ee6000, 1575656)     = 0
>4673  munmap(0x2a96067000, 1278864)     = 0
>4673  munmap(0x2a962ba000, 1421240)     = 0
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0}) = 0 (Timeout)
>4673  select(6, [5], NULL, NULL, {1, 0} <unfinished ...>

Actions: View

Attachments on bug 225487: 146999 | 153306 | 153349