X-Debbugs-Cc: debian-h...@lists.debian.org
Hello,
A bit of context: sv is trying to open a fifo (aka named pipe) which is read by
a different program runsv. The fifo is called ok and is placed in this case in
/run/runit/supervise/cron/ok
but /etc/sv/cron/supervise is a symbolic link to /run/runit/supervise/cron, so
sv is trying to open supervise/ok which is via the symbolic link.
But we are failing to open the fifo with an error ENXIO. This is occurring in
glibc functions __hurd_file_name_lookup and __hurd_file_name_lookup_retry.
I don't understand how these functions are supposed to work and what is failing
exactly. I also don't know what sort of magic FS_RETRY_MAGICAL is supposed to be
doing, but it does not seem to be working here.
Help looking into this is appreciated. I attach a new gdb log this time with
glibc sources.
I also noted that people have been coming across this bug for a while now. The
following email is describing bug 1003891
https://lists.debian.org/debian-hurd/2011/07/msg00103.html
That mail mentioned that rpctrace could be helpful somehow, so I attach the
output of that as well.
Best regards,
João
Breakpoint 1 at 0x1870: file ./runit-2.1.2/src/sv.c, line 253.
Starting program: /usr/bin/sv start cron
[New Thread 785.5]
Thread 4 hit Breakpoint 1, control (a=0x4bcc "u") at ./runit-2.1.2/src/sv.c:253
253 if (svstatus_get() <= 0) return(-1);
svstatus_get () at ./runit-2.1.2/src/sv.c:94
94 if ((fd =open_write("supervise/ok")) == -1) {
open_write (fn=0x4a8c "supervise/ok") at ./runit-2.1.2/src/open_write.c:8
8 { return open(fn,O_WRONLY | O_NDELAY); }
open64 (__path=0x4a8c "supervise/ok", __oflag=10) at
/usr/include/i386-gnu/bits/fcntl2.h:55
warning: Source file is more recent than executable.
55 return __open_alias (__path, __oflag, __va_arg_pack ());
0x011b1814 in __GI___libc_open (file=0x4a8c "supervise/ok", oflag=10) at
../sysdeps/mach/hurd/open.c:39
39 mode = va_arg (arg, mode_t);
45 cancel_oldtype = LIBC_CANCEL_ASYNC();
46 port = __file_name_lookup (file, oflag, mode);
0x0108fc82 in __file_name_lookup (file_name=0x4a8c "supervise/ok", flags=10,
mode=0) at ./hurd/hurdlookup.c:224
224 return __file_name_lookup_at (AT_FDCWD, 0, file_name, flags, mode);
0x01099985 in __file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c
"supervise/ok", flags=10, mode=0) at ./hurd/lookup-at.c:26
26 __file_name_lookup_at (int fd, int at_flags,
__x86.get_pc_thunk.bx () at ../sysdeps/i386/i686/multiarch/memset-sse2.S:97
97 BRANCH_TO_JMPTBL_ENTRY (L(table_less_32bytes))
__file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c "supervise/ok",
flags=10, mode=0) at ./hurd/lookup-at.c:36
36 err = __hurd_at_flags (&at_flags, &flags);
40 if (empty != 0 && file_name[0] == '\0')
58 if (flags & O_TMPFILE)
61 if (fd == AT_FDCWD || file_name[0] == '/')
63 err = __hurd_file_name_lookup (&_hurd_ports_use, &__getdport, 0,
0x0108f7d0 in __hurd_file_name_lookup (use_init_port=0x108df80
<_hurd_ports_use>, get_dtable_port=0x1074be0 <__getdport>, lookup=0x0,
file_name=0x4a8c "supervise/ok", flags=10, mode=0, result=0x104181c) at
./hurd/hurdlookup.c:42
42 __hurd_file_name_lookup (error_t (*use_init_port)
63 if (! lookup)
64 lookup = __dir_lookup;
66 if (file_name[0] == '\0')
69 startport = (file_name[0] == '/') ? INIT_PORT_CRDIR : INIT_PORT_CWDIR;
70 while (file_name[0] == '/')
73 if (flags & O_NOFOLLOW) /* See lookup-retry.c about O_NOFOLLOW.
*/
76 if (flags & O_DIRECTORY && (flags & O_NOFOLLOW) == 0)
$1 = 10
94 err = (*use_init_port) (startport, &lookup_op);
95 if (! err)
$2 = ESUCCESS
96 err = __hurd_file_name_lookup_retry (use_init_port, get_dtable_port,
0x0109d735 in __hurd_file_name_lookup_retry (use_init_port=0x108df80
<_hurd_ports_use>, get_dtable_port=0x1074be0 <__getdport>, lookup=0x12ea240
<__dir_lookup>, doretry=FS_RETRY_MAGICAL, retryname=0x1041388
"/run/runit/supervise/cron/ok", flags=10, mode=0, result=0x104181c) at
./hurd/lookup-retry.c:47
47 __hurd_file_name_lookup_retry (error_t (*use_init_port)
98 if (! lookup)
105 file_t startdir = MACH_PORT_NULL;
108 switch (doretry)
204 switch (retryname[0])
208 if (*result != MACH_PORT_NULL)
210 if (nloops++ >= __eloop_threshold ())
215 file_name = &retryname[1];
216 break;
373 if (MACH_PORT_VALID (*result) && *result != lastdir)
383 if (startdir != MACH_PORT_NULL)
390 err = (*use_init_port) (dirport, &lookup_op);
391 } while (! err);
105 file_t startdir = MACH_PORT_NULL;
108 switch (doretry)
116 if (nloops++ >= __eloop_threshold ())
124 if (retryname[0] == '\0'
$3 = <optimized out>
199 startdir = *result;
$4 = 0
201 break;
$5 = 13
373 if (MACH_PORT_VALID (*result) && *result != lastdir)
375 if (MACH_PORT_VALID (lastdir))
379 __mach_port_mod_refs (__mach_task_self (), lastdir,
383 if (startdir != MACH_PORT_NULL)
385 err = lookup_op (startdir);
386 __mach_port_deallocate (__mach_task_self (), startdir);
387 startdir = MACH_PORT_NULL;
391 } while (! err);
394 if (MACH_PORT_VALID (lastdir))
395 __mach_port_deallocate (__mach_task_self (), lastdir);
397 return err;
$6 = ENXIO
__file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c "supervise/ok",
flags=10, mode=0) at ./hurd/lookup-at.c:66
66 if (err)
#0 __file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c
"supervise/ok", flags=10, mode=0) at ./hurd/lookup-at.c:66
66 if (err)
#0 __file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c
"supervise/ok", flags=10, mode=0) at ./hurd/lookup-at.c:66
66 if (err)
#0 __file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c
"supervise/ok", flags=10, mode=0) at ./hurd/lookup-at.c:66
66 if (err)
#0 __file_name_lookup_at (fd=-100, at_flags=0, file_name=0x4a8c
"supervise/ok", flags=10, mode=0) at ./hurd/lookup-at.c:66
66 if (err)
$7 = ENXIO
109 __hurd_fail (err);
68 __hurd_fail (err);
__GI___libc_open (file=0x4a8c "supervise/ok", oflag=10) at
../sysdeps/mach/hurd/open.c:47
47 LIBC_CANCEL_RESET (cancel_oldtype);
49 if (port == MACH_PORT_NULL)
svstatus_get () at ./runit-2.1.2/src/sv.c:95
95 if (errno == error_nodevice) {
96 *acts == 'x' ? ok("runsv not running") : failx("runsv not
running");
main (argc=<optimized out>, argv=<optimized out>) at ./runit-2.1.2/src/sv.c:360
360 if (fchdir(curdir) == -1) fatal("unable to change to original
directory");
Continuing.
[Inferior 1 (bogus thread id 0) exited with code 01]
task6(pid773)->vm_map (0 4096 0 0 (null) 0 1 0 0 1) = 0x3 ((os/kern) no space
available)
task6(pid773)->task_get_special_port (4) = 0 7<--1(pid773)
7<--1(pid773)->exec_startup_get_info () = 0 8576 4148 288 270336 16777216 0
"sv\0start\0cron\0"
"SHELL=/bin/bash\0LD_ORIGIN_PATH=/usr/bin\0NAME=root\0PWD=/root\0LOGNAME=root\0HOME=/r"
{ 25<--8(pid773) 24<--38(pid773) 26<--41(pid773) 16<--42(pid773)} {
30<--43(pid773) 27<--44(pid773) 23<--45(pid773) 39<--46(pid773)
12<--47(pid773) (null)} {18 0 0 0 0}
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
27<--44(pid773)->dir_lookup ("etc/ld.so.cache" 1 0) = 0 1 "" 7<--48(pid773)
7<--48(pid773)->io_stat_request () = 0 {23 7 0 16391 0 1734216449 0 33188 1 0
0 32506 0 1734211782 0 1734211782 0 1734211782 0 8192 64 0 0 0 0 0 0 0 0 0 0 0}
7<--48(pid773)->io_map_request () = 0 49<--1(pid773) (null)
task6(pid773)->vm_map (0 32506 0 1 49<--1(pid773) 0 32 1 7 1) = 0 17068032
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
27<--44(pid773)->dir_lookup ("lib/i386-gnu/libc.so.0.3" 1 0) = 0 1 ""
7<--50(pid773)
7<--50(pid773)->io_read_request (-1 512) = 0
"\x7fELF\x01\x01\x01\x03\0\0\0\0\0\0\0\0\x03\0\x03\0\x01\0\0\0P6\x05\04\0\0\08\x1c'\0\0\0\0\04\0
\0\n\0(\0`\0_\0\x06\0\0\04\0\0\04\0\0\04\0\0\0@\x01\0\0@\x01\0\0\x04\0\0\0"
7<--50(pid773)->io_stat_request () = 0 {23 7 0 212599 0 1733874384 0 33261 1
0 0 2566968 0 1734211504 0 1732370223 0 1733862078 0 8192 5024 0 0 0 0 0 0 0 0
0 0 0}
task6(pid773)->vm_map (0 8192 0 1 (null) 0 0 3 7 1) = 0 17100800
7<--50(pid773)->io_map_request () = 0 49<--48(pid773) (null)
task6(pid773)->vm_map (0 2571636 0 1 49<--48(pid773) 0 32 5 7 1) = 0 17108992
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
7<--50(pid773)->io_map_request () = 0 49<--1(pid773) (null)
task6(pid773)->vm_map (19648512 20480 0 0 49<--1(pid773) 2539520 32 3 7 1) =
0x3 ((os/kern) no space available)
task6(pid773)->vm_deallocate (19648512 20480) = 0
task6(pid773)->vm_map (19648512 20480 0 0 49<--1(pid773) 2539520 32 3 7 1) =
0 19648512
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
task6(pid773)->vm_map (19668992 11636 0 0 (null) 0 0 3 7 1) = 0x3 ((os/kern)
no space available)
task6(pid773)->vm_deallocate (19668992 11636) = 0
task6(pid773)->vm_map (19668992 11636 0 0 (null) 0 0 3 7 1) = 0 19668992
task6(pid773)->vm_protect (270336 16777216 0 7) = 0
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
27<--44(pid773)->dir_lookup ("lib/i386-gnu/libmachuser.so.1" 1 0) = 0 1 ""
7<--48(pid773)
7<--48(pid773)->io_read_request (-1 512) = 0
"\x7fELF\x01\x01\x01\0\0\0\0\0\0\0\0\0\x03\0\x03\0\x01\0\0\0\0\0\0\04\0\0\0(Q\x01\0\0\0\0\04\0
\0\a\0(\0\x1a\0\x19\0\x01\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\xe8B\x01\0\xe8B\x01\0\x05\0\0\0"
7<--48(pid773)->io_stat_request () = 0 {23 7 0 212784 0 1733874394 0 33188 1
0 0 87352 0 1734211504 0 1732370223 0 1733862078 0 8192 184 0 0 0 0 0 0 0 0 0 0
0}
7<--48(pid773)->io_map_request () = 0 49<--50(pid773) (null)
task6(pid773)->vm_map (0 90124 0 1 49<--50(pid773) 0 32 5 7 1) = 0 19681280
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
7<--48(pid773)->io_map_request () = 0 49<--1(pid773) (null)
task6(pid773)->vm_map (19767296 8192 0 0 49<--1(pid773) 81920 32 3 7 1) =
0x3 ((os/kern) no space available)
task6(pid773)->vm_deallocate (19767296 8192) = 0
task6(pid773)->vm_map (19767296 8192 0 0 49<--1(pid773) 81920 32 3 7 1) = 0
19767296
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
27<--44(pid773)->dir_lookup ("lib/i386-gnu/libhurduser.so.0.3" 1 0) = 0 1 ""
7<--50(pid773)
7<--50(pid773)->io_read_request (-1 512) = 0
"\x7fELF\x01\x01\x01\0\0\0\0\0\0\0\0\0\x03\0\x03\0\x01\0\0\0\0\0\0\04\0\0\0\xa4\x01\x03\0\0\0\0\04\0
\0\a\0(\0\x1a\0\x19\0\x01\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\xb4\xfd\x02\0\xb4\xfd\x02\0\x05\0\0\0"
7<--50(pid773)->io_stat_request () = 0 {23 7 0 212671 0 1733874390 0 33188 1
0 0 198068 0 1734211504 0 1732370223 0 1733862078 0 8192 400 0 0 0 0 0 0 0 0 0
0 0}
7<--50(pid773)->io_map_request () = 0 49<--48(pid773) (null)
task6(pid773)->vm_map (0 200840 0 1 49<--48(pid773) 0 32 5 7 1) = 0 19775488
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
7<--50(pid773)->io_map_request () = 0 49<--1(pid773) (null)
task6(pid773)->vm_map (19972096 8192 0 0 49<--1(pid773) 192512 32 3 7 1) =
0x3 ((os/kern) no space available)
task6(pid773)->vm_deallocate (19972096 8192) = 0
task6(pid773)->vm_map (19972096 8192 0 0 49<--1(pid773) 192512 32 3 7 1) = 0
19972096
task6(pid773)->mach_port_deallocate (pn{ 14}) = 0
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
thread4(pid773)->i386_set_gdt (-1 {113311743 30405125}) = 0 75
task6(pid773)->mach_port_deallocate (pn{ 4}) = 0
task6(pid773)->vm_protect (19648512 12288 0 1) = 0
task6(pid773)->vm_protect (19767296 4096 0 1) = 0
task6(pid773)->vm_protect (19972096 4096 0 1) = 0
task6(pid773)->vm_protect (28672 4096 0 1) = 0
task6(pid773)->vm_protect (253952 8192 0 1) = 0
task6(pid773)->mach_port_mod_refs (pn{ 3} 1 -1) = 0
task6(pid773)->mach_port_deallocate (pn{ 2}) = 0
task6(pid773)->mach_port_deallocate (pn{ 1}) = 0
task6(pid773)->vm_map (536870912 134217728 0 0 (null) 0 0 0 7 1) = 0 536870912
task6(pid773)->vm_allocate (1 4096 1) = 0 19980288
task6(pid773)->task_set_special_port (4 (null)) = 0
task6(pid773)->vm_allocate (4 4096 1) = 0 19984384
task6(pid773)->mach_port_mod_refs (pn{ 3} 0 1) = 0
task6(pid773)->mach_port_deallocate (pn{ 3}) = 0
39<--46(pid773)->proc_getpids_request () = 0 773 772 0
39<--46(pid773)->proc_getpgrp_request (773) = 0 772
task6(pid773)->vm_allocate (17302027 4096 1) = 0 19988480
task6(pid773)->vm_allocate (19988480 4096 1) = 0 19992576
25<--8(pid773)->term_getctty () = 0 12<--47(pid773)
task6(pid773)->mach_port_deallocate (pn{ 13}) = 0
25<--8(pid773)->term_open_ctty (773 772) = 0 7<--48(pid773)
24<--38(pid773)->term_getctty () = 0 12<--47(pid773)
task6(pid773)->mach_port_deallocate (pn{ 13}) = 0
24<--38(pid773)->term_open_ctty (773 772) = 0 49<--50(pid773)
26<--41(pid773)->term_getctty () = 0 12<--47(pid773)
task6(pid773)->mach_port_deallocate (pn{ 13}) = 0
26<--41(pid773)->term_open_ctty (773 772) = 0 51<--1(pid773)
16<--42(pid773)->term_getctty () = 0xfffffed1 ((ipc/mig) bad request message
ID)
task6(pid773)->vm_deallocate (17055744 16) = 0
task6(pid773)->mach_port_allocate (1) = 0 pn{ 17}
task6(pid773)->mach_port_insert_right (pn{ 17} 53) = 0
task6(pid773)->thread_create () = 0 54<--52(pid773)
task6(pid773)->vm_allocate (0 36864 1) = 0 19996672
task6(pid773)->vm_protect (19996672 4096 0 0) = 0
thread54(pid773)->thread_set_state (1 {0 0 0 0 0 0 0 0 0 0 0 0 17424432 0 0
20033536 0}) = 0
27<--44(pid773)->dir_lookup ("dev/urandom" 9 0) = 0 1 "" 56<--55(pid773)
56<--55(pid773)->io_read_request (-1 4) = 0 "\xf2#\xfd\xfb"
task6(pid773)->vm_protect (536870912 135168 0 3) = 0
task6(pid773)->vm_protect (537006080 4096 0 3) = 0
thread54(pid773)->thread_get_state (5 17) = 0 {31 31 31 31 0 0 0 0 0 0 0 0
17424432 23 512 20033536 31}
thread54(pid773)->i386_set_gdt (75 {146866175 550498816}) = 0 75
thread54(pid773)->thread_set_state (5 {75 31 31 31 0 0 0 0 0 0 0 0 17424432 23
512 20033536 31}) = 0
thread54(pid773)->thread_resume () = 0
task6(pid773)->vm_allocate (0 4096 1) ...2
task6(pid773)->task_set_special_port (3 53<--60(pid-1)) ...59
2... = 0 17055744
59... = 0
task6(pid773)->mach_port_mod_refs (pn{ 18} 0 1) ...59
39<--46(pid773)->proc_setmsgport_request ( 53<--60(pid-1)) ...2
59... = 0
2... = 0 (null)
task6(pid773)->mach_port_deallocate (pn{ 18}) ...2
39<--46(pid773)->proc_set_arg_locations_request (17047076 17047092) ...59
2... = 0
59... = 0
task6(pid773)->mach_port_allocate (1) = 0 pn{ 21}
task6(pid773)->mach_port_insert_right (pn{ 21} 3) = 0
task6(pid773)->mach_port_allocate (1) = 0 pn{ 22}
task6(pid773)->mach_port_set_qlimit (pn{ 22} 1) = 0
39<--46(pid773)->proc_handle_exceptions_request ( 3<--62(pid-1)
61<--63(pid-1) 5 {75 31 31 31 0 0 0 0 0 0 0 0 17295296 23 0 19667744 0}) = 0
thread54(pid773)->thread_set_special_port (3 62) = 0
task6(pid773)->mach_port_deallocate (pn{ 21}) = 0
task6(pid773)->vm_deallocate (17063936 20) = 0
task6(pid773)->vm_deallocate (17059840 24) = 0
30<--43(pid773)->dir_lookup ("." 9 0) = 0 1 "" 62<--57(pid773)
62<--57(pid773)->term_getctty () = 0xfffffed1 ((ipc/mig) bad request message
ID)
27<--44(pid773)->dir_lookup ("etc/service//." 0 0) = 0 3
"/etc/runit/runsvdir/current/." (null)
27<--44(pid773)->dir_lookup ("etc/runit/runsvdir/current/." 0 0) = 0 1 ""
64<--3(pid773)
task6(pid773)->mach_port_deallocate (pn{ 9}) = 0
64<--3(pid773)->dir_lookup ("cron/." 0 0) = 0 3 "/etc/sv/cron/." (null)
27<--44(pid773)->dir_lookup ("etc/sv/cron/." 0 0) = 0 1 "" 43<--65(pid773)
task6(pid773)->mach_port_deallocate (pn{ 23}) = 0
43<--65(pid773)->dir_lookup ("supervise/ok" 10 0) = 0 3
"/run/runit/supervise/cron/ok" (null)
27<--44(pid773)->dir_lookup ("run/runit/supervise/cron/ok" 10 0) = 0 1
"runit/supervise/cron/ok" 64<--66(pid773)
task6(pid773)->mach_port_mod_refs (pn{ 23} 0 1) = 0
64<--66(pid773)->dir_lookup ("runit/supervise/cron/ok" 10 0) = 0x40000006 (No
such device or address)
task6(pid773)->mach_port_deallocate (pn{ 23}) = 0
task6(pid773)->mach_port_deallocate (pn{ 23}) = 0
49<--50(pid773)->io_write_request ("fail: cron: runsv not running\n" -1) = 0
30
62<--57(pid773)->dir_lookup ("." 128 0) = 0 1 "" 64<--3(pid773)
task6(pid773)->mach_port_deallocate (pn{ 9}) = 0
39<--46(pid773)->proc_mark_exit_request (256 0) = 0
task6(pid773)->task_terminate () = 0
Child 773 exited with 1
