GNU bug report logs - #77634
[shepherd] Test failures on GNU/Hurd

Previous Next

Full log

View this message in rfc822 format

From: Ludovic Courtès <ludo <at> gnu.org>
To: yelninei <at> tutamail.com
Cc: 77634 <77634 <at> debbugs.gnu.org>
Subject: bug#77634: [shepherd] Test failures on GNU/Hurd
Date: Tue, 15 Apr 2025 16:49:02 +0200

Hey,

yelninei <at> tutamail.com writes:

> It is still slow on 1.0.3 to do anything once its started but with 1.0.4rc1 even starting is extremely painful.
> I tried to manually add features to the system-log-service and the
> thing that causes everything to slow down drastically is the addition
> of the #:kernel-log-file (even if it is empty).
>
> Setting that to #f instead makes the test now fail considerable faster (1.8s rather than 900).

Interesting.

I cross-compiled current ‘main’ to test it in my childhurd, as an
unprivileged user, like so:

  echo '(use-modules (shepherd service system-log)) (register-services (list (system-log-service (list (endpoint (make-socket-address AF_UNIX "/home/ludo/syslog.sock") #:style SOCK_DGRAM)) #:kernel-log-file "t.conf")))' > t.conf
  ./shep/bin/shepherd -c t.conf &

I can reproduce the unresponsiveness as soon as I run ‘herd start
system-log’.

Unfortunately, rpctrace is unhelpful.  Even ‘rpctrace -o log
./shep/bin/shepherd --version’ hangs:

--8<---------------cut here---------------start------------->8---
ludo <at> childhurd ~$ rpctrace -s 10 -o log ./shep/bin/shepherd  --version
Terminated
ludo <at> childhurd ~$ tail -50 log ; echo END
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--79(pid283)->io_map_request () = 0    80<--77(pid283)  (null)
task13(pid283)-> 2089 (48619520 4096 0 0    80<--77(pid283) 4096 1 5 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (48619520 4096) = 0 
task13(pid283)-> 2089 (48619520 4096 0 0    80<--77(pid283) 4096 1 5 7 1) = 0 48619520
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--79(pid283)->io_map_request () = 0    80<--81(pid283)  (null)
task13(pid283)-> 2089 (48623616 4096 0 0    80<--81(pid283) 8192 1 1 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (48623616 4096) = 0 
task13(pid283)-> 2089 (48623616 4096 0 0    80<--81(pid283) 8192 1 1 7 1) = 0 48623616
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--79(pid283)->io_map_request () = 0    80<--77(pid283)  (null)
task13(pid283)-> 2089 (48627712 4096 0 0    80<--77(pid283) 8192 1 3 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (48627712 4096) = 0 
task13(pid283)-> 2089 (48627712 4096 0 0    80<--77(pid283) 8192 1 3 7 1) = 0 48627712
task13(pid283)-> 3206 (pn{ 35}) = 0 
task13(pid283)-> 3206 (pn{ 34}) = 0 
  17<--33(pid283)->dir_lookup ("gnu/store/" 4194305 0) = 0 1 ""    78<--81(pid283)
  78<--81(pid283)->term_getctty () = 0xfffffed1 ((ipc/mig) bad request message ID) 
  78<--81(pid283)->io_read_request (-1 512) = 0 "\x7fELF\x01\x01\x01\0\0\0"
  78<--81(pid283)->io_stat_request () = 0 {23 7 0 80111 0 1744699086 0 33133 1 0 0 375340 0 1744691226 270000000 1 0 1744691169 440000000 8192 744 0 0 0 0 0 0 0 0 0 0 0}
  78<--81(pid283)->io_map_request () = 0    80<--79(pid283)  (null)
task13(pid283)-> 2089 (0 379380 0 1    80<--79(pid283) 0 1 1 7 1) = 0 48631808
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--81(pid283)->io_map_request () = 0    80<--77(pid283)  (null)
task13(pid283)-> 2089 (48676864 204800 0 0    80<--77(pid283) 45056 1 5 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (48676864 204800) = 0 
task13(pid283)-> 2089 (48676864 204800 0 0    80<--77(pid283) 45056 1 5 7 1) = 0 48676864
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--81(pid283)->io_map_request () = 0    80<--79(pid283)  (null)
task13(pid283)-> 2089 (48881664 122880 0 0    80<--79(pid283) 249856 1 1 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (48881664 122880) = 0 
task13(pid283)-> 2089 (48881664 122880 0 0    80<--79(pid283) 249856 1 1 7 1) = 0 48881664
task13(pid283)-> 3206 (pn{ 35}) = 0 
  78<--81(pid283)->io_map_request () = 0    80<--77(pid283)  (null)
task13(pid283)-> 2089 (49004544 8192 0 0    80<--77(pid283) 368640 1 3 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2023 (49004544 8192) = 0 
task13(pid283)-> 2089 (49004544 8192 0 0    80<--77(pid283) 368640 1 3 7 1) = 0 49004544
task13(pid283)-> 3206 (pn{ 35}) = 0 
task13(pid283)-> 3206 (pn{ 34}) = 0 
task13(pid283)-> 2089 (48435200 65536 0 0  (null) 0 1 3 7 1) = 0x3 ((os/kern) no space available) 
task13(pid283)-> 2089 (48435200 65536 0 1  (null) 0 1 3 7 1) = 0 49012736
task13(pid283)-> 2012 (1 22) = 0 {0 25 183304192 6975488 0 0 0 0 1744693029 80000 0 0 0 0 0 0 0 0 1744693029 0 80000000 0}
task13(pid283)-> 2012 (3 12) = 0 {0 0 0 10000 0 0 0 0 0 0 10000000 0}
task13(pid283)-> 2012 (1 22) = 0 {0 25 183304192 6975488 0 0 0 0 1744693029 80000 0 0 0 0 0 0 0 0 1744693029 0 80000000 0}
task13(pid283)-> 2012 (3 12) = 0 {0 0 0 10000 0 0 0 0 0 0 10000000 0}
  65<--64(pid283)->io_write_request ("\0" -1) = 0 1
18... = 0 "\0"
task13(pid283)-> 2089 (49078272 471040 0 0  (null) 0 1 3 7 1) ...18
task13(pid283)-> 4204 (18820768 2 0 0 0)END
--8<---------------cut here---------------end--------------->8---

> Running the logger manually only the syslog_remote_file seems to be created. This is consistent with the log output from the test.
> I also added a pk for the message-sender to investigate.
> Difference I can see is that on Linux most of them are #f but here are #(1 \x00") instead

Yeah that’s the data coming from ‘recvfrom!’ where 1 = AF_UNIX and Linux
returns nothing.

Thanks,
Ludo’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.