0s autopkgtest [07:50:04]: starting date and time: 2025-05-02 07:50:04+0000 0s autopkgtest [07:50:04]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [07:50:04]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.6bx4rb1r/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:guile-fibers --apt-upgrade shepherd --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=guile-fibers/1.3.1-5 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-s390x --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-s390x-4.secgroup --name adt-questing-s390x-shepherd-20250502-075004-juju-7f2275-prod-proposed-migration-environment-2-7028df65-0d51-413f-b4a9-462bd9822f5c --image adt/ubuntu-questing-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-s390x -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 109s autopkgtest [07:51:53]: testbed dpkg architecture: s390x 109s autopkgtest [07:51:53]: testbed apt version: 3.0.0 109s autopkgtest [07:51:53]: @@@@@@@@@@@@@@@@@@@@ test bed setup 109s autopkgtest [07:51:53]: testbed release detected to be: None 111s autopkgtest [07:51:55]: updating testbed package index (apt update) 111s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 111s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 111s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 111s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 111s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [2202 kB] 112s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [57.4 kB] 112s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [184 kB] 112s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main s390x Packages [216 kB] 112s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe s390x Packages [1083 kB] 112s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse s390x Packages [15.9 kB] 112s Fetched 3868 kB in 1s (3149 kB/s) 113s Reading package lists... 113s autopkgtest [07:51:57]: upgrading testbed (apt dist-upgrade and autopurge) 114s Reading package lists... 114s Building dependency tree... 114s Reading state information... 114s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 114s Starting 2 pkgProblemResolver with broken count: 0 114s Done 114s Entering ResolveByKeep 114s 114s Calculating upgrade... 114s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 114s Reading package lists... 115s Building dependency tree... 115s Reading state information... 115s Starting pkgProblemResolver with broken count: 0 115s Starting 2 pkgProblemResolver with broken count: 0 115s Done 115s Solving dependencies... 115s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 117s autopkgtest [07:52:01]: testbed running kernel: Linux 6.14.0-15-generic #15-Ubuntu SMP Sun Apr 6 13:39:00 UTC 2025 118s autopkgtest [07:52:02]: @@@@@@@@@@@@@@@@@@@@ apt-source shepherd 119s Get:1 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (dsc) [2568 B] 119s Get:2 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (tar) [811 kB] 119s Get:3 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (asc) [833 B] 119s Get:4 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (diff) [8432 B] 120s gpgv: Signature made Tue Mar 4 17:03:10 2025 UTC 120s gpgv: using EDDSA key A3CC9C870B9D310ABAD4CF2F51722B08FE4745A2 120s gpgv: issuer "simon@josefsson.org" 120s gpgv: Can't check signature: No public key 120s dpkg-source: warning: cannot verify inline signature for ./shepherd_1.0.2-4.dsc: no acceptable signature found 120s autopkgtest [07:52:04]: testing package shepherd version 1.0.2-4 120s autopkgtest [07:52:04]: build not needed 121s autopkgtest [07:52:05]: test herd--help: preparing testbed 121s Reading package lists... 122s Building dependency tree... 122s Reading state information... 122s Starting pkgProblemResolver with broken count: 0 122s Starting 2 pkgProblemResolver with broken count: 0 122s Done 122s The following NEW packages will be installed: 122s guile-3.0 guile-3.0-libs guile-fibers libgc1 shepherd 122s 0 upgraded, 5 newly installed, 0 to remove and 0 not upgraded. 122s Need to get 9094 kB of archives. 122s After this operation, 64.3 MB of additional disk space will be used. 122s Get:1 http://ftpmaster.internal/ubuntu questing/main s390x libgc1 s390x 1:8.2.8-1 [93.7 kB] 122s Get:2 http://ftpmaster.internal/ubuntu questing/universe s390x guile-3.0-libs s390x 3.0.10+really3.0.10-4 [7889 kB] 123s Get:3 http://ftpmaster.internal/ubuntu questing/universe s390x guile-3.0 s390x 3.0.10+really3.0.10-4 [16.4 kB] 123s Get:4 http://ftpmaster.internal/ubuntu questing-proposed/universe s390x guile-fibers s390x 1.3.1-5 [332 kB] 123s Get:5 http://ftpmaster.internal/ubuntu questing/universe s390x shepherd s390x 1.0.2-4 [763 kB] 123s Fetched 9094 kB in 1s (8834 kB/s) 123s Selecting previously unselected package libgc1:s390x. 123s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 81472 files and directories currently installed.) 123s Preparing to unpack .../libgc1_1%3a8.2.8-1_s390x.deb ... 123s Unpacking libgc1:s390x (1:8.2.8-1) ... 123s Selecting previously unselected package guile-3.0-libs:s390x. 123s Preparing to unpack .../guile-3.0-libs_3.0.10+really3.0.10-4_s390x.deb ... 123s Unpacking guile-3.0-libs:s390x (3.0.10+really3.0.10-4) ... 124s Selecting previously unselected package guile-3.0. 124s Preparing to unpack .../guile-3.0_3.0.10+really3.0.10-4_s390x.deb ... 124s Unpacking guile-3.0 (3.0.10+really3.0.10-4) ... 124s Selecting previously unselected package guile-fibers. 124s Preparing to unpack .../guile-fibers_1.3.1-5_s390x.deb ... 124s Unpacking guile-fibers (1.3.1-5) ... 124s Selecting previously unselected package shepherd. 124s Preparing to unpack .../shepherd_1.0.2-4_s390x.deb ... 124s Unpacking shepherd (1.0.2-4) ... 124s Setting up libgc1:s390x (1:8.2.8-1) ... 124s Setting up guile-3.0-libs:s390x (3.0.10+really3.0.10-4) ... 124s Setting up guile-3.0 (3.0.10+really3.0.10-4) ... 124s update-alternatives: using /usr/lib/s390x-linux-gnu/guile/3.0/bin/guile to provide /usr/bin/guile (guile) in auto mode 124s Setting up guile-fibers (1.3.1-5) ... 124s Setting up shepherd (1.0.2-4) ... 124s Processing triggers for install-info (7.1.1-1) ... 124s Processing triggers for libc-bin (2.41-6ubuntu1) ... 124s Processing triggers for man-db (2.13.0-1) ... 125s autopkgtest [07:52:09]: test herd--help: herd --help 125s autopkgtest [07:52:09]: test herd--help: [----------------------- 125s herd [OPTIONS...] ACTION SERVICE [ARG...] 125s Apply ACTION (start, stop, status, etc.) on SERVICE with the ARGs. 125s --group=GROUP run the given program as GROUP 125s --user=USER run the given program as USER 125s -E, --environment-variable=ENVIRONMENT 125s pass the environment variable specified by ENVIRONMENT 125s -d, --working-directory=DIRECTORY 125s run service from DIRECTORY (for transient services) 125s --log-file=FILE log service output to FILE 125s -N, --service-name=NAME register new service under NAME 125s -n, --log-history=NUMBER display up to NUMBER service log lines 125s -s, --socket=FILE send commands to FILE 125s --help display this help and exit 125s --usage display short usage message and exit 125s --version display version information and exit 125s 125s Mandatory or optional arguments to long options are also mandatory or 125s optional to the corresponding short options. 125s 125s Report bugs to: bug-guix@gnu.org . 125s GNU Shepherd general home page: 125s General help using GNU software: 126s autopkgtest [07:52:10]: test herd--help: -----------------------] 126s autopkgtest [07:52:10]: test herd--help: - - - - - - - - - - results - - - - - - - - - - 126s herd--help PASS 126s autopkgtest [07:52:10]: test shepherd--help: preparing testbed 127s Reading package lists... 127s Building dependency tree... 127s Reading state information... 127s Starting pkgProblemResolver with broken count: 0 127s Starting 2 pkgProblemResolver with broken count: 0 127s Done 127s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 128s autopkgtest [07:52:12]: test shepherd--help: shepherd --help 128s autopkgtest [07:52:12]: test shepherd--help: [----------------------- 128s shepherd [OPTIONS...] 128s This is a service manager for Unix and GNU. 128s -s, --socket=FILE get commands from socket FILE or from stdin (-) 128s -c, --config=FILE read configuration from FILE 128s --pid[=FILE] when ready, write PID to FILE or stdout 128s -l, --logfile=FILE log actions in FILE 128s -I, --insecure don't ensure that the setup is secure 128s -S, --silent don't do output to stdout 128s --quiet synonym for --silent 128s --help display this help and exit 128s --usage display short usage message and exit 128s --version display version information and exit 128s 128s Mandatory or optional arguments to long options are also mandatory or 128s optional to the corresponding short options. 128s 128s Report bugs to: bug-guix@gnu.org . 128s GNU Shepherd general home page: 128s General help using GNU software: 128s autopkgtest [07:52:12]: test shepherd--help: -----------------------] 129s autopkgtest [07:52:13]: test shepherd--help: - - - - - - - - - - results - - - - - - - - - - 129s shepherd--help PASS 129s autopkgtest [07:52:13]: test herd--version: preparing testbed 129s Reading package lists... 130s Building dependency tree... 130s Reading state information... 130s Starting pkgProblemResolver with broken count: 0 130s Starting 2 pkgProblemResolver with broken count: 0 130s Done 130s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 131s autopkgtest [07:52:15]: test herd--version: herd --version 131s autopkgtest [07:52:15]: test herd--version: [----------------------- 131s herd (GNU Shepherd) 1.0.2 131s Copyright (C) 2025 the Shepherd authors 131s License GPLv3+: GNU GPL version 3 or later 131s This is free software: you are free to change and redistribute it. 131s There is NO WARRANTY, to the extent permitted by law. 131s autopkgtest [07:52:15]: test herd--version: -----------------------] 132s herd--version PASS 132s autopkgtest [07:52:16]: test herd--version: - - - - - - - - - - results - - - - - - - - - - 132s autopkgtest [07:52:16]: test shepherd--version: preparing testbed 132s Reading package lists... 132s Building dependency tree... 132s Reading state information... 132s Starting pkgProblemResolver with broken count: 0 132s Starting 2 pkgProblemResolver with broken count: 0 132s Done 133s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 133s autopkgtest [07:52:17]: test shepherd--version: shepherd --version 133s autopkgtest [07:52:17]: test shepherd--version: [----------------------- 134s shepherd (GNU Shepherd) 1.0.2 134s Copyright (C) 2025 the Shepherd authors 134s License GPLv3+: GNU GPL version 3 or later 134s This is free software: you are free to change and redistribute it. 134s There is NO WARRANTY, to the extent permitted by law. 134s autopkgtest [07:52:18]: test shepherd--version: -----------------------] 134s autopkgtest [07:52:18]: test shepherd--version: - - - - - - - - - - results - - - - - - - - - - 134s shepherd--version PASS 135s autopkgtest [07:52:19]: test tests-basic: preparing testbed 135s Reading package lists... 135s Building dependency tree... 135s Reading state information... 135s Starting pkgProblemResolver with broken count: 0 135s Starting 2 pkgProblemResolver with broken count: 0 135s Done 135s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 136s autopkgtest [07:52:20]: test tests-basic: sh -x tests/basic.sh 136s autopkgtest [07:52:20]: test tests-basic: [----------------------- 136s + shepherd --version 136s shepherd (GNU Shepherd) 1.0.2 136s Copyright (C) 2025 the Shepherd authors 136s License GPLv3+: GNU GPL version 3 or later 136s This is free software: you are free to change and redistribute it. 136s There is NO WARRANTY, to the extent permitted by law. 136s + herd --version 136s herd (GNU Shepherd) 1.0.2 136s Copyright (C) 2025 the Shepherd authors 136s License GPLv3+: GNU GPL version 3 or later 136s This is free software: you are free to change and redistribute it. 136s There is NO WARRANTY, to the extent permitted by law. 136s + socket=t-socket-2403 136s + conf=t-conf-2403 136s + confdir=t-confdir-2403 136s + datadir=t-datadir-2403 136s + log=t-log-2403 136s + stamp=t-stamp-2403 136s + pid=t-pid-2403 136s + herd=herd -s t-socket-2403 136s + trap cat t-log-2403 || true; rm -f t-socket-2403 t-conf-2403 t-stamp-2403 t-log-2403; 136s test -f t-pid-2403 && kill `cat t-pid-2403` || true; rm -f t-pid-2403 EXIT 136s + cat 136s + rm -f t-pid-2403 136s + test -f t-pid-2403 136s + sleep 0.3 136s + shepherd -I -s t-socket-2403 -c t-conf-2403 -l t-log-2403 --pid=t-pid-2403 136s GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 136s Starting service root... 136s Service root started. 136s Service root running with value #< id: 2412 command: #f>. 136s Service root has been started. 136s Configuration successfully loaded from 't-conf-2403'. 137s + test -f t-pid-2403 137s + cat t-pid-2403 137s + shepherd_pid=2412 137s + kill -0 2412 137s + test -S t-socket-2403 137s + herd -s t-socket-2403 status -n 0 137s + pristine_status=Started: 137s + root 137s Stopped: 137s - broken 137s - spawn-with-system 137s - test 137s - test-2 137s + echo Started: + root Stopped: - broken - spawn-with-system - test - test-2 137s + grep -E (Start.*root|Stop.*test) 137s Started: + root Stopped: - broken - spawn-with-system - test - test-2 137s + herd -s t-socket-2403 status root 137s + cat t-pid-2403 137s + grep PID: 2412 137s Main PID: 2412 137s + herd -s t-socket-2403 status root 137s + grep Service root started 137s 2025-05-02 07:52:20 Service root started. 137s + herd -s t-socket-2403 status root 137s + grep actions: .*eval 137s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 137s + herd+ grep actions: .*load 137s -s t-socket-2403 status root 137s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 137s + herd -s t-socket-2403 status root 137s + grep actions: .*halt 137s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 137s + herd -s t-socket-2403 graph 137s + grep "test-2" -> "test" 137s "test-2" -> "test"; 137s + herd -s t-socket-2403 start test 137s + test -f t-stamp-2403 137s + herd -s t-socket-2403 status test 137s + grep running 137s Service test has been started. 137s It is running since 07:52:21 (0 seconds ago). 137s + herd -s t-socket-2403 status root 137s + grep Service test started 137s 2025-05-02 07:52:21 Service test started. 137s + herd -s t-socket-2403 stop test 137s + test -f t-stamp-2403 137s + herd -s t-socket-2403 log 137s 2 May 2025 07:52:20 service root is being started 137s 2 May 2025 07:52:20 service root is running 137s 2 May 2025 07:52:21 service test is being started 137s 2 May 2025 07:52:21 service test is running 137s 2 May 2025 07:52:21 service test is being stopped 137s 2 May 2025 07:52:21 service test is stopped 137s + herd -s t-socket-2403 log 137s + grep service test is running 137s 2 May 2025 07:52:21 service test is running 137s + herd -s t-socket-2403 log 137s + grep service test is stopped 137s 2 May 2025 07:52:21 service test is stopped 137s + herd -s t-socket-2403 status test 137s + grep stopped 137s It is stopped since 07:52:21 (0 seconds ago). 137s + herd -s t-socket-2403 stop test 137s + herd -s t-socket-2403 stop test 137s + test -z 137s + herd -s t-socket-2403 disable test-2 137s Disabled service test-2. 137s + herd -s t-socket-2403 start test-2 137s Service test has been started. 137s Service test-2 is currently disabled. 137s herd: error: failed to start service test-2 137s + true 137s + herd -s t-socket-2403 start test-2 137s + grep test-2 is currently disabled 137s herd: error: failed to start service test-2 137s Service test-2 is currently disabled. 137s + herd -s t-socket-2403 enable test-2 137s Enabled service test-2. 137s + herd -s t-socket-2403 start test-2 137s Service test-2 has been started. 137s + wc -l 137s + test 25 -gt 0 137s + cut -c 21- 137s + grep ^$ 137s + wc -l 137s + test 0 -eq 0 137s + herd -s t-socket-2403 doc test-2 action hi 137s + grep Say hi\. 137s + herd -s t-socket-2403 hi test-2 137s hi: Say hi. 137s start 137s 137s end 137s + herd -s t-socket-2403 hi test-2 137s + grep ^start$ 137s + herd -s t-socket-2403 hi test-2 137s + grep ^end$ 137s start 137s + herdend 137s -s+ wc -l 137s t-socket-2403 hi test-2 137s + test 3 -eq 3 137s + herd -s t-socket-2403 fail test-2 137s + true 137s + herd -s t-socket-2403 enable test-2 with extra arguments 137s herd: error: exception caught while executing 'enable' on service 'test-2': 137s Wrong number of arguments to # 137s + true 137s + herd -s t-socket-2403 status test-2 137s + grep running 137s + It is running since 07:52:21 (0 seconds ago). 137s herd -s t-socket-2403 status test-2 something else that is useless 137s herd: error: exception caught while executing 'status' on service 'test-2': 137s Wrong number of arguments to # 137s + true 137s + herd -s t-socket-2403 status does-not-exist 137s herd: error: service 'does-not-exist' could not be found 137s + true 137s + herd -s t-socket-2403 status does-not-exist 137s + grep does-not-exist.*not.*found 137s + herd -s t-socket-2403 start does-not-exist 137s herd: error: service 'does-not-exist' could not be found 137s herd: error: service 'does-not-exist' could not be found 137s + true 137s + herd -s t-socket-2403 start does-not-exist 137s + grep does-not-exist.*not.*found 137s + herd -s t-socket-2403 stop does-not-exist 137s herd: error: service 'does-not-exist' could not be found 137s herd: error: service 'does-not-exist' could not be found 137s + true 137s + herd -s t-socket-2403 stop does-not-exist 137s + grep does-not-exist.*not.*found 137s herd: error: service 'does-not-exist' could not be found 137s + herd -s t-socket-2403 an-action-that-does-not-exist root 137s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 137s herd: hint: Run 'herd doc root list-actions' to list supported actions. 137s + true 137s + herd -s t-socket-2403 start broken 137s herd: error: exception caught while executing 'start' on service 'broken': 137s In procedure mkdir: No such file or directory 137s + herd -s t-socket-2403 status broken 137s + grep stopped 137s It is stopped (failing). 137s + herd -s t-socket-2403 start spawn-with-system 137s + herd -s t-socket-2403 status spawn-with-system 137s + grep running 137s Service spawn-with-system has been started. 137s It is running since 07:52:21 (0 seconds ago). 137s + herd -s t-socket-2403 status spawn-with-system 137s + grep starting from 137s 2025-05-02 07:52:21 starting from /tmp/autopkgtest.wCo11H/build.xU1/src 137s + herd -s t-socket-2403 stop spawn-with-system 137s + herd -s t-socket-2403 status spawn-with-system 137s + grep stopped 137s It is stopped since 07:52:21 (0 seconds ago). 137s + herd -s t-socket-2403 status root foo bar baz 137s herd: error: exception caught while executing 'status' on service 'root': 137s Wrong number of arguments to # 137s + true 137s + herd -s t-socket-2403 doc root action status 137s status: Return an s-expression showing information about all the services. 137s Clients such as 'herd' can read it and format it in a human-readable way. 137s + herd -s t-socket-2403 doc root action an-action-that-does-not-exist 137s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 137s herd: hint: Run 'herd doc root list-actions' to list supported actions. 137s + true 137s + herd -s t-socket-2403 doc root action an-action-that-does-not-exist 137s + grep does not have an action 'an-action-that-does-not-exist' 137s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 137s + herd -s t-socket-2403 doc root list-actions 137s + grep ^daemonize: 137s daemonize: 137s + herd -s t-socket-2403 doc root list-actions 137s + grep ^halt: 137s halt: 137s + herd -s t-socket-2403 load root /does/not/exist.scm 137s Loading /does/not/exist.scm. 137s herd: error: exception caught while executing 'load' on service 'root': 137s In procedure open-fdes: No such file or directory 137s + true 137s + herd -s t-socket-2403 unload root broken 137s Removing service 'broken'... 137s Service broken is not running. 137s Done. 137s + herd -s t-socket-2403 unload root test 137s Removing service 'test'... 137s Done. 137s + herd -s t-socket-2403 status -n 0 137s + grep -e - test-2 137s + herd -s t-socket-2403 reload root t-conf-2403 137s - test-2 137s + herd -s t-socket-2403 status -n 0 137s Service test-2 is not running. 137s Service spawn-with-system is not running. 137s Loading t-conf-2403. 137s + test Started: 137s + root 137s Stopped: 137s - broken 137s - spawn-with-system 137s - test 137s - test-2 == Started: 137s + root 137s Stopped: 137s - broken 137s - spawn-with-system 137s - test 137s - test-2 137s tests/basic.sh: 205: test: Started: 137s + root 137s Stopped: 137s - broken 137s - spawn-with-system 137s - test 137s - test-2: unexpected operator 137s + mkdir -p t-confdir-2403 137s + cat 137s + herd -s t-socket-2403 status test-loaded 137s herd: error: service 'test-loaded' could not be found 137s + true 137s + herd -s t-socket-2403 load root t-confdir-2403/some-conf.scm 137s Loading t-confdir-2403/some-conf.scm. 137s + rm t-confdir-2403/some-conf.scm 137s + grep register-services.*rest list.*deprecated t-log-2403 137s 2025-05-02 07:52:21 Passing 'register-services' services as a rest list is now deprecated. 137s + herd -s t-socket-2403 status test-loaded 137s ● Status of test-loaded: 137s It is stopped. 137s It is enabled. 137s Provides: test-loaded 137s Will not be respawned. 137s + herd -s t-socket-2403 status test-loaded 137s + grep stopped 137s It is stopped. 137s + herd -s t-socket-2403 start test-loaded 137s Greek letter λ 137s Service test-loaded has been started. 137s + herd -s t-socket-2403 status test-loaded 137s + grep -i running.*abc 137s Running value is abc. 137s 2025-05-02 07:52:21 Greek letter λ 137s + grep Greek letter t-log-2403 137s + herd -s t-socket-2403 stop test-loaded 138s + herd -s t-socket-2403 unload root test-loaded 138s Removing service 'test-loaded'... 138s Service test-loaded is not running. 138s Done. 138s + type -P pwd 138s + cat 138s + herd -s t-socket-2403 load root t-confdir-2403/some-conf.scm 138s Loading t-confdir-2403/some-conf.scm. 138s + herd -s t-socket-2403 start test-run-from-nonexistent-directory 138s Starting service test-run-from-nonexistent-directory... 138s Service test-run-from-nonexistent-directory started. 138s Service test-run-from-nonexistent-directory running with value #< id: 2671 command: ("-P: not found\npwd is a shell builtin")>. 138s Service test-run-from-nonexistent-directory has been started. 138s + herd -s t-socket-2403 status test-run-from-nonexistent-directory 138s + grep exited with code 127 138s Process exited with code 127. 138s + seq 1 10 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 eval root (getpid) 138s + grep ^[0-9] 138s + test 2412 -eq 2412 138s + herd -s t-socket-2403 unload root test-run-from-nonexistent-directory 138s Removing service 'test-run-from-nonexistent-directory'... 138s Service test-run-from-nonexistent-directory is not running. 138s Done. 138s + cat 138s + herd -s t-socket-2403 load root t-confdir-2403/some-conf.scm 138s Loading t-confdir-2403/some-conf.scm. 138s + herd -s t-socket-2403 start test-loaded 138s Starting service test-loaded... 138s Service test-loaded started. 138s Service test-loaded running with value #. 138s Service test-loaded has been started. 138s + herd -s t-socket-2403 status test-loaded 138s + grep -i running.*# 138s Running value is "#". 138s + herd -s t-socket-2403 stop test-loaded 138s + herd -s t-socket-2403 eval root (perform-service-action root-service 'unload "test-loaded") 138s Evaluating user expression (perform-service-action root-service (quote #) #). 138s Removing service 'test-loaded'... 138s Service test-loaded is not running. 138s Done. 138s "#" 138s + herd -s t-socket-2403 status test-loaded 138s herd: error: service 'test-loaded' could not be found 138s + true 138s + cat 138s + herd -s t-socket-2403 load root t-confdir-2403/some-conf.scm 138s Loading t-confdir-2403/some-conf.scm. 138s herd: error: exception caught while executing 'load' on service 'root': 138s Syntax error: 138s unknown location: source expression failed to match any pattern in form (define x y z) 138s + true 138s + herd -s t-socket-2403 status 138s + cat 138s + herd -s t-socket-2403 load root t-confdir-2403/some-conf.scm 138s Started: 138s + root 138s Stopped: 138s - broken 138s - spawn-with-system 138s - test 138s - test-2 138s Loading t-confdir-2403/some-conf.scm. 138s herd: error: exception caught while executing 'load' on service 'root': 138s Throw to key `what?!' with args `("#<>")'. 138s + true 138s + herd -s t-socket-2403 status 138s Started: 138s + root 138s Stopped: 138s - broken 138s - spawn-with-system 138s - test 138s - test-2 138s + herd -s t-socket-2403 eval root (/ 0 0) 138s Evaluating user expression (/ 0 0). 138s herd: error: exception caught while executing 'eval' on service 'root': 138s Throw to key `numerical-overflow' with args `("divide" "Numerical overflow" #f #f)'. 138s + true 138s + herd -s t-socket-2403 eval root (no closing paren 138s herd: error: exception caught while executing 'eval' on service 'root': 138s #:1:18: unexpected end of input while searching for: #\) 138s + true 138s + herd -s t-socket-2403 eval root (values) 138s Evaluating user expression (values). 138s "#" 138s + herd -s t-socket-2403 eval root ((@ (fibers) sleep) 1) 139s Evaluating user expression ((@ (fibers) sleep) 1). 139s "#" 139s + herd -s t-socket-2403 unload root all 139s Service broken is not running. 139s Service spawn-with-system is not running. 139s Service test-2 is not running. 139s Service test is not running. 139s + herd -s t-socket-2403 status 139s + grep Stopped: 139s + true 139s + herd -s t-socket-2403 status 139s + grep -e + root 139s + grep already running t-log-2403 139s + true 139s + herd -s t-socket-2403 start root 139s + grep already running 139s + grep already running t-log-2403 139s + herd -s t-socket-2403 stop root 139s + kill -0 2412 139s tests/basic.sh: 332: kill: No such process 139s 139s + test -f t-log-2403 139s + export XDG_CONFIG_HOME=t-confdir-2403 139s + export XDG_DATA_HOME=t-datadir-2403 139s + export XDG_STATE_HOME=t-datadir-2403 139s + mkdir -p t-confdir-2403/shepherd 139s + mkdir -p t-datadir-2403/shepherd 139s + root 139s Service root is already running. 139s 2025-05-02 07:52:23 Service root is already running. 139s Stopping service root... 139s Exiting. 139s + mv t-conf-2403 t-confdir-2403/shepherd/init.scm 139s + rm -f t-pid-2403 t-socket-2403 139s + test -f t-pid-2403 139s + sleep 0.3 139s + shepherd -I -s t-socket-2403 --pid=t-pid-2403 139s GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 139s Starting service root... 139s Service root started. 139s Service root running with value #< id: 2802 command: #f>. 139s Service root has been started. 139s Configuration successfully loaded from 't-confdir-2403/shepherd/init.scm'. 139s + test -f t-pid-2403 139s + herd -s t-socket-2403 start test 139s Starting service test... 139s Service test started. 139s Service test running with value #t. 139s Service test has been started. 139s + test -f t-stamp-2403 139s + herd -s t-socket-2403 status test 139s + grep running 139s It is running since 07:52:23 (0 seconds ago). 139s + herd -s t-socket-2403 stop test 139s + test -f t-stamp-2403 139s + cat t-pid-2403 139s + shepherd_pid=2802 139s + herd -s t-socket-2403 stop root 139s Stopping service root... 139s Exiting. 139s + kill -0 2802 139s tests/basic.sh: 369: kill: No such process 139s 139s + rm -rf t-confdir-2403 t-datadir-2403 139s + cat t-log-2403 139s 2025-05-02 07:52:20 GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 139s 2025-05-02 07:52:20 Starting service root... 139s 2025-05-02 07:52:20 Service root started. 139s 2025-05-02 07:52:20 Service root running with value #< id: 2412 command: #f>. 139s 2025-05-02 07:52:20 Service root has been started. 139s 2025-05-02 07:52:20 Configuration successfully loaded from 't-conf-2403'. 139s 2025-05-02 07:52:21 Starting service test... 139s 2025-05-02 07:52:21 Service test has been started. 139s 2025-05-02 07:52:21 Service test started. 139s 2025-05-02 07:52:21 Service test running with value #t. 139s 2025-05-02 07:52:21 Stopping service test... 139s 2025-05-02 07:52:21 Service test might have failed to stop. 139s 2025-05-02 07:52:21 Service test is now stopped. 139s 2025-05-02 07:52:21 Disabled service test-2. 139s 2025-05-02 07:52:21 Starting service test... 139s 2025-05-02 07:52:21 Service test has been started. 139s 2025-05-02 07:52:21 Service test started. 139s 2025-05-02 07:52:21 Service test running with value #t. 139s 2025-05-02 07:52:21 Service test-2 is currently disabled. 139s 2025-05-02 07:52:21 Service test-2 is currently disabled. 139s 2025-05-02 07:52:21 Enabled service test-2. 139s 2025-05-02 07:52:21 Starting service test-2... 139s 2025-05-02 07:52:21 Service test-2 has been started. 139s 2025-05-02 07:52:21 Service test-2 started. 139s 2025-05-02 07:52:21 Service test-2 running with value #t. 139s 2025-05-02 07:52:21 hi: Say hi. 139s 2025-05-02 07:52:21 start 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 end 139s 2025-05-02 07:52:21 start 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 end 139s 2025-05-02 07:52:21 start 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 end 139s 2025-05-02 07:52:21 start 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 end 139s 2025-05-02 07:52:21 Starting service broken... 139s 2025-05-02 07:52:21 Service broken failed to start. 139s 2025-05-02 07:52:21 Starting service spawn-with-system... 139s 2025-05-02 07:52:21 [bash] starting from /tmp/autopkgtest.wCo11H/build.xU1/src 139s 2025-05-02 07:52:21 Service spawn-with-system has been started. 139s 2025-05-02 07:52:21 Service spawn-with-system started. 139s 2025-05-02 07:52:21 Service spawn-with-system running with value #t. 139s 2025-05-02 07:52:21 Stopping service spawn-with-system... 139s 2025-05-02 07:52:21 Registering new logger for spawn-with-system. 139s 2025-05-02 07:52:21 [bash] stopping from /tmp/autopkgtest.wCo11H/build.xU1/src 139s 2025-05-02 07:52:21 Service spawn-with-system stopped. 139s 2025-05-02 07:52:21 Service spawn-with-system is now stopped. 139s 2025-05-02 07:52:21 status: Return an s-expression showing information about all the services. 139s 2025-05-02 07:52:21 Clients such as 'herd' can read it and format it in a human-readable way. 139s 2025-05-02 07:52:21 help: 139s 2025-05-02 07:52:21 Show the help message for the 'root' service. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 status: 139s 2025-05-02 07:52:21 Return an s-expression showing information about all the services. 139s 2025-05-02 07:52:21 Clients such as 'herd' can read it and format it in a human-readable way. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 halt: 139s 2025-05-02 07:52:21 Halt the system. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 power-off: 139s 2025-05-02 07:52:21 Halt the system and turn it off. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 kexec: 139s 2025-05-02 07:52:21 Reboot the system and run kexec. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 load: 139s 2025-05-02 07:52:21 Load the Scheme code from FILE into shepherd. This is potentially 139s 2025-05-02 07:52:21 dangerous. You have been warned. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 eval: 139s 2025-05-02 07:52:21 Evaluate the given Scheme expression into the shepherd. This is 139s 2025-05-02 07:52:21 potentially dangerous, be careful. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 unload: 139s 2025-05-02 07:52:21 Unload the service identified by SERVICE-NAME or all services 139s 2025-05-02 07:52:21 except for 'root' if SERVICE-NAME is 'all'. Stop services before 139s 2025-05-02 07:52:21 removing them if needed. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 reload: 139s 2025-05-02 07:52:21 Unload all services, then load from FILE-NAME into shepherd. This 139s 2025-05-02 07:52:21 is potentially dangerous. You have been warned. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 daemonize: 139s 2025-05-02 07:52:21 Go into the background. Be careful, this means that a new 139s 2025-05-02 07:52:21 process will be created, so shepherd will not get SIGCHLD signals anymore 139s 2025-05-02 07:52:21 if previously spawned children terminate. Therefore, this action should 139s 2025-05-02 07:52:21 usually only be used (if at all) *before* children get spawned for which 139s 2025-05-02 07:52:21 we want to receive these signals. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 restart: 139s 2025-05-02 07:52:21 This does not work for the 'root' service. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 help: 139s 2025-05-02 07:52:21 Show the help message for the 'root' service. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 status: 139s 2025-05-02 07:52:21 Return an s-expression showing information about all the services. 139s 2025-05-02 07:52:21 Clients such as 'herd' can read it and format it in a human-readable way. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 halt: 139s 2025-05-02 07:52:21 Halt the system. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 power-off: 139s 2025-05-02 07:52:21 Halt the system and turn it off. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 kexec: 139s 2025-05-02 07:52:21 Reboot the system and run kexec. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 load: 139s 2025-05-02 07:52:21 Load the Scheme code from FILE into shepherd. This is potentially 139s 2025-05-02 07:52:21 dangerous. You have been warned. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 eval: 139s 2025-05-02 07:52:21 Evaluate the given Scheme expression into the shepherd. This is 139s 2025-05-02 07:52:21 potentially dangerous, be careful. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 unload: 139s 2025-05-02 07:52:21 Unload the service identified by SERVICE-NAME or all services 139s 2025-05-02 07:52:21 except for 'root' if SERVICE-NAME is 'all'. Stop services before 139s 2025-05-02 07:52:21 removing them if needed. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 reload: 139s 2025-05-02 07:52:21 Unload all services, then load from FILE-NAME into shepherd. This 139s 2025-05-02 07:52:21 is potentially dangerous. You have been warned. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 daemonize: 139s 2025-05-02 07:52:21 Go into the background. Be careful, this means that a new 139s 2025-05-02 07:52:21 process will be created, so shepherd will not get SIGCHLD signals anymore 139s 2025-05-02 07:52:21 if previously spawned children terminate. Therefore, this action should 139s 2025-05-02 07:52:21 usually only be used (if at all) *before* children get spawned for which 139s 2025-05-02 07:52:21 we want to receive these signals. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 restart: 139s 2025-05-02 07:52:21 This does not work for the 'root' service. 139s 2025-05-02 07:52:21 139s 2025-05-02 07:52:21 Loading /does/not/exist.scm. 139s 2025-05-02 07:52:21 Removing service 'broken'... 139s 2025-05-02 07:52:21 Service broken is not running. 139s 2025-05-02 07:52:21 Done. 139s 2025-05-02 07:52:21 Removing service 'test'... 139s 2025-05-02 07:52:21 Stopping service test-2... 139s 2025-05-02 07:52:21 Service test-2 might have failed to stop. 139s 2025-05-02 07:52:21 Service test-2 is now stopped. 139s 2025-05-02 07:52:21 Stopping service test... 139s 2025-05-02 07:52:21 Service test might have failed to stop. 139s 2025-05-02 07:52:21 Service test is now stopped. 139s 2025-05-02 07:52:21 Done. 139s 2025-05-02 07:52:21 Service test-2 is not running. 139s 2025-05-02 07:52:21 Service spawn-with-system is not running. 139s 2025-05-02 07:52:21 Loading t-conf-2403. 139s 2025-05-02 07:52:21 Loading t-confdir-2403/some-conf.scm. 139s 2025-05-02 07:52:21 Passing 'register-services' services as a rest list is now deprecated. 139s 2025-05-02 07:52:21 Starting service test-loaded... 139s 2025-05-02 07:52:21 Greek letter λ 139s 2025-05-02 07:52:21 Service test-loaded has been started. 139s 2025-05-02 07:52:21 Service test-loaded started. 139s 2025-05-02 07:52:21 Service test-loaded running with value abc. 139s 2025-05-02 07:52:21 Stopping service test-loaded... 139s 2025-05-02 07:52:21 Service test-loaded stopped. 139s 2025-05-02 07:52:21 Service test-loaded is now stopped. 139s 2025-05-02 07:52:21 Removing service 'test-loaded'... 139s 2025-05-02 07:52:21 Service test-loaded is not running. 139s 2025-05-02 07:52:21 Done. 139s 2025-05-02 07:52:21 Loading t-confdir-2403/some-conf.scm. 139s 2025-05-02 07:52:21 Starting service test-run-from-nonexistent-directory... 139s 2025-05-02 07:52:21 Service test-run-from-nonexistent-directory started. 139s 2025-05-02 07:52:21 Failed to run "-P: not found\npwd is a shell builtin": In procedure chdir: No such file or directory 139s 2025-05-02 07:52:21 Service test-run-from-nonexistent-directory running with value #< id: 2671 command: ("-P: not found\npwd is a shell builtin")>. 139s 2025-05-02 07:52:21 Service test-run-from-nonexistent-directory has been started. 139s 2025-05-02 07:52:21 Service test-run-from-nonexistent-directory (PID 2671) exited with 127. 139s 2025-05-02 07:52:21 Service test-run-from-nonexistent-directory has been disabled. 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Evaluating user expression (getpid). 139s 2025-05-02 07:52:22 Removing service 'test-run-from-nonexistent-directory'... 139s 2025-05-02 07:52:22 Service test-run-from-nonexistent-directory is not running. 139s 2025-05-02 07:52:22 Done. 139s 2025-05-02 07:52:22 Loading t-confdir-2403/some-conf.scm. 139s 2025-05-02 07:52:22 Starting service test-loaded... 139s 2025-05-02 07:52:22 Service test-loaded started. 139s 2025-05-02 07:52:22 Service test-loaded running with value #. 139s 2025-05-02 07:52:22 Service test-loaded has been started. 139s 2025-05-02 07:52:22 Stopping service test-loaded... 139s 2025-05-02 07:52:22 Service test-loaded stopped. 139s 2025-05-02 07:52:22 Service test-loaded is now stopped. 139s 2025-05-02 07:52:22 Evaluating user expression (perform-service-action root-service (quote #) #). 139s 2025-05-02 07:52:22 Removing service 'test-loaded'... 139s 2025-05-02 07:52:22 Service test-loaded is not running. 139s 2025-05-02 07:52:22 Done. 139s 2025-05-02 07:52:22 Loading t-confdir-2403/some-conf.scm. 139s 2025-05-02 07:52:22 Loading t-confdir-2403/some-conf.scm. 139s 2025-05-02 07:52:22 Evaluating user expression (/ 0 0). 139s 2025-05-02 07:52:22 Evaluating user expression (values). 139s 2025-05-02 07:52:22 Evaluating user expression ((@ (fibers) sleep) 1). 139s 2025-05-02 07:52:23 Service broken is not running. 139s 2025-05-02 07:52:23 Service spawn-with-system is not running. 139s 2025-05-02 07:52:23 Service test-2 is not running. 139s 2025-05-02 07:52:23 Service test is not running. 139s 2025-05-02 07:52:23 Service root is already running. 139s 2025-05-02 07:52:23 Stopping service root... 139s + rm -f t-socket-2403 t-conf-2403 t-stamp-2403 t-log-2403 139s + test -f t-pid-2403 139s + cat t-pid-2403 139s + kill 2802 139s tests/basic.sh: 2: kill: No such process 139s 139s + true 139s + rm -f t-pid-2403 140s autopkgtest [07:52:24]: test tests-basic: -----------------------] 140s autopkgtest [07:52:24]: test tests-basic: - - - - - - - - - - results - - - - - - - - - - 140s tests-basic PASS 140s autopkgtest [07:52:24]: test tests-starting-status: preparing testbed 141s Reading package lists... 141s Building dependency tree... 141s Reading state information... 141s Starting pkgProblemResolver with broken count: 0 141s Starting 2 pkgProblemResolver with broken count: 0 141s Done 141s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 142s autopkgtest [07:52:26]: test tests-starting-status: sh -x tests/starting-status.sh 142s autopkgtest [07:52:26]: test tests-starting-status: [----------------------- 142s + shepherd --version 142s shepherd (GNU Shepherd) 1.0.2 142s Copyright (C) 2025 the Shepherd authors 142s License GPLv3+: GNU GPL version 3 or later 142s This is free software: you are free to change and redistribute it. 142s There is NO WARRANTY, to the extent permitted by law. 142s + herd --version 142s herd (GNU Shepherd) 1.0.2 142s Copyright (C) 2025 the Shepherd authors 142s License GPLv3+: GNU GPL version 3 or later 142s This is free software: you are free to change and redistribute it. 142s There is NO WARRANTY, to the extent permitted by law. 142s + socket=t-socket-2975 142s + conf=t-conf-2975 142s + confdir=t-confdir-2975 142s + datadir=t-datadir-2975 142s + log=t-log-2975 142s + stamp=t-stamp-2975 142s + pid=t-pid-2975 142s + herd=herd -s t-socket-2975 142s + trap cat t-log-2975 || true; rm -f t-socket-2975 t-conf-2975 t-stamp-2975 t-log-2975; 142s test -f t-pid-2975 && kill `cat t-pid-2975` || true; rm -f t-pid-2975 EXIT 142s + cat 142s + rm -f t-pid-2975 t-stamp-2975 142s + test -f t-pid-2975 142s + sleep 0.3 142s + shepherd -I -s t-socket-2975 -c t-conf-2975 -l t-log-2975 --pid=t-pid-2975 142s GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 142s Starting service root... 142s Service root started. 142s Service root running with value #< id: 2984 command: #f>. 142s Service root has been started. 142s Configuration successfully loaded from 't-conf-2975'. 142s + test -f t-pid-2975 142s + cat t-pid-2975 142s + shepherd_pid=2984 142s + herd_pid=2990 142s + herd -s t-socket-2975 status 142s + herd -s t-socket-2975 start test 142s Started: 142s + root 142s Starting: 142s ^ test 142s + herd -s t-socket-2975 status 142s + grep ^ test 142s ^ test 142s + herd -s t-socket-2975 status test 142s ● Status of test: 142s It is starting. 142s It is enabled. 142s Provides: test 142s Will not be respawned. 142s + herd -s t-socket-2975 status test 142s + grep starting 142s It is starting. 142s + herd_pid2=3007 142s + sleep 1 142s + herd -s t-socket-2975 start test 143s + kill -0 2990 143s + kill -0 3007 143s + touch t-stamp-2975 143s + n=0 143s + : 143s + herd -s t-socket-2975 status test 143s + grep running 143s + expr 0 + 1 143s + n=1 143s + test 1 -le 10 143s + sleep 1 144s Starting service test... 144s Service test has been started. 144s + : 144s + herd -s t-socket-2975 status test 144s + grep running 144s It is running since 07:52:28 (0 seconds ago). 144s + break 144s + n=0 145s + Now trying to stop a service in 'starting' state. 145s It is starting. 145s : 145s + kill -0 2990 145s tests/starting-status.sh: 91: kill: No such process 145s 145s + kill -0 3007 145s tests/starting-status.sh: 91: kill: No such process 145s 145s + break 145s + herd -s t-socket-2975 stop test 145s + test -f t-stamp-2975 145s + grep Starting service test t-log-2975 145s + wc -l 145s + test 1 = 1 145s + echo Now trying to stop a service in 'starting' state. 145s + herd_start_pid=3029 145s + herd -s t-socket-2975 start test 145s + herd -s t-socket-2975 status test 145s + grep starting 145s + herd_stop_pid1=3036 145s + herd -s+ herd_stop_pid2=3037 145s t-socket-2975 stop test 145s + seq 1 3 145s + herd -s t-socket-2975 stop test 145s + herd -s t-socket-2975 status test 145s + grep starting 145s + sleep 0.3 145s It is starting. 145s + + grep starting 145s herd -s t-socket-2975 status test 145s It is starting. 145s + sleep 0.3 145s + herd -s t-socket-2975 status test 145s + grep starting 145s It is starting. 145s + sleep 0.3 145s + grep Waiting for test to start t-log-2975 145s 2025-05-02 07:52:28 Waiting for test to start... 145s 2025-05-02 07:52:28 Waiting for test to start... 145s + touch t-stamp-2975 145s + kill -0 3029 145s + sleep 0.5 146s Service test has been started. 146s + kill -0 3029 146s tests/starting-status.sh: 131: kill: No such process 146s 146s + kill -0 3036 146s tests/starting-status.sh: 132: kill: No such process 146s 146s + kill -0 3037 146s tests/starting-status.sh: 133: kill: No such process 146s 146s + herd -s+ grep stopped 146s t-socket-2975 status test 146s It is stopped since 07:52:29 (1 second ago). 146s + herdStopping service root... 146s Exiting. 146s 2025-05-02 07:52:26 GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 146s 2025-05-02 07:52:26 Starting service root... 146s 2025-05-02 07:52:26 Service root started. 146s 2025-05-02 07:52:26 Service root running with value #< id: 2984 command: #f>. 146s 2025-05-02 07:52:26 Service root has been started. 146s 2025-05-02 07:52:26 Configuration successfully loaded from 't-conf-2975'. 146s 2025-05-02 07:52:26 Starting service test... 146s 2025-05-02 07:52:28 Service test has been started. 146s 2025-05-02 07:52:28 Service test started. 146s 2025-05-02 07:52:28 Service test running with value #t. 146s 2025-05-02 07:52:28 Stopping service test... 146s 2025-05-02 07:52:28 Service test might have failed to stop. 146s 2025-05-02 07:52:28 Service test is now stopped. 146s 2025-05-02 07:52:28 Starting service test... 146s 2025-05-02 07:52:28 Waiting for test to start... 146s 2025-05-02 07:52:28 Waiting for test to start... 146s 2025-05-02 07:52:29 Service test has been started. 146s 2025-05-02 07:52:29 Service test started. 146s 2025-05-02 07:52:29 Service test running with value #t. 146s 2025-05-02 07:52:29 Stopping service test... 146s 2025-05-02 07:52:29 Service test might have failed to stop. 146s 2025-05-02 07:52:29 Service test is now stopped. 146s 2025-05-02 07:52:30 Stopping service root... 146s 2025-05-02 07:52:30 Exiting shepherd... 146s -s t-socket-2975 stop root 146s + rm -rf t-confdir-2975 146s + rm -rf t-datadir-2975 146s + cat t-log-2975 146s + rm -f t-socket-2975 t-conf-2975 t-stamp-2975 t-log-2975 146s + test -f t-pid-2975 146s + cat t-pid-2975 146s + kill 2984 146s tests/starting-status.sh: 2: kill: No such process 146s 146s + true 146s + rm -f t-pid-2975 146s autopkgtest [07:52:30]: test tests-starting-status: -----------------------] 147s autopkgtest [07:52:31]: test tests-starting-status: - - - - - - - - - - results - - - - - - - - - - 147s tests-starting-status PASS 148s autopkgtest [07:52:32]: test tests-one-shot: preparing testbed 148s Reading package lists... 148s Building dependency tree... 148s Reading state information... 148s Starting pkgProblemResolver with broken count: 0 148s Starting 2 pkgProblemResolver with broken count: 0 148s Done 148s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 149s autopkgtest [07:52:33]: test tests-one-shot: sh -x tests/one-shot.sh 149s autopkgtest [07:52:33]: test tests-one-shot: [----------------------- 150s + shepherd --version 150s shepherd (GNU Shepherd) 1.0.2 150s Copyright (C) 2025 the Shepherd authors 150s License GPLv3+: GNU GPL version 3 or later 150s This is free software: you are free to change and redistribute it. 150s There is NO WARRANTY, to the extent permitted by law. 150s + herd --version 150s + socket=t-socket-3222 150s + conf=t-conf-3222 150s + confdir=t-confdir-3222 150s + log=t-log-3222 150s + stamp=t-stamp-3222 150s + pid=t-pid-3222 150s + herd=herd -s t-socket-3222 150s + trap cat t-log-3222 || true; rm -f t-socket-3222 t-conf-3222 t-stamp-3222 t-log-3222; 150s test -f t-pid-3222 && kill `cat t-pid-3222` || true; rm -f t-pid-3222 EXIT 150s + cat 150s + rm -f t-pid-3222 150s + test -f t-pid-3222 150s + sleep 0.3 150s + shepherd -I -s t-socket-3222 -c t-conf-3222 -l t-log-3222 --pid=t-pid-3222 150s herd (GNU Shepherd) 1.0.2 150s Copyright (C) 2025 the Shepherd authors 150s License GPLv3+: GNU GPL version 3 or later 150s This is free software: you are free to change and redistribute it. 150s There is NO WARRANTY, to the extent permitted by law. 150s GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 150s Starting service root... 150s Service root started. 150s Service root running with value #< id: 3231 command: #f>. 150s Service root has been started. 150s Configuration successfully loaded from 't-conf-3222'. 150s Starting service one-shotty... 150s Service one-shotty started. 150s Service one-shotty running with value #t. 150s Service one-shotty has been started. 150s Starting service a... 150s Service a started. 150s Service a running with value #t. 150s Service a has been started. 150s Starting service b... 150s Service b started. 150s Service b running with value #t. 150s Service b has been started. 150s Starting service c... 150s Service c started. 150s Service c running with value #t. 150s Service c has been started. 150s Successfully started 3 services in the background. 150s + test -f t-pid-3222 150s + cat t-pid-3222 150s + shepherd_pid=3231 150s + kill -0 3231 150s + test -S t-socket-3222 150s + herd -s t-socket-3222 start always-fail 150s Starting service always-fail... 150s Service always-fail failed to start. 150s Service always-fail could not be started. 150s herd: error: failed to start service always-fail 150s + true 150s + rm -f t-stamp-3222 150s + herd -s t-socket-3222 start test 150s Starting service test... 150s Service test started. 150s Service test running with value #t. 150s Service test has been started. 150s + test -f t-stamp-3222 150s + herd -s t-socket-3222 status test 150s + grep stopped.*one-shot 150s It is stopped (one-shot). 150s 2025-05-02 07:52:34 Service test started. 150s 2025-05-02 07:52:34 Service test has been started. 150s + grep test.*started t-log-3222 150s + herd -s t-socket-3222 stop test 150s + rm -f t-stamp-3222 150s + herd -s t-socket-3222 start test 150s Service test has been started. 150s + test -f t-stamp-3222 150s + herd -s t-socket-3222 status test 150s + grep stopped.*one-shot 150s It is stopped (one-shot). 150s 2025-05-02 07:52:34 Service test started. 150s 2025-05-02 07:52:34 Service test has been started. 150s 2025-05-02 07:52:34 Service test has been started. 150s 2025-05-02 07:52:34 Service test started. 150s + grep test.*started t-log-3222 150s + herd -s t-socket-3222 stop test 150s + rm -f t-stamp-3222 150s + herd -s t-socket-3222 start test 150s Service test has been started. 150s + test -f t-stamp-3222 150s + herd -s t-socket-3222 status test 150s + grep stopped.*one-shot 150s + grep test.*started t-log-3222 150s + herd -s t-socket-3222 stop test 150s It is stopped (one-shot). 150s 2025-05-02 07:52:34 Service test started. 150s 2025-05-02 07:52:34 Service test has been started. 150s 2025-05-02 07:52:34 Service test has been started. 150s 2025-05-02 07:52:34 Service test started. 150s 2025-05-02 07:52:34 Service test has been started. 150s 2025-05-02 07:52:34 Service test started. 150s + herd -s t-socket-3222 status 150s + grep -i ^one-shot 150s One-shot: 150s + herd -s t-socket-3222 status 150s Started: 150s + a 150s + b 150s + c 150s + root 150s Stopped: 150s - test-2 150s One-shot: 150s * always-fail 150s * one-shotty 150s * test 150s + rm -f t-stamp-3222 t-stamp-3222-2 150s + herd -s t-socket-3222 start test-2 150s Service test has been started. 150s Service test-2 has been started. 150s + test -f t-stamp-3222 150s + test -f t-stamp-3222-2 150s + herd -s t-socket-3222 status test 150s + grep stopped.*one-shot 150s It is stopped (one-shot). 150s + herd -s t-socket-3222 status test-2 150s + grep running 150s It is running since 07:52:34 (0 seconds ago). 150s + herd -s t-socket-3222 stop test-2 150s + test -f t-stamp-3222-2 150s + true 150s + grep Starting service one-shotty t-log-3222 150s + wc -l 150s + test 1 -eq 1 150s + herd -s t-socket-3222 stop a 150s Stopping service c... 150s Service c stopped. 150s Service c is now stopped. 150s Stopping service b... 150s Service b stopped. 150s Service b is now stopped. 150s Stopping service a... 150s Service a stopped. 150s Service a is now stopped. 150s + herd -s t-socket-3222 start c 150s Starting service one-shotty... 150s Service one-shotty started. 150s Service one-shotty running with value #t. 150s Starting service a... 150s Service a started. 150s Service a running with value #t. 150s Starting service b... 150s Service b started. 150s Service b running with value #t. 150s Starting service c... 150s Service c started. 150s Service c running with value #t. 150s Service one-shotty has been started. 150s Service a has been started. 150s Service b has been started. 150s Service c has been started. 150s Stopping service c... 150s Service c stopped. 150s Service c is now stopped. 150s Stopping service b... 150s Service b stopped. 150s Service b is now stopped. 150s Stopping service a... 150s Service a stopped. 150s Service a is now stopped. 150s Starting service one-shotty... 150s Service one-shotty started. 150s Service one-shotty running with value #t. 150s Starting service a... 150s Service a started. 150s Service a running with value #t. 150s Starting service b... 150s Service b started. 150s Service b running with value #t. 150s Starting service c... 150s Service c started. 150s Service c running with value #t. 150s Service one-shotty has been started. 150s Service a has been started. 150s Service b has been started. 150s Service c has been started. 150s + grep Starting service one-shotty t-log-3222 150s + wc -l 150s + test 2 -eq 2 150s + herd -s t-socket-3222 stop a 150s + herd -s t-socket-3222 start c 150s + grep Starting service one-shotty t-log-3222 150s + wc -l 150s + test 3 -eq 3 150s + herd -s t-socket-3222 start one-shotty 150s + grep Starting service one-shotty+ wc -l 150s t-log-3222 150s + test 4 -eq 4 150s + cat 150s + rm -f t-stamp-3222 150s + herd -s t-socket-3222 load root t-conf-3222 150s + grep Service third started t-log-3222 150s + sleep 0.5 150s Starting service one-shotty... 150s Service one-shotty started. 150s Service one-shotty running with value #t. 150s Service one-shotty has been started. 150s Loading t-conf-3222. 151s + grep Service third started t-log-3222 151s + sleep 0.5 151s + grep Service third started t-log-3222 151s + sleep 0.5 152s + grep Service third started t-log-3222 152s + sleep 0.5 152s + grep Service third started t-log-3222 152s 2025-05-02 07:52:36 Service third started. 152s + cat t-stamp-3222 152s + test third = third 152s + herd -s t-socket-3222 start fourth 152s herd: error: failed to start service fourth 152s Service always-fail could not be started. 152s Service fourth depends on always-fail. 152s + herd -s t-socket-3222 start fourth 152s herd: error: failed to start service fourth 152s Service always-fail could not be started. 152s Service fourth depends on always-fail. 152s + herd -s t-socket-3222 stop root 152s Stopping service root... 152s Stopping service c... 152s + cat t-log-3222 152s Service c stopped. 152s Service c is now stopped. 152s Stopping service b... 152s Service b stopped. 152s Service b is now stopped. 152s Stopping service a... 152s Service a stopped. 152s Service a is now stopped. 152s Exiting. 152s + rm -f t-socket-3222 t-conf-3222 t-stamp-3222 t-log-3222 152s + test -f t-pid-3222 152s + cat t-pid-3222 152s + kill 3231 152s tests/one-shot.sh: 2: kill: No such process 152s 152s + true 152s + rm -f t-pid-3222 152s 2025-05-02 07:52:34 GNU Shepherd 1.0.2 (Guile 3.0.10, s390x-ibm-linux-gnu) 152s 2025-05-02 07:52:34 Starting service root... 152s 2025-05-02 07:52:34 Service root started. 152s 2025-05-02 07:52:34 Service root running with value #< id: 3231 command: #f>. 152s 2025-05-02 07:52:34 Service root has been started. 152s 2025-05-02 07:52:34 Configuration successfully loaded from 't-conf-3222'. 152s 2025-05-02 07:52:34 Starting service one-shotty... 152s 2025-05-02 07:52:34 Service one-shotty started. 152s 2025-05-02 07:52:34 Service one-shotty running with value #t. 152s 2025-05-02 07:52:34 Service one-shotty has been started. 152s 2025-05-02 07:52:34 Starting service a... 152s 2025-05-02 07:52:34 Service a started. 152s 2025-05-02 07:52:34 Service a running with value #t. 152s 2025-05-02 07:52:34 Service a has been started. 152s 2025-05-02 07:52:34 Starting service b... 152s 2025-05-02 07:52:34 Service b started. 152s 2025-05-02 07:52:34 Service b running with value #t. 152s 2025-05-02 07:52:34 Service b has been started. 152s 2025-05-02 07:52:34 Starting service c... 152s 2025-05-02 07:52:34 Service c started. 152s 2025-05-02 07:52:34 Service c running with value #t. 152s 2025-05-02 07:52:34 Service c has been started. 152s 2025-05-02 07:52:34 Successfully started 3 services in the background. 152s 2025-05-02 07:52:34 Starting service always-fail... 152s 2025-05-02 07:52:34 Service always-fail failed to start. 152s 2025-05-02 07:52:34 Service always-fail could not be started. 152s 2025-05-02 07:52:34 Starting service test... 152s 2025-05-02 07:52:34 Service test started. 152s 2025-05-02 07:52:34 Service test running with value #t. 152s 2025-05-02 07:52:34 Service test has been started. 152s 2025-05-02 07:52:34 Starting service test... 152s 2025-05-02 07:52:34 Service test has been started. 152s 2025-05-02 07:52:34 Service test started. 152s 2025-05-02 07:52:34 Service test running with value #t. 152s 2025-05-02 07:52:34 Starting service test... 152s 2025-05-02 07:52:34 Service test has been started. 152s 2025-05-02 07:52:34 Service test started. 152s 2025-05-02 07:52:34 Service test running with value #t. 152s 2025-05-02 07:52:34 Starting service test... 152s 2025-05-02 07:52:34 Service test has been started. 152s 2025-05-02 07:52:34 Service test started. 152s 2025-05-02 07:52:34 Service test running with value #t. 152s 2025-05-02 07:52:34 Starting service test-2... 152s 2025-05-02 07:52:34 Service test-2 has been started. 152s 2025-05-02 07:52:34 Service test-2 started. 152s 2025-05-02 07:52:34 Service test-2 running with value #t. 152s 2025-05-02 07:52:34 Stopping service test-2... 152s 2025-05-02 07:52:34 Service test-2 stopped. 152s 2025-05-02 07:52:34 Service test-2 is now stopped. 152s 2025-05-02 07:52:34 Stopping service c... 152s 2025-05-02 07:52:34 Service c stopped. 152s 2025-05-02 07:52:34 Service c is now stopped. 152s 2025-05-02 07:52:34 Stopping service b... 152s 2025-05-02 07:52:34 Service b stopped. 152s 2025-05-02 07:52:34 Service b is now stopped. 152s 2025-05-02 07:52:34 Stopping service a... 152s 2025-05-02 07:52:34 Service a stopped. 152s 2025-05-02 07:52:34 Service a is now stopped. 152s 2025-05-02 07:52:34 Starting service one-shotty... 152s 2025-05-02 07:52:34 Service one-shotty has been started. 152s 2025-05-02 07:52:34 Service one-shotty started. 152s 2025-05-02 07:52:34 Service one-shotty running with value #t. 152s 2025-05-02 07:52:34 Starting service a... 152s 2025-05-02 07:52:34 Service a has been started. 152s 2025-05-02 07:52:34 Service a started. 152s 2025-05-02 07:52:34 Service a running with value #t. 152s 2025-05-02 07:52:34 Starting service b... 152s 2025-05-02 07:52:34 Service b has been started. 152s 2025-05-02 07:52:34 Service b started. 152s 2025-05-02 07:52:34 Service b running with value #t. 152s 2025-05-02 07:52:34 Starting service c... 152s 2025-05-02 07:52:34 Service c has been started. 152s 2025-05-02 07:52:34 Service c started. 152s 2025-05-02 07:52:34 Service c running with value #t. 152s 2025-05-02 07:52:34 Stopping service c... 152s 2025-05-02 07:52:34 Service c stopped. 152s 2025-05-02 07:52:34 Service c is now stopped. 152s 2025-05-02 07:52:34 Stopping service b... 152s 2025-05-02 07:52:34 Service b stopped. 152s 2025-05-02 07:52:34 Service b is now stopped. 152s 2025-05-02 07:52:34 Stopping service a... 152s 2025-05-02 07:52:34 Service a stopped. 152s 2025-05-02 07:52:34 Service a is now stopped. 152s 2025-05-02 07:52:34 Starting service one-shotty... 152s 2025-05-02 07:52:34 Service one-shotty has been started. 152s 2025-05-02 07:52:34 Service one-shotty started. 152s 2025-05-02 07:52:34 Service one-shotty running with value #t. 152s 2025-05-02 07:52:34 Starting service a... 152s 2025-05-02 07:52:34 Service a has been started. 152s 2025-05-02 07:52:34 Service a started. 152s 2025-05-02 07:52:34 Service a running with value #t. 152s 2025-05-02 07:52:34 Starting service b... 152s 2025-05-02 07:52:34 Service b has been started. 152s 2025-05-02 07:52:34 Service b started. 152s 2025-05-02 07:52:34 Service b running with value #t. 152s 2025-05-02 07:52:34 Starting service c... 152s 2025-05-02 07:52:34 Service c has been started. 152s 2025-05-02 07:52:34 Service c started. 152s 2025-05-02 07:52:34 Service c running with value #t. 152s 2025-05-02 07:52:34 Starting service one-shotty... 152s 2025-05-02 07:52:34 Service one-shotty has been started. 152s 2025-05-02 07:52:34 Service one-shotty started. 152s 2025-05-02 07:52:34 Service one-shotty running with value #t. 152s 2025-05-02 07:52:34 Loading t-conf-3222. 152s 2025-05-02 07:52:34 Starting service first... 152s 2025-05-02 07:52:35 Service first has been started. 152s 2025-05-02 07:52:35 Service first started. 152s 2025-05-02 07:52:35 Service first running with value #t. 152s 2025-05-02 07:52:35 Starting service second... 152s 2025-05-02 07:52:36 Service second has been started. 152s 2025-05-02 07:52:36 Service second started. 152s 2025-05-02 07:52:36 Service second running with value #t. 152s 2025-05-02 07:52:36 Starting service third... 152s 2025-05-02 07:52:36 Service third started. 152s 2025-05-02 07:52:36 Service third running with value #t. 152s 2025-05-02 07:52:36 Service third has been started. 152s 2025-05-02 07:52:36 Successfully started 3 services in the background. 152s 2025-05-02 07:52:36 Starting service always-fail... 152s 2025-05-02 07:52:36 Service always-fail could not be started. 152s 2025-05-02 07:52:36 Service always-fail failed to start. 152s 2025-05-02 07:52:36 Service fourth depends on always-fail. 152s 2025-05-02 07:52:36 Starting service always-fail... 152s 2025-05-02 07:52:36 Service always-fail could not be started. 152s 2025-05-02 07:52:36 Service always-fail failed to start. 152s 2025-05-02 07:52:36 Service fourth depends on always-fail. 152s 2025-05-02 07:52:36 Stopping service root... 152s 2025-05-02 07:52:36 Exiting shepherd... 152s 2025-05-02 07:52:36 Service always-fail is not running. 152s 2025-05-02 07:52:36 Service test is not running. 152s 2025-05-02 07:52:36 Service test-2 is not running. 152s 2025-05-02 07:52:36 Service one-shotty is not running. 152s 2025-05-02 07:52:36 Stopping service c... 152s 2025-05-02 07:52:36 Service c stopped. 152s 2025-05-02 07:52:36 Service c is now stopped. 152s 2025-05-02 07:52:36 Stopping service b... 152s 2025-05-02 07:52:36 Service b stopped. 152s 2025-05-02 07:52:36 Service b is now stopped. 152s 2025-05-02 07:52:36 Stopping service a... 152s 2025-05-02 07:52:36 Service a stopped. 152s 2025-05-02 07:52:36 Service a is now stopped. 152s 2025-05-02 07:52:36 Service b is not running. 152s 2025-05-02 07:52:36 Service c is not running. 152s 2025-05-02 07:52:36 Service first is not running. 152s 2025-05-02 07:52:36 Service second is not running. 153s autopkgtest [07:52:37]: test tests-one-shot: -----------------------] 153s autopkgtest [07:52:37]: test tests-one-shot: - - - - - - - - - - results - - - - - - - - - - 153s tests-one-shot PASS 153s autopkgtest [07:52:37]: @@@@@@@@@@@@@@@@@@@@ summary 153s herd--help PASS 153s shepherd--help PASS 153s herd--version PASS 153s shepherd--version PASS 153s tests-basic PASS 153s tests-starting-status PASS 153s tests-one-shot PASS 171s nova [W] Using flock in prodstack6-s390x 171s flock: timeout while waiting to get lock 171s Creating nova instance adt-questing-s390x-shepherd-20250502-075004-juju-7f2275-prod-proposed-migration-environment-2-7028df65-0d51-413f-b4a9-462bd9822f5c from image adt/ubuntu-questing-s390x-server-20250502.img (UUID 632ecfca-a19d-4f3a-af48-b7883fa0ccf2)... 171s nova [W] Timed out waiting for 670e20d1-3e47-49e3-b605-60ab5f363054 to get deleted.