0s autopkgtest [04:50:45]: starting date and time: 2025-05-02 04:50:45+0000 0s autopkgtest [04:50:45]: git checkout: 9986aa8c Merge branch 'skia/fix_network_interface' into 'ubuntu/production' 0s autopkgtest [04:50:45]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.xkhsxzo8/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-ppc64el --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-ppc64el-9.secgroup --name adt-questing-ppc64el-shepherd-20250502-045045-juju-7f2275-prod-proposed-migration-environment-2-20de6f5f-bd04-4c2d-b594-6e13398558ed --image adt/ubuntu-questing-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-ppc64el -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 128s autopkgtest [04:52:53]: testbed dpkg architecture: ppc64el 128s autopkgtest [04:52:53]: testbed apt version: 3.0.0 128s autopkgtest [04:52:53]: @@@@@@@@@@@@@@@@@@@@ test bed setup 128s autopkgtest [04:52:53]: testbed release detected to be: None 129s autopkgtest [04:52:54]: updating testbed package index (apt update) 130s Get:1 http://ftpmaster.internal/ubuntu questing-proposed InRelease [110 kB] 130s Hit:2 http://ftpmaster.internal/ubuntu questing InRelease 130s Hit:3 http://ftpmaster.internal/ubuntu questing-updates InRelease 130s Hit:4 http://ftpmaster.internal/ubuntu questing-security InRelease 130s Get:5 http://ftpmaster.internal/ubuntu questing-proposed/main Sources [184 kB] 130s Get:6 http://ftpmaster.internal/ubuntu questing-proposed/multiverse Sources [57.4 kB] 130s Get:7 http://ftpmaster.internal/ubuntu questing-proposed/universe Sources [2202 kB] 130s Get:8 http://ftpmaster.internal/ubuntu questing-proposed/main ppc64el Packages [221 kB] 130s Get:9 http://ftpmaster.internal/ubuntu questing-proposed/universe ppc64el Packages [1320 kB] 130s Get:10 http://ftpmaster.internal/ubuntu questing-proposed/multiverse ppc64el Packages [16.5 kB] 131s Fetched 4111 kB in 1s (2943 kB/s) 132s Reading package lists... 133s autopkgtest [04:52:58]: upgrading testbed (apt dist-upgrade and autopurge) 133s Reading package lists... 133s Building dependency tree... 133s Reading state information... 134s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 134s Starting 2 pkgProblemResolver with broken count: 0 134s Done 134s Entering ResolveByKeep 134s 135s Calculating upgrade... 135s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 135s Reading package lists... 135s Building dependency tree... 135s Reading state information... 136s Starting pkgProblemResolver with broken count: 0 136s Starting 2 pkgProblemResolver with broken count: 0 136s Done 136s Solving dependencies... 136s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 139s autopkgtest [04:53:04]: testbed running kernel: Linux 6.14.0-15-generic #15-Ubuntu SMP Sun Apr 6 14:52:42 UTC 2025 139s autopkgtest [04:53:04]: @@@@@@@@@@@@@@@@@@@@ apt-source shepherd 141s Get:1 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (dsc) [2568 B] 141s Get:2 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (tar) [811 kB] 141s Get:3 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (asc) [833 B] 141s Get:4 http://ftpmaster.internal/ubuntu questing/universe shepherd 1.0.2-4 (diff) [8432 B] 141s gpgv: Signature made Tue Mar 4 17:03:10 2025 UTC 141s gpgv: using EDDSA key A3CC9C870B9D310ABAD4CF2F51722B08FE4745A2 141s gpgv: issuer "simon@josefsson.org" 141s gpgv: Can't check signature: No public key 141s dpkg-source: warning: cannot verify inline signature for ./shepherd_1.0.2-4.dsc: no acceptable signature found 142s autopkgtest [04:53:07]: testing package shepherd version 1.0.2-4 142s autopkgtest [04:53:07]: build not needed 143s autopkgtest [04:53:08]: test herd--help: preparing testbed 143s Reading package lists... 143s Building dependency tree... 143s Reading state information... 144s Starting pkgProblemResolver with broken count: 0 144s Starting 2 pkgProblemResolver with broken count: 0 144s Done 144s The following NEW packages will be installed: 144s guile-3.0 guile-3.0-libs guile-fibers libgc1 shepherd 144s 0 upgraded, 5 newly installed, 0 to remove and 0 not upgraded. 144s Need to get 9186 kB of archives. 144s After this operation, 65.0 MB of additional disk space will be used. 144s Get:1 http://ftpmaster.internal/ubuntu questing/main ppc64el libgc1 ppc64el 1:8.2.8-1 [112 kB] 145s Get:2 http://ftpmaster.internal/ubuntu questing/universe ppc64el guile-3.0-libs ppc64el 3.0.10+really3.0.10-4 [7946 kB] 145s Get:3 http://ftpmaster.internal/ubuntu questing/universe ppc64el guile-3.0 ppc64el 3.0.10+really3.0.10-4 [16.4 kB] 145s Get:4 http://ftpmaster.internal/ubuntu questing-proposed/universe ppc64el guile-fibers ppc64el 1.3.1-5 [332 kB] 145s Get:5 http://ftpmaster.internal/ubuntu questing/universe ppc64el shepherd ppc64el 1.0.2-4 [780 kB] 146s Fetched 9186 kB in 1s (6810 kB/s) 146s Selecting previously unselected package libgc1:ppc64el. 146s (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 ... 107206 files and directories currently installed.) 146s Preparing to unpack .../libgc1_1%3a8.2.8-1_ppc64el.deb ... 146s Unpacking libgc1:ppc64el (1:8.2.8-1) ... 146s Selecting previously unselected package guile-3.0-libs:ppc64el. 146s Preparing to unpack .../guile-3.0-libs_3.0.10+really3.0.10-4_ppc64el.deb ... 146s Unpacking guile-3.0-libs:ppc64el (3.0.10+really3.0.10-4) ... 146s Selecting previously unselected package guile-3.0. 146s Preparing to unpack .../guile-3.0_3.0.10+really3.0.10-4_ppc64el.deb ... 146s Unpacking guile-3.0 (3.0.10+really3.0.10-4) ... 146s Selecting previously unselected package guile-fibers. 146s Preparing to unpack .../guile-fibers_1.3.1-5_ppc64el.deb ... 146s Unpacking guile-fibers (1.3.1-5) ... 146s Selecting previously unselected package shepherd. 146s Preparing to unpack .../shepherd_1.0.2-4_ppc64el.deb ... 146s Unpacking shepherd (1.0.2-4) ... 147s Setting up libgc1:ppc64el (1:8.2.8-1) ... 147s Setting up guile-3.0-libs:ppc64el (3.0.10+really3.0.10-4) ... 147s Setting up guile-3.0 (3.0.10+really3.0.10-4) ... 147s update-alternatives: using /usr/lib/powerpc64le-linux-gnu/guile/3.0/bin/guile to provide /usr/bin/guile (guile) in auto mode 147s Setting up guile-fibers (1.3.1-5) ... 147s Setting up shepherd (1.0.2-4) ... 147s Processing triggers for install-info (7.1.1-1) ... 147s Processing triggers for libc-bin (2.41-6ubuntu1) ... 147s Processing triggers for man-db (2.13.0-1) ... 148s autopkgtest [04:53:13]: test herd--help: herd --help 148s autopkgtest [04:53:13]: test herd--help: [----------------------- 149s herd [OPTIONS...] ACTION SERVICE [ARG...] 149s Apply ACTION (start, stop, status, etc.) on SERVICE with the ARGs. 149s --group=GROUP run the given program as GROUP 149s --user=USER run the given program as USER 149s -E, --environment-variable=ENVIRONMENT 149s pass the environment variable specified by ENVIRONMENT 149s -d, --working-directory=DIRECTORY 149s run service from DIRECTORY (for transient services) 149s --log-file=FILE log service output to FILE 149s -N, --service-name=NAME register new service under NAME 149s -n, --log-history=NUMBER display up to NUMBER service log lines 149s -s, --socket=FILE send commands to FILE 149s --help display this help and exit 149s --usage display short usage message and exit 149s --version display version information and exit 149s 149s Mandatory or optional arguments to long options are also mandatory or 149s optional to the corresponding short options. 149s 149s Report bugs to: bug-guix@gnu.org . 149s GNU Shepherd general home page: 149s General help using GNU software: 149s autopkgtest [04:53:14]: test herd--help: -----------------------] 149s autopkgtest [04:53:14]: test herd--help: - - - - - - - - - - results - - - - - - - - - - 149s herd--help PASS 150s autopkgtest [04:53:15]: test shepherd--help: preparing testbed 150s Reading package lists... 150s Building dependency tree... 150s Reading state information... 151s Starting pkgProblemResolver with broken count: 0 151s Starting 2 pkgProblemResolver with broken count: 0 151s Done 151s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 152s autopkgtest [04:53:17]: test shepherd--help: shepherd --help 152s autopkgtest [04:53:17]: test shepherd--help: [----------------------- 152s shepherd [OPTIONS...] 152s This is a service manager for Unix and GNU. 152s -s, --socket=FILE get commands from socket FILE or from stdin (-) 152s -c, --config=FILE read configuration from FILE 152s --pid[=FILE] when ready, write PID to FILE or stdout 152s -l, --logfile=FILE log actions in FILE 152s -I, --insecure don't ensure that the setup is secure 152s -S, --silent don't do output to stdout 152s --quiet synonym for --silent 152s --help display this help and exit 152s --usage display short usage message and exit 152s --version display version information and exit 152s 152s Mandatory or optional arguments to long options are also mandatory or 152s optional to the corresponding short options. 152s 152s Report bugs to: bug-guix@gnu.org . 152s GNU Shepherd general home page: 152s General help using GNU software: 153s autopkgtest [04:53:18]: test shepherd--help: -----------------------] 153s autopkgtest [04:53:18]: test shepherd--help: - - - - - - - - - - results - - - - - - - - - - 153s shepherd--help PASS 153s autopkgtest [04:53:18]: test herd--version: preparing testbed 154s Reading package lists... 154s Building dependency tree... 154s Reading state information... 154s Starting pkgProblemResolver with broken count: 0 154s Starting 2 pkgProblemResolver with broken count: 0 154s Done 155s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 156s autopkgtest [04:53:21]: test herd--version: herd --version 156s autopkgtest [04:53:21]: test herd--version: [----------------------- 156s herd (GNU Shepherd) 1.0.2 156s Copyright (C) 2025 the Shepherd authors 156s License GPLv3+: GNU GPL version 3 or later 156s This is free software: you are free to change and redistribute it. 156s There is NO WARRANTY, to the extent permitted by law. 156s autopkgtest [04:53:21]: test herd--version: -----------------------] 157s autopkgtest [04:53:22]: test herd--version: - - - - - - - - - - results - - - - - - - - - - 157s herd--version PASS 158s autopkgtest [04:53:23]: test shepherd--version: preparing testbed 158s Reading package lists... 158s Building dependency tree... 158s Reading state information... 159s Starting pkgProblemResolver with broken count: 0 159s Starting 2 pkgProblemResolver with broken count: 0 159s Done 160s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 160s autopkgtest [04:53:25]: test shepherd--version: shepherd --version 160s autopkgtest [04:53:25]: test shepherd--version: [----------------------- 161s shepherd (GNU Shepherd) 1.0.2 161s Copyright (C) 2025 the Shepherd authors 161s License GPLv3+: GNU GPL version 3 or later 161s This is free software: you are free to change and redistribute it. 161s There is NO WARRANTY, to the extent permitted by law. 161s autopkgtest [04:53:26]: test shepherd--version: -----------------------] 162s autopkgtest [04:53:27]: test shepherd--version: - - - - - - - - - - results - - - - - - - - - - 162s shepherd--version PASS 162s autopkgtest [04:53:27]: test tests-basic: preparing testbed 162s Reading package lists... 163s Building dependency tree... 163s Reading state information... 163s Starting pkgProblemResolver with broken count: 0 163s Starting 2 pkgProblemResolver with broken count: 0 163s Done 164s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 165s autopkgtest [04:53:30]: test tests-basic: sh -x tests/basic.sh 165s autopkgtest [04:53:30]: test tests-basic: [----------------------- 165s + shepherd --version 165s shepherd (GNU Shepherd) 1.0.2 165s Copyright (C) 2025 the Shepherd authors 165s License GPLv3+: GNU GPL version 3 or later 165s This is free software: you are free to change and redistribute it. 165s There is NO WARRANTY, to the extent permitted by law. 165s + herd --version 165s + socket=t-socket-2550 165s + conf=t-conf-2550 165s + confdir=t-confdir-2550 165s + datadir=t-datadir-2550 165s + log=t-log-2550 165s + stamp=t-stamp-2550 165s + pid=t-pid-2550 165s + herd=herd -s t-socket-2550 165s + trap cat t-log-2550 || true; rm -f t-socket-2550 t-conf-2550 t-stamp-2550 t-log-2550; 165s test -f t-pid-2550 && kill `cat t-pid-2550` || true; rm -f t-pid-2550 EXIT 165s + cat 165s herd (GNU Shepherd) 1.0.2 165s Copyright (C) 2025 the Shepherd authors 165s License GPLv3+: GNU GPL version 3 or later 165s This is free software: you are free to change and redistribute it. 165s There is NO WARRANTY, to the extent permitted by law. 165s + rm -f t-pid-2550 165s + test -f t-pid-2550 165s + sleep 0.3 165s + shepherd -I -s t-socket-2550 -c t-conf-2550 -l t-log-2550 --pid=t-pid-2550 165s GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 165s Starting service root... 165s Service root started. 165s Service root running with value #< id: 2559 command: #f>. 165s Service root has been started. 165s Configuration successfully loaded from 't-conf-2550'. 165s + test -f t-pid-2550 165s + cat t-pid-2550 165s + shepherd_pid=2559 165s + kill -0 2559 165s + test -S t-socket-2550 165s + herd -s t-socket-2550 status -n 0 165s + pristine_status=Started: 165s + root 165s Stopped: 165s - broken 165s - spawn-with-system 165s - test 165s - test-2 165s + echo Started: + root Stopped: - broken - spawn-with-system - test - test-2 165s + grep -E (Start.*root|Stop.*test) 165s Started: + root Stopped: - broken - spawn-with-system - test - test-2 165s + herd -s t-socket-2550 status root 165s + cat t-pid-2550 165s + grep PID: 2559 165s Main PID: 2559 165s + grep Service root started 165s + herd -s t-socket-2550 status root 165s 2025-05-02 04:53:30 Service root started. 165s + herd -s t-socket-2550 status root 165s + grep actions: .*eval 165s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 165s + herd+ grep actions: .*load 165s -s t-socket-2550 status root 165s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 165s + herd -s t-socket-2550 status root 165s + grep actions: .*halt 165s Custom actions: help status halt power-off kexec load eval unload reload daemonize restart 165s + herd -s t-socket-2550 graph 165s + grep "test-2" -> "test" 165s "test-2" -> "test"; 165s + herd -s t-socket-2550 start test 165s Service test has been started. 165s + test -f t-stamp-2550 165s + herd -s t-socket-2550 status test 165s + grep running 165s + herd -s t-socket-2550 status root 165s It is running since 04:53:30 (0 seconds ago). 165s + grep Service test started 166s 2025-05-02 04:53:30 Service test started. 166s + herd -s t-socket-2550 stop test 166s + test -f t-stamp-2550 166s + herd -s t-socket-2550 log 166s 2 May 2025 04:53:30 service root is being started 166s 2 May 2025 04:53:30 service root is running 166s 2 May 2025 04:53:30 service test is being started 166s 2 May 2025 04:53:30 service test is running 166s 2 May 2025 04:53:31 service test is being stopped 166s 2 May 2025 04:53:31 service test is stopped 166s + herd -s t-socket-2550 log 166s + grep service test is running 166s 2 May 2025 04:53:30 service test is running 166s + herd -s t-socket-2550 log 166s + grep service test is stopped 166s 2 May 2025 04:53:31 service test is stopped 166s + herd -s t-socket-2550+ grep stopped 166s status test 166s It is stopped since 04:53:31 (0 seconds ago). 166s + herd -s t-socket-2550 stop test 166s + herd -s t-socket-2550 stop test 166s + test -z 166s + herd -s t-socket-2550 disable test-2 166s Disabled service test-2. 166s + herd -s t-socket-2550 start test-2 166s Service test has been started. 166s Service test-2 is currently disabled. 166s herd: error: failed to start service test-2 166s + true 166s + herd -s t-socket-2550 start test-2 166s + grep test-2 is currently disabled 166s Service test-2 is currently disabled. 166s herd: error: failed to start service test-2 166s + herd -s t-socket-2550 enable test-2 166s + herd -s t-socket-2550 start test-2 166s Enabled service test-2. 166s Service test-2 has been started. 166s + wc -l 166s + test 25 -gt 0 166s + grep ^$ 166s + cut -c 21- 166s + wc -l 166s + test 0 -eq 0 166s + herd -s t-socket-2550 doc test-2 action hi 166s + grep Say hi\. 166s hi: Say hi. 166s + herd -s t-socket-2550 hi test-2 166s start 166s 166s end 166s + herd -s t-socket-2550 hi test-2 166s + grep ^start$ 166s start 166s + herd -s t-socket-2550 hi+ grep ^end$ 166s test-2 166s end 166s + herd -s t-socket-2550 hi test-2 166s + wc -l 166s + test 3 -eq 3 166s + herd -s t-socket-2550 fail test-2 166s + true 166s + herd -s t-socket-2550 enable test-2 with extra arguments 166s herd: error: exception caught while executing 'enable' on service 'test-2': 166s Wrong number of arguments to # 166s + true 166s + herd -s t-socket-2550 status test-2 166s + grep running 166s It is running since 04:53:31 (0 seconds ago). 166s + herd -s t-socket-2550 status test-2 something else that is useless 166s herd: error: exception caught while executing 'status' on service 'test-2': 166s Wrong number of arguments to # 166s + true 166s + herd -s t-socket-2550 status does-not-exist 166s herd: error: service 'does-not-exist' could not be found 166s + true 166s + herd -s t-socket-2550 status does-not-exist 166s + grep does-not-exist.*not.*found 166s herd: error: service 'does-not-exist' could not be found 166s + herd -s t-socket-2550 start does-not-exist 166s herd: error: service 'does-not-exist' could not be found 166s + true 166s + herd -s t-socket-2550 start does-not-exist 166s + grep does-not-exist.*not.*found 166s herd: error: service 'does-not-exist' could not be found 166s + herd -s t-socket-2550 stop does-not-exist 166s herd: error: service 'does-not-exist' could not be found 166s + true 166s + herd -s t-socket-2550 stop does-not-exist 166s + grep does-not-exist.*not.*found 166s herd: error: service 'does-not-exist' could not be found 166s + herd -s t-socket-2550 an-action-that-does-not-exist root 166s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 166s herd: hint: Run 'herd doc root list-actions' to list supported actions. 166s + true 166s + herd -s t-socket-2550 start broken 166s herd: error: exception caught while executing 'start' on service 'broken': 166s In procedure mkdir: No such file or directory 166s + herd -s t-socket-2550 status broken 166s + grep stopped 166s It is stopped (failing). 166s + herd -s t-socket-2550 start spawn-with-system 166s Service spawn-with-system has been started. 166s + herd -s t-socket-2550 status spawn-with-system 166s + grep running 166s It is running since 04:53:31 (0 seconds ago). 166s + herd -s t-socket-2550 status spawn-with-system 166s + grep starting from 166s 2025-05-02 04:53:31 starting from /tmp/autopkgtest.5EFDPQ/build.Kta/src 166s + herd -s t-socket-2550 stop spawn-with-system 166s + herd -s t-socket-2550 status spawn-with-system 166s + grep stopped 166s It is stopped since 04:53:31 (0 seconds ago). 166s + herd -s t-socket-2550 status root foo bar baz 167s herd: error: exception caught while executing 'status' on service 'root': 167s Wrong number of arguments to # 167s + true 167s + herd -s t-socket-2550 doc root action status 167s status: Return an s-expression showing information about all the services. 167s Clients such as 'herd' can read it and format it in a human-readable way. 167s + herd -s t-socket-2550 doc root action an-action-that-does-not-exist 167s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 167s herd: hint: Run 'herd doc root list-actions' to list supported actions. 167s + true 167s + herd -s t-socket-2550 doc root action an-action-that-does-not-exist 167s + grep does not have an action 'an-action-that-does-not-exist' 167s herd: error: service 'root' does not have an action 'an-action-that-does-not-exist' 167s + herd+ grep ^daemonize: 167s -s t-socket-2550 doc root list-actions 167s daemonize: 167s + herd -s t-socket-2550 doc root list-actions 167s + grep ^halt: 167s halt: 167s + herd -s t-socket-2550 load root /does/not/exist.scm 167s Loading /does/not/exist.scm. 167s herd: error: exception caught while executing 'load' on service 'root': 167s In procedure open-fdes: No such file or directory 167s + true 167s + herd -s t-socket-2550 unload root broken 167s Removing service 'broken'... 167s Service broken is not running. 167s Done. 167s + herd -s t-socket-2550 unload root test 167s + herd -s t-socket-2550 status -n 0 167s + grep -e - test-2 167s Removing service 'test'... 167s Done. 167s + herd -s t-socket-2550 reload root t-conf-2550 167s - test-2 167s Service test-2 is not running. 167s Service spawn-with-system is not running. 167s Loading t-conf-2550. 167s + herd -s t-socket-2550 status -n 0 167s + test Started: 167s + root 167s Stopped: 167s - broken 167s - spawn-with-system 167s - test 167s - test-2 == Started: 167s + root 167s Stopped: 167s - broken 167s - spawn-with-system 167s - test 167s - test-2 167s tests/basic.sh: 205: test: Started: 167s + root 167s Stopped: 167s - broken 167s - spawn-with-system 167s - test 167s - test-2: unexpected operator 167s + mkdir -p t-confdir-2550 167s + cat 167s + herd -s t-socket-2550 status test-loaded 167s herd: error: service 'test-loaded' could not be found 167s + true 167s + herd -s t-socket-2550 load root t-confdir-2550/some-conf.scm 167s Loading t-confdir-2550/some-conf.scm. 167s + rm t-confdir-2550/some-conf.scm 167s + grep register-services.*rest list.*deprecated t-log-2550 167s + herd -s t-socket-2550 status test-loaded 167s 2025-05-02 04:53:32 Passing 'register-services' services as a rest list is now deprecated. 167s ● Status of test-loaded: 167s It is stopped. 167s It is enabled. 167s Provides: test-loaded 167s Will not be respawned. 167s + herd -s t-socket-2550 status test-loaded 167s + grep stopped 167s + herd -s t-socket-2550 start test-loaded 167s It is stopped. 167s Greek letter λ 167s Service test-loaded has been started. 167s + herd -s t-socket-2550 status test-loaded 167s + grep -i running.*abc 167s Running value is abc. 167s + grep Greek letter t-log-2550 167s 2025-05-02 04:53:32 Greek letter λ 167s + herd -s t-socket-2550 stop test-loaded 167s + herd -s t-socket-2550 unload root test-loaded 167s Removing service 'test-loaded'... 167s Service test-loaded is not running. 167s Done. 167s + type -P pwd 167s + cat 167s + herd -s t-socket-2550 load root t-confdir-2550/some-conf.scm 167s Loading t-confdir-2550/some-conf.scm. 167s + herd -s t-socket-2550 start test-run-from-nonexistent-directory 167s Starting service test-run-from-nonexistent-directory... 167s Service test-run-from-nonexistent-directory started. 167s Service test-run-from-nonexistent-directory running with value #< id: 2818 command: ("-P: not found\npwd is a shell builtin")>. 167s Service test-run-from-nonexistent-directory has been started. 167s + herd -s t-socket-2550 status test-run-from-nonexistent-directory 167s + grep exited with code 127 167s Process exited with code 127. 167s + seq 1 10 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s+ grep ^[0-9] 167s t-socket-2550 eval root (getpid) 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 eval root (getpid) 167s + grep ^[0-9] 167s + test 2559 -eq 2559 167s + herd -s t-socket-2550 unload root test-run-from-nonexistent-directory 167s Removing service 'test-run-from-nonexistent-directory'... 167s Service test-run-from-nonexistent-directory is not running. 167s Done. 167s + cat 167s + herd -s t-socket-2550 load root t-confdir-2550/some-conf.scm 167s + herd -s t-socket-2550 start test-loaded 167s Loading t-confdir-2550/some-conf.scm. 168s Starting service test-loaded... 168s Service test-loaded started. 168s Service test-loaded running with value #. 168s Service test-loaded has been started. 168s + grep -i running.*# 168s + herd -s t-socket-2550 status test-loaded 168s + herd -s t-socket-2550 Running value is "#". 168s stop test-loaded 168s + herd -s t-socket-2550 eval root (perform-service-action root-service 'unload "test-loaded") 168s Evaluating user expression (perform-service-action root-service (quote #) #). 168s Removing service 'test-loaded'... 168s Service test-loaded is not running. 168s Done. 168s "#" 168s + herd -s t-socket-2550 status test-loaded 168s herd: error: service 'test-loaded' could not be found 168s + true 168s + cat 168s + herd -s t-socket-2550 load root t-confdir-2550/some-conf.scm 168s herd: error: exception caught while executing 'load' on service 'root': 168s Syntax error: 168s unknown location: source expression failed to match any pattern in form (define x y z) 168s Loading t-confdir-2550/some-conf.scm. 168s + true 168s + herd -s t-socket-2550 status 168s Started: 168s + root 168s Stopped: 168s - broken 168s - spawn-with-system 168s - test 168s - test-2 168s + cat 168s + herd -s t-socket-2550 load root t-confdir-2550/some-conf.scm 168s herd: error: exception caught while executing 'load' on service 'root': 168s Throw to key `what?!' with args `("#<>")'. 168s + true 168s + herd -s t-socket-2550 status 168s Loading t-confdir-2550/some-conf.scm. 168s Started: 168s + root 168s Stopped: 168s - broken 168s - spawn-with-system 168s - test 168s - test-2 168s + herd -s t-socket-2550 eval root (/ 0 0) 168s Evaluating user expression (/ 0 0). 168s herd: error: exception caught while executing 'eval' on service 'root': 168s Throw to key `numerical-overflow' with args `("divide" "Numerical overflow" #f #f)'. 168s + true 168s + herd -s t-socket-2550 eval root (no closing paren 168s herd: error: exception caught while executing 'eval' on service 'root': 168s #:1:18: unexpected end of input while searching for: #\) 168s + true 168s + herd -s t-socket-2550 eval root (values) 168s Evaluating user expression (values). 168s "#" 168s + herd -s t-socket-2550 eval root ((@ (fibers) sleep) 1) 169s + herd -s t-socket-2550 unload root all 169s Evaluating user expression ((@ (fibers) sleep) 1). 169s "#" 169s + herd -s t-socket-2550 status 169s + grep Stopped: 169s Service broken is not running. 169s Service spawn-with-system is not running. 169s Service test-2 is not running. 169s Service test is not running. 169s + true 169s + herd -s t-socket-2550 status 169s + grep -e + root 169s + root 169s + grep already running t-log-2550 169s + true 169s + herd+ grep already running 169s -s t-socket-2550 start root 169s + grep already running t-log-2550 169s Service root is already running. 169s + herd -s t-socket-2550 stop root 169s 2025-05-02 04:53:34 Service root is already running. 169s Stopping service root... 169s Exiting. 169s + kill -0 2559 169s tests/basic.sh: 332: kill: No such process 169s 169s + test -f t-log-2550 169s + export XDG_CONFIG_HOME=t-confdir-2550 169s + export XDG_DATA_HOME=t-datadir-2550 169s + export XDG_STATE_HOME=t-datadir-2550 169s + mkdir -p t-confdir-2550/shepherd 169s + mkdir -p t-datadir-2550/shepherd 169s + mv t-conf-2550 t-confdir-2550/shepherd/init.scm 169s + rm -f t-pid-2550 t-socket-2550 169s + test -f t-pid-2550 169s + sleep 0.3 169s + shepherd -I -s t-socket-2550 --pid=t-pid-2550 169s GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 169s Starting service root... 169s Service root started. 169s Service root running with value #< id: 2949 command: #f>. 169s Service root has been started. 169s Configuration successfully loaded from 't-confdir-2550/shepherd/init.scm'. 169s + test -f t-pid-2550 169s + herd -s t-socket-2550 start test 169s + test -f t-stamp-2550 169s + herd -s t-socket-2550 status test 169s + grep running 169s Starting service test... 169s Service test started. 169s Service test running with value #t. 169s Service test has been started. 169s + herd -s t-socket-2550 stop test 169s It is running since 04:53:34 (0 seconds ago). 169s + test -f t-stamp-2550 169s + cat t-pid-2550 169s + shepherd_pid=2949 169s + herd -s t-socket-2550 stop root 169s Stopping service root... 169s Exiting. 169s + kill -0 2949 169s tests/basic.sh: 369: kill: No such process 169s 169s + rm -rf t-confdir-2550 t-datadir-2550 169s + cat t-log-2550 169s + rm -f t-socket-2550 t-conf-2550 t-stamp-2550 t-log-2550 169s 2025-05-02 04:53:30 GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 169s 2025-05-02 04:53:30 Starting service root... 169s 2025-05-02 04:53:30 Service root started. 169s 2025-05-02 04:53:30 Service root running with value #< id: 2559 command: #f>. 169s 2025-05-02 04:53:30 Service root has been started. 169s 2025-05-02 04:53:30 Configuration successfully loaded from 't-conf-2550'. 169s 2025-05-02 04:53:30 Starting service test... 169s 2025-05-02 04:53:30 Service test has been started. 169s 2025-05-02 04:53:30 Service test started. 169s 2025-05-02 04:53:30 Service test running with value #t. 169s 2025-05-02 04:53:31 Stopping service test... 169s 2025-05-02 04:53:31 Service test might have failed to stop. 169s 2025-05-02 04:53:31 Service test is now stopped. 169s 2025-05-02 04:53:31 Disabled service test-2. 169s 2025-05-02 04:53:31 Starting service test... 169s 2025-05-02 04:53:31 Service test has been started. 169s 2025-05-02 04:53:31 Service test started. 169s 2025-05-02 04:53:31 Service test running with value #t. 169s 2025-05-02 04:53:31 Service test-2 is currently disabled. 169s 2025-05-02 04:53:31 Service test-2 is currently disabled. 169s 2025-05-02 04:53:31 Enabled service test-2. 169s 2025-05-02 04:53:31 Starting service test-2... 169s 2025-05-02 04:53:31 Service test-2 has been started. 169s 2025-05-02 04:53:31 Service test-2 started. 169s 2025-05-02 04:53:31 Service test-2 running with value #t. 169s 2025-05-02 04:53:31 hi: Say hi. 169s 2025-05-02 04:53:31 start 169s 2025-05-02 04:53:31 169s 2025-05-02 04:53:31 end 169s 2025-05-02 04:53:31 start 169s 2025-05-02 04:53:31 169s 2025-05-02 04:53:31 end 169s 2025-05-02 04:53:31 start 169s 2025-05-02 04:53:31 169s 2025-05-02 04:53:31 end 169s 2025-05-02 04:53:31 start 169s 2025-05-02 04:53:31 169s 2025-05-02 04:53:31 end 169s 2025-05-02 04:53:31 Starting service broken... 169s 2025-05-02 04:53:31 Service broken failed to start. 169s 2025-05-02 04:53:31 Starting service spawn-with-system... 169s 2025-05-02 04:53:31 [bash] starting from /tmp/autopkgtest.5EFDPQ/build.Kta/src 169s 2025-05-02 04:53:31 Service spawn-with-system has been started. 169s 2025-05-02 04:53:31 Service spawn-with-system started. 169s 2025-05-02 04:53:31 Service spawn-with-system running with value #t. 169s 2025-05-02 04:53:31 Stopping service spawn-with-system... 169s 2025-05-02 04:53:31 Registering new logger for spawn-with-system. 169s 2025-05-02 04:53:31 [bash] stopping from /tmp/autopkgtest.5EFDPQ/build.Kta/src 169s 2025-05-02 04:53:31 Service spawn-with-system stopped. 169s 2025-05-02 04:53:31 Service spawn-with-system is now stopped. 169s 2025-05-02 04:53:32 status: Return an s-expression showing information about all the services. 169s 2025-05-02 04:53:32 Clients such as 'herd' can read it and format it in a human-readable way. 169s 2025-05-02 04:53:32 help: 169s 2025-05-02 04:53:32 Show the help message for the 'root' service. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 status: 169s 2025-05-02 04:53:32 Return an s-expression showing information about all the services. 169s 2025-05-02 04:53:32 Clients such as 'herd' can read it and format it in a human-readable way. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 halt: 169s 2025-05-02 04:53:32 Halt the system. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 power-off: 169s 2025-05-02 04:53:32 Halt the system and turn it off. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 kexec: 169s 2025-05-02 04:53:32 Reboot the system and run kexec. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 load: 169s 2025-05-02 04:53:32 Load the Scheme code from FILE into shepherd. This is potentially 169s 2025-05-02 04:53:32 dangerous. You have been warned. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 eval: 169s 2025-05-02 04:53:32 Evaluate the given Scheme expression into the shepherd. This is 169s 2025-05-02 04:53:32 potentially dangerous, be careful. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 unload: 169s 2025-05-02 04:53:32 Unload the service identified by SERVICE-NAME or all services 169s 2025-05-02 04:53:32 except for 'root' if SERVICE-NAME is 'all'. Stop services before 169s 2025-05-02 04:53:32 removing them if needed. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 reload: 169s 2025-05-02 04:53:32 Unload all services, then load from FILE-NAME into shepherd. This 169s 2025-05-02 04:53:32 is potentially dangerous. You have been warned. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 daemonize: 169s 2025-05-02 04:53:32 Go into the background. Be careful, this means that a new 169s 2025-05-02 04:53:32 process will be created, so shepherd will not get SIGCHLD signals anymore 169s 2025-05-02 04:53:32 if previously spawned children terminate. Therefore, this action should 169s 2025-05-02 04:53:32 usually only be used (if at all) *before* children get spawned for which 169s 2025-05-02 04:53:32 we want to receive these signals. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 restart: 169s 2025-05-02 04:53:32 This does not work for the 'root' service. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 help: 169s 2025-05-02 04:53:32 Show the help message for the 'root' service. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 status: 169s 2025-05-02 04:53:32 Return an s-expression showing information about all the services. 169s 2025-05-02 04:53:32 Clients such as 'herd' can read it and format it in a human-readable way. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 halt: 169s 2025-05-02 04:53:32 Halt the system. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 power-off: 169s 2025-05-02 04:53:32 Halt the system and turn it off. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 kexec: 169s 2025-05-02 04:53:32 Reboot the system and run kexec. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 load: 169s 2025-05-02 04:53:32 Load the Scheme code from FILE into shepherd. This is potentially 169s 2025-05-02 04:53:32 dangerous. You have been warned. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 eval: 169s 2025-05-02 04:53:32 Evaluate the given Scheme expression into the shepherd. This is 169s 2025-05-02 04:53:32 potentially dangerous, be careful. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 unload: 169s 2025-05-02 04:53:32 Unload the service identified by SERVICE-NAME or all services 169s 2025-05-02 04:53:32 except for 'root' if SERVICE-NAME is 'all'. Stop services before 169s 2025-05-02 04:53:32 removing them if needed. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 reload: 169s 2025-05-02 04:53:32 Unload all services, then load from FILE-NAME into shepherd. This 169s 2025-05-02 04:53:32 is potentially dangerous. You have been warned. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 daemonize: 169s 2025-05-02 04:53:32 Go into the background. Be careful, this means that a new 169s 2025-05-02 04:53:32 process will be created, so shepherd will not get SIGCHLD signals anymore 169s 2025-05-02 04:53:32 if previously spawned children terminate. Therefore, this action should 169s 2025-05-02 04:53:32 usually only be used (if at all) *before* children get spawned for which 169s 2025-05-02 04:53:32 we want to receive these signals. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 restart: 169s 2025-05-02 04:53:32 This does not work for the 'root' service. 169s 2025-05-02 04:53:32 169s 2025-05-02 04:53:32 Loading /does/not/exist.scm. 169s 2025-05-02 04:53:32 Removing service 'broken'... 169s 2025-05-02 04:53:32 Service broken is not running. 169s 2025-05-02 04:53:32 Done. 169s 2025-05-02 04:53:32 Removing service 'test'... 169s 2025-05-02 04:53:32 Stopping service test-2... 169s 2025-05-02 04:53:32 Service test-2 might have failed to stop. 169s 2025-05-02 04:53:32 Service test-2 is now stopped. 169s 2025-05-02 04:53:32 Stopping service test... 169s 2025-05-02 04:53:32 Service test might have failed to stop. 169s 2025-05-02 04:53:32 Service test is now stopped. 169s 2025-05-02 04:53:32 Done. 169s 2025-05-02 04:53:32 Service test-2 is not running. 169s 2025-05-02 04:53:32 Service spawn-with-system is not running. 169s 2025-05-02 04:53:32 Loading t-conf-2550. 169s 2025-05-02 04:53:32 Loading t-confdir-2550/some-conf.scm. 169s 2025-05-02 04:53:32 Passing 'register-services' services as a rest list is now deprecated. 169s 2025-05-02 04:53:32 Starting service test-loaded... 169s 2025-05-02 04:53:32 Greek letter λ 169s 2025-05-02 04:53:32 Service test-loaded has been started. 169s 2025-05-02 04:53:32 Service test-loaded started. 169s 2025-05-02 04:53:32 Service test-loaded running with value abc. 169s 2025-05-02 04:53:32 Stopping service test-loaded... 169s 2025-05-02 04:53:32 Service test-loaded stopped. 169s 2025-05-02 04:53:32 Service test-loaded is now stopped. 169s 2025-05-02 04:53:32 Removing service 'test-loaded'... 169s 2025-05-02 04:53:32 Service test-loaded is not running. 169s 2025-05-02 04:53:32 Done. 169s 2025-05-02 04:53:32 Loading t-confdir-2550/some-conf.scm. 169s 2025-05-02 04:53:32 Starting service test-run-from-nonexistent-directory... 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory started. 169s 2025-05-02 04:53:32 Failed to run "-P: not found\npwd is a shell builtin": In procedure chdir: No such file or directory 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory running with value #< id: 2818 command: ("-P: not found\npwd is a shell builtin")>. 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory has been started. 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory (PID 2818) exited with 127. 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory has been disabled. 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Evaluating user expression (getpid). 169s 2025-05-02 04:53:32 Removing service 'test-run-from-nonexistent-directory'... 169s 2025-05-02 04:53:32 Service test-run-from-nonexistent-directory is not running. 169s 2025-05-02 04:53:32 Done. 169s 2025-05-02 04:53:32 Loading t-confdir-2550/some-conf.scm. 169s 2025-05-02 04:53:32 Starting service test-loaded... 169s 2025-05-02 04:53:32 Service test-loaded started. 169s 2025-05-02 04:53:32 Service test-loaded running with value #. 169s 2025-05-02 04:53:32 Service test-loaded has been started. 169s 2025-05-02 04:53:33 Stopping service test-loaded... 169s 2025-05-02 04:53:33 Service test-loaded stopped. 169s 2025-05-02 04:53:33 Service test-loaded is now stopped. 169s 2025-05-02 04:53:33 Evaluating user expression (perform-service-action root-service (quote #) #). 169s 2025-05-02 04:53:33 Removing service 'test-loaded'... 169s 2025-05-02 04:53:33 Service test-loaded is not running. 169s 2025-05-02 04:53:33 Done. 169s 2025-05-02 04:53:33 Loading t-confdir-2550/some-conf.scm. 169s 2025-05-02 04:53:33 Loading t-confdir-2550/some-conf.scm. 169s 2025-05-02 04:53:33 Evaluating user expression (/ 0 0). 169s 2025-05-02 04:53:33 Evaluating user expression (values). 169s 2025-05-02 04:53:33 Evaluating user expression ((@ (fibers) sleep) 1). 169s 2025-05-02 04:53:34 Service broken is not running. 169s 2025-05-02 04:53:34 Service spawn-with-system is not running. 169s 2025-05-02 04:53:34 Service test-2 is not running. 169s 2025-05-02 04:53:34 Service test is not running. 169s 2025-05-02 04:53:34 Service root is already running. 169s 2025-05-02 04:53:34 Stopping service root... 169s + test -f t-pid-2550 169s + cat t-pid-2550 169s + kill 2949 169s tests/basic.sh: 2: kill: No such process 169s 169s + true 169s + rm -f t-pid-2550 170s autopkgtest [04:53:35]: test tests-basic: -----------------------] 170s tests-basic PASS 170s autopkgtest [04:53:35]: test tests-basic: - - - - - - - - - - results - - - - - - - - - - 171s autopkgtest [04:53:36]: test tests-starting-status: preparing testbed 171s Reading package lists... 171s Building dependency tree... 171s Reading state information... 171s Starting pkgProblemResolver with broken count: 0 171s Starting 2 pkgProblemResolver with broken count: 0 171s Done 172s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 173s autopkgtest [04:53:38]: test tests-starting-status: sh -x tests/starting-status.sh 173s autopkgtest [04:53:38]: test tests-starting-status: [----------------------- 173s + shepherd --version 173s shepherd (GNU Shepherd) 1.0.2 173s Copyright (C) 2025 the Shepherd authors 173s License GPLv3+: GNU GPL version 3 or later 173s This is free software: you are free to change and redistribute it. 173s There is NO WARRANTY, to the extent permitted by law. 173s + herd --version 173s herd (GNU Shepherd) 1.0.2 173s Copyright (C) 2025 the Shepherd authors 173s License GPLv3+: GNU GPL version 3 or later 173s This is free software: you are free to change and redistribute it. 173s There is NO WARRANTY, to the extent permitted by law. 173s + socket=t-socket-3122 173s + conf=t-conf-3122 173s + confdir=t-confdir-3122 173s + datadir=t-datadir-3122 173s + log=t-log-3122 173s + stamp=t-stamp-3122 173s + pid=t-pid-3122 173s + herd=herd -s t-socket-3122 173s + trap cat t-log-3122 || true; rm -f t-socket-3122 t-conf-3122 t-stamp-3122 t-log-3122; 173s test -f t-pid-3122 && kill `cat t-pid-3122` || true; rm -f t-pid-3122 EXIT 173s + cat 173s + rm -f t-pid-3122 t-stamp-3122 173s + + shepherd -I -s t-socket-3122 -c t-conf-3122 -l t-log-3122 --pid=t-pid-3122 173s test -f t-pid-3122 173s + sleep 0.3 173s GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 173s Starting service root... 173s Service root started. 173s Service root running with value #< id: 3131 command: #f>. 173s Service root has been started. 173s Configuration successfully loaded from 't-conf-3122'. 173s + test -f t-pid-3122 173s + cat t-pid-3122 173s + shepherd_pid=3131 173s + herd_pid=3137 173s + herd -s t-socket-3122 status 173s + herd -s t-socket-3122 start test 173s Started: 173s + root 173s Starting: 173s ^ test 173s + herd+ grep ^ test 173s -s t-socket-3122 status 173s ^ test 173s + herd -s t-socket-3122 status test 173s ● Status of test: 173s It is starting. 173s It is enabled. 173s Provides: test 173s Will not be respawned. 173s + herd -s t-socket-3122 status test 173s + grep starting 173s It is starting. 173s + herd_pid2=3154 173s + + herd -s t-socket-3122 start test 173s sleep 1 175s + kill -0 3137 175s + kill -0 3154 175s + touch t-stamp-3122 175s + n=0 175s + : 175s + herd -s t-socket-3122 status test 175s + grep running 175s + expr 0 + 1 175s + n=1 175s + test 1 -le 10 175s + sleep 1 175s Starting service test... 175s Service test has been started. 176s + : 176s + herd -s t-socket-3122 status test 176s + grep running 176s It is running since 04:53:40 (1 second ago). 176s + break 176s + n=0 176s + : 176s + kill -0 3137 176s tests/starting-status.sh: 91: kill: No such process 176s 176s + kill -0 3154 176s tests/starting-status.sh: 91: kill: No such process 176s 176s + break 176s + herd -s t-socket-3122 stop test 176s + test -f t-stamp-3122 176s Now trying to stop a service in 'starting' state. 176s + grep Starting service test t-log-3122 176s + wc -l 176s + test 1 = 1 176s + echo Now trying to stop a service in 'starting' state. 176s + herd_start_pid=3176 176s + herd -s t-socket-3122 start test 176s + herd -s t-socket-3122 status test 176s + grep starting 176s + sleep 0.5 176s + herd -s t-socket-3122 status test 176s + grep starting 176s It is starting. 176s + herd_stop_pid1=3188 176s + herd -s+ herd_stop_pid2=3189 176s t-socket-3122 stop test 176s + herd -s t-socket-3122 stop test 176s + seq 1 3 176s + herd -s t-socket-3122 status test 176s + grep starting 176s It is starting. 176s + sleep 0.3 176s + herd -s t-socket-3122 status test 176s + grep starting 177s It is starting. 177s + sleep 0.3 177s + + grep starting 177s herd -s t-socket-3122 status test 177s It is starting. 177s + sleep 0.3 177s + grep Waiting for test to start t-log-3122 177s 2025-05-02 04:53:41 Waiting for test to start... 177s 2025-05-02 04:53:41 Waiting for test to start... 177s + touch t-stamp-3122 177s + kill -0 3176 177s + sleep 0.5 178s Service test has been started. 178s + kill -0 3176 178s tests/starting-status.sh: 131: kill: No such process 178s 178s + kill -0 3188 178s tests/starting-status.sh: 132: kill: No such process 178s 178s + kill -0 3189 178s tests/starting-status.sh: 133: kill: No such process 178s 178s + herd -s t-socket-3122 status test 178s + grep stopped 178s It is stopped since 04:53:43 (0 seconds ago). 178s + herd -s t-socket-3122 stop root 178s Stopping service root... 178s Exiting. 178s + rm -rf t-confdir-3122 178s 2025-05-02 04:53:38 GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 178s 2025-05-02 04:53:38 Starting service root... 178s 2025-05-02 04:53:38 Service root started. 178s 2025-05-02 04:53:38 Service root running with value #< id: 3131 command: #f>. 178s 2025-05-02 04:53:38 Service root has been started. 178s 2025-05-02 04:53:38 Configuration successfully loaded from 't-conf-3122'. 178s 2025-05-02 04:53:38 Starting service test... 178s 2025-05-02 04:53:40 Service test has been started. 178s 2025-05-02 04:53:40 Service test started. 178s 2025-05-02 04:53:40 Service test running with value #t. 178s 2025-05-02 04:53:41 Stopping service test... 178s 2025-05-02 04:53:41 Service test might have failed to stop. 178s 2025-05-02 04:53:41 Service test is now stopped. 178s 2025-05-02 04:53:41 Starting service test... 178s 2025-05-02 04:53:41 Waiting for test to start... 178s 2025-05-02 04:53:41 Waiting for test to start... 178s 2025-05-02 04:53:43 Service test has been started. 178s 2025-05-02 04:53:43 Service test started. 178s 2025-05-02 04:53:43 Service test running with value #t. 178s 2025-05-02 04:53:43 Stopping service test... 178s 2025-05-02 04:53:43 Service test might have failed to stop. 178s 2025-05-02 04:53:43 Service test is now stopped. 178s 2025-05-02 04:53:43 Stopping service root... 178s 2025-05-02 04:53:43 Exiting shepherd... 178s + rm -rf t-datadir-3122 178s + cat t-log-3122 178s + rm -f t-socket-3122 t-conf-3122 t-stamp-3122 t-log-3122 178s + test -f t-pid-3122 178s + cat t-pid-3122 178s + kill 3131 178s tests/starting-status.sh: 2: kill: No such process 178s 178s + true 178s + rm -f t-pid-3122 178s autopkgtest [04:53:43]: test tests-starting-status: -----------------------] 179s autopkgtest [04:53:44]: test tests-starting-status: - - - - - - - - - - results - - - - - - - - - - 179s tests-starting-status PASS 179s autopkgtest [04:53:44]: test tests-one-shot: preparing testbed 179s Reading package lists... 179s Building dependency tree... 179s Reading state information... 180s Starting pkgProblemResolver with broken count: 0 180s Starting 2 pkgProblemResolver with broken count: 0 180s Done 180s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 181s autopkgtest [04:53:46]: test tests-one-shot: sh -x tests/one-shot.sh 181s autopkgtest [04:53:46]: test tests-one-shot: [----------------------- 181s + shepherd --version 181s shepherd (GNU Shepherd) 1.0.2 181s Copyright (C) 2025 the Shepherd authors 181s License GPLv3+: GNU GPL version 3 or later 181s This is free software: you are free to change and redistribute it. 181s There is NO WARRANTY, to the extent permitted by law. 181s + herd --version 181s herd (GNU Shepherd) 1.0.2 181s Copyright (C) 2025 the Shepherd authors 181s License GPLv3+: GNU GPL version 3 or later 181s This is free software: you are free to change and redistribute it. 181s There is NO WARRANTY, to the extent permitted by law. 181s + socket=t-socket-3374 181s + conf=t-conf-3374 181s + confdir=t-confdir-3374 181s + log=t-log-3374 181s + stamp=t-stamp-3374 181s + pid=t-pid-3374 181s + herd=herd -s t-socket-3374 181s + trap cat t-log-3374 || true; rm -f t-socket-3374 t-conf-3374 t-stamp-3374 t-log-3374; 181s test -f t-pid-3374 && kill `cat t-pid-3374` || true; rm -f t-pid-3374 EXIT 181s + cat 181s + rm -f t-pid-3374 181s + + shepherd -I -s t-socket-3374 -c t-conf-3374 -l t-log-3374 --pid=t-pid-3374 181s test -f t-pid-3374 181s + sleep 0.3 181s GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 181s Starting service root... 181s Service root started. 181s Service root running with value #< id: 3383 command: #f>. 181s Service root has been started. 181s Configuration successfully loaded from 't-conf-3374'. 181s Starting service one-shotty... 181s Service one-shotty started. 181s Service one-shotty running with value #t. 181s Service one-shotty has been started. 181s Starting service a... 181s Service a started. 181s Service a running with value #t. 181s Service a has been started. 181s Starting service b... 181s Service b started. 181s Service b running with value #t. 181s Service b has been started. 181s Starting service c... 181s Service c started. 181s Service c running with value #t. 181s Service c has been started. 181s Successfully started 3 services in the background. 182s + test -f t-pid-3374 182s + cat t-pid-3374 182s + shepherd_pid=3383 182s + kill -0 3383 182s + test -S t-socket-3374 182s + herd -s t-socket-3374 start always-fail 182s Starting service always-fail... 182s Service always-fail failed to start. 182s Service always-fail could not be started. 182s herd: error: failed to start service always-fail 182s + true 182s + rm -f t-stamp-3374 182s + herd -s t-socket-3374 start test 182s Starting service test... 182s Service test started. 182s Service test running with value #t. 182s Service test has been started. 182s + test -f t-stamp-3374 182s + herd -s t-socket-3374 status test 182s + grep stopped.*one-shot 182s It is stopped (one-shot). 182s + grep test.*started t-log-3374 182s + 2025-05-02 04:53:47 Service test started. 182s 2025-05-02 04:53:47 Service test has been started. 182s herd -s t-socket-3374 stop test 182s + rm -f t-stamp-3374 182s + herd -s t-socket-3374 start test 182s Service test has been started. 182s + test -f t-stamp-3374 182s + herd -s t-socket-3374 status test 182s + grep stopped.*one-shot 182s It is stopped (one-shot). 182s + grep test.*started t-log-3374 182s 2025-05-02 04:53:47 Service test started. 182s 2025-05-02 04:53:47 Service test has been started. 182s 2025-05-02 04:53:47 Service test has been started. 182s 2025-05-02 04:53:47 Service test started. 182s + herd -s t-socket-3374 stop test 182s + rm -f t-stamp-3374 182s + herd -s t-socket-3374 start test 182s Service test has been started. 182s + test -f t-stamp-3374 182s + herd -s t-socket-3374 status test 182s + grep stopped.*one-shot 182s It is stopped (one-shot). 182s + grep test.*started t-log-3374 182s 2025-05-02 04:53:47 Service test started. 182s 2025-05-02 04:53:47 Service test has been started. 182s 2025-05-02 04:53:47 Service test has been started. 182s 2025-05-02 04:53:47 Service test started. 182s 2025-05-02 04:53:47 Service test has been started. 182s 2025-05-02 04:53:47 Service test started. 182s + herd -s t-socket-3374 stop test 182s + herd -s t-socket-3374 status 182s + grep -i ^one-shot 182s One-shot: 182s + herd -s t-socket-3374 status 182s Started: 182s + a 182s + b 182s + c 182s + root 182s Stopped: 182s - test-2 182s One-shot: 182s * always-fail 182s * one-shotty 182s * test 182s + rm -f t-stamp-3374 t-stamp-3374-2 182s + herd -s t-socket-3374 start test-2 182s Service test has been started. 182s Service test-2 has been started. 182s + test -f t-stamp-3374 182s + test -f t-stamp-3374-2 182s + herd -s t-socket-3374 status test 182s + grep stopped.*one-shot 182s It is stopped (one-shot). 182s + herd -s t-socket-3374 status test-2 182s + grep running 182s It is running since 04:53:47 (0 seconds ago). 182s + herd -s t-socket-3374 stop test-2 182s + test -f t-stamp-3374-2 182s + true 182s + grep Starting service one-shotty t-log-3374+ 182s wc -l 182s + test 1 -eq 1 182s + herd -s t-socket-3374 stop a 182s Stopping service c... 182s Service c stopped. 182s Service c is now stopped. 182s Stopping service b... 182s Service b stopped. 182s Service b is now stopped. 182s Stopping service a... 182s Service a stopped. 182s Service a is now stopped. 182s + herd -s t-socket-3374 start c 182s Starting service one-shotty... 182s Service one-shotty started. 182s Service one-shotty running with value #t. 182s Starting service a... 182s Service a started. 182s Service a running with value #t. 182s Starting service b... 182s Service b started. 182s Service b running with value #t. 182s Starting service c... 182s Service c started. 182s Service c running with value #t. 182s Service one-shotty has been started. 182s Service a has been started. 182s Service b has been started. 182s Service c has been started. 182s + + wc -l 182s grep Starting service one-shotty t-log-3374 182s + test 2 -eq 2 182s + herd -s t-socket-3374 stop a 182s Stopping service c... 182s Service c stopped. 182s Service c is now stopped. 182s Stopping service b... 182s Service b stopped. 182s Service b is now stopped. 182s Stopping service a... 182s Service a stopped. 182s + herd -s t-socket-3374 start c 182s Service a is now stopped. 182s Starting service one-shotty... 182s Service one-shotty started. 182s Service one-shotty running with value #t. 182s Starting service a... 182s Service a started. 182s Service a running with value #t. 182s Starting service b... 182s Service b started. 182s Service b running with value #t. 182s Starting service c... 182s Service c started. 182s Service c running with value #t. 182s Service one-shotty has been started. 182s Service a has been started. 182s Service b has been started. 182s Service c has been started. 182s + grep+ Starting service one-shotty t-log-3374 182s wc -l 182s + test 3 -eq 3 182s + herd -s t-socket-3374 start one-shotty 182s Starting service one-shotty... 182s Service one-shotty started. 182s Service one-shotty running with value #t. 182s Service one-shotty has been started. 182s + grep Starting service one-shotty t-log-3374 182s + wc -l 182s + test 4 -eq 4 182s + cat 182s + rm -f t-stamp-3374 182s + herd -s t-socket-3374 load root t-conf-3374 182s + grep Service third started t-log-3374 182s Loading t-conf-3374. 182s + sleep 0.5 183s + grep Service third started t-log-3374 183s + sleep 0.5 183s + grep Service third started t-log-3374 183s + sleep 0.5 184s + grep Service third started t-log-3374 184s + sleep 0.5 184s + grep Service third started t-log-3374 184s + sleep 0.5 185s 2025-05-02 04:53:49 Service third started. 185s + grep Service third started t-log-3374 185s + cat t-stamp-3374 185s + test third = third 185s + herd -s t-socket-3374 start fourth 185s Service always-fail could not be started. 185s Service fourth depends on always-fail. 185s herd: error: failed to start service fourth 185s + herd -s t-socket-3374 start fourth 185s Service always-fail could not be started. 185s Service fourth depends on always-fail. 185s herd: error: failed to start service fourth 185s + herd -s t-socket-3374 stop root 185s Stopping service root... 185s Stopping service c... 185s Service c stopped. 185s Service c is now stopped. 185s Stopping service b... 185s Service b stopped. 185s Service b is now stopped. 185s Stopping service a... 185s Service a stopped. 185s Service a is now stopped. 185s Exiting. 185s + cat t-log-3374 185s 2025-05-02 04:53:46 GNU Shepherd 1.0.2 (Guile 3.0.10, powerpc64le-unknown-linux-gnu) 185s 2025-05-02 04:53:46 Starting service root... 185s 2025-05-02 04:53:46 Service root started. 185s 2025-05-02 04:53:46 Service root running with value #< id: 3383 command: #f>. 185s 2025-05-02 04:53:46 Service root has been started. 185s 2025-05-02 04:53:46 Configuration successfully loaded from 't-conf-3374'. 185s 2025-05-02 04:53:46 Starting service one-shotty... 185s 2025-05-02 04:53:46 Service one-shotty started. 185s 2025-05-02 04:53:46 Service one-shotty running with value #t. 185s 2025-05-02 04:53:46 Service one-shotty has been started. 185s 2025-05-02 04:53:46 Starting service a... 185s 2025-05-02 04:53:46 Service a started. 185s 2025-05-02 04:53:46 Service a running with value #t. 185s 2025-05-02 04:53:46 Service a has been started. 185s 2025-05-02 04:53:46 Starting service b... 185s 2025-05-02 04:53:46 Service b started. 185s 2025-05-02 04:53:46 Service b running with value #t. 185s 2025-05-02 04:53:46 Service b has been started. 185s 2025-05-02 04:53:46 Starting service c... 185s 2025-05-02 04:53:46 Service c started. 185s 2025-05-02 04:53:46 Service c running with value #t. 185s 2025-05-02 04:53:46 Service c has been started. 185s 2025-05-02 04:53:46 Successfully started 3 services in the background. 185s 2025-05-02 04:53:47 Starting service always-fail... 185s 2025-05-02 04:53:47 Service always-fail failed to start. 185s 2025-05-02 04:53:47 Service always-fail could not be started. 185s 2025-05-02 04:53:47 Starting service test... 185s 2025-05-02 04:53:47 Service test started. 185s 2025-05-02 04:53:47 Service test running with value #t. 185s 2025-05-02 04:53:47 Service test has been started. 185s 2025-05-02 04:53:47 Starting service test... 185s 2025-05-02 04:53:47 Service test has been started. 185s 2025-05-02 04:53:47 Service test started. 185s 2025-05-02 04:53:47 Service test running with value #t. 185s 2025-05-02 04:53:47 Starting service test... 185s 2025-05-02 04:53:47 Service test has been started. 185s 2025-05-02 04:53:47 Service test started. 185s 2025-05-02 04:53:47 Service test running with value #t. 185s 2025-05-02 04:53:47 Starting service test... 185s 2025-05-02 04:53:47 Service test has been started. 185s 2025-05-02 04:53:47 Service test started. 185s 2025-05-02 04:53:47 Service test running with value #t. 185s 2025-05-02 04:53:47 Starting service test-2... 185s 2025-05-02 04:53:47 Service test-2 has been started. 185s 2025-05-02 04:53:47 Service test-2 started. 185s 2025-05-02 04:53:47 Service test-2 running with value #t. 185s 2025-05-02 04:53:47 Stopping service test-2... 185s 2025-05-02 04:53:47 Service test-2 stopped. 185s 2025-05-02 04:53:47 Service test-2 is now stopped. 185s 2025-05-02 04:53:47 Stopping service c... 185s 2025-05-02 04:53:47 Service c stopped. 185s 2025-05-02 04:53:47 Service c is now stopped. 185s 2025-05-02 04:53:47 Stopping service b... 185s 2025-05-02 04:53:47 Service b stopped. 185s 2025-05-02 04:53:47 Service b is now stopped. 185s 2025-05-02 04:53:47 Stopping service a... 185s 2025-05-02 04:53:47 Service a stopped. 185s 2025-05-02 04:53:47 Service a is now stopped. 185s 2025-05-02 04:53:47 Starting service one-shotty... 185s 2025-05-02 04:53:47 Service one-shotty has been started. 185s 2025-05-02 04:53:47 Service one-shotty started. 185s 2025-05-02 04:53:47 Service one-shotty running with value #t. 185s 2025-05-02 04:53:47 Starting service a... 185s 2025-05-02 04:53:47 Service a has been started. 185s 2025-05-02 04:53:47 Service a started. 185s 2025-05-02 04:53:47 Service a running with value #t. 185s 2025-05-02 04:53:47 Starting service b... 185s 2025-05-02 04:53:47 Service b has been started. 185s 2025-05-02 04:53:47 Service b started. 185s 2025-05-02 04:53:47 Service b running with value #t. 185s 2025-05-02 04:53:47 Starting service c... 185s 2025-05-02 04:53:47 Service c has been started. 185s 2025-05-02 04:53:47 Service c started. 185s 2025-05-02 04:53:47 Service c running with value #t. 185s 2025-05-02 04:53:47 Stopping service c... 185s 2025-05-02 04:53:47 Service c stopped. 185s 2025-05-02 04:53:47 Service c is now stopped. 185s 2025-05-02 04:53:47 Stopping service b... 185s 2025-05-02 04:53:47 Service b stopped. 185s 2025-05-02 04:53:47 Service b is now stopped. 185s 2025-05-02 04:53:47 Stopping service a... 185s 2025-05-02 04:53:47 Service a stopped. 185s 2025-05-02 04:53:47 Service a is now stopped. 185s 2025-05-02 04:53:47 Starting service one-shotty... 185s 2025-05-02 04:53:47 Service one-shotty has been started. 185s 2025-05-02 04:53:47 Service one-shotty started. 185s 2025-05-02 04:53:47 Service one-shotty running with value #t. 185s 2025-05-02 04:53:47 Starting service a... 185s 2025-05-02 04:53:47 Service a has been started. 185s 2025-05-02 04:53:47 Service a started. 185s 2025-05-02 04:53:47 Service a running with value #t. 185s 2025-05-02 04:53:47 Starting service b... 185s 2025-05-02 04:53:47 Service b has been started. 185s 2025-05-02 04:53:47 Service b started. 185s 2025-05-02 04:53:47 Service b running with value #t. 185s 2025-05-02 04:53:47 Starting service c... 185s 2025-05-02 04:53:47 Service c has been started. 185s 2025-05-02 04:53:47 Service c started. 185s 2025-05-02 04:53:47 Service c running with value #t. 185s 2025-05-02 04:53:47 Starting service one-shotty... 185s 2025-05-02 04:53:47 Service one-shotty has been started. 185s 2025-05-02 04:53:47 Service one-shotty started. 185s 2025-05-02 04:53:47 Service one-shotty running with value #t. 185s 2025-05-02 04:53:47 Loading t-conf-3374. 185s 2025-05-02 04:53:47 Starting service first... 185s 2025-05-02 04:53:48 Service first has been started. 185s 2025-05-02 04:53:48 Service first started. 185s 2025-05-02 04:53:48 Service first running with value #t. 185s 2025-05-02 04:53:48 Starting service second... 185s 2025-05-02 04:53:49 Service second has been started. 185s 2025-05-02 04:53:49 Service second started. 185s 2025-05-02 04:53:49 Service second running with value #t. 185s 2025-05-02 04:53:49 Starting service third... 185s 2025-05-02 04:53:49 Service third started. 185s 2025-05-02 04:53:49 Service third running with value #t. 185s 2025-05-02 04:53:49 Service third has been started. 185s 2025-05-02 04:53:49 Successfully started 3 services in the background. 185s 2025-05-02 04:53:50 Starting service always-fail... 185s 2025-05-02 04:53:50 Service always-fail could not be started. 185s 2025-05-02 04:53:50 Service always-fail failed to start. 185s 2025-05-02 04:53:50 Service fourth depends on always-fail. 185s 2025-05-02 04:53:50 Starting service always-fail... 185s 2025-05-02 04:53:50 Service always-fail could not be started. 185s 2025-05-02 04:53:50 Service always-fail failed to start. 185s 2025-05-02 04:53:50 Service fourth depends on always-fail. 185s 2025-05-02 04:53:50 Stopping service root... 185s 2025-05-02 04:53:50 Exiting shepherd... 185s 2025-05-02 04:53:50 Service always-fail is not running. 185s 2025-05-02 04:53:50 Service test is not running. 185s 2025-05-02 04:53:50 Service test-2 is not running. 185s 2025-05-02 04:53:50 Service one-shotty is not running. 185s 2025-05-02 04:53:50 Stopping service c... 185s 2025-05-02 04:53:50 Service c stopped. 185s 2025-05-02 04:53:50 Service c is now stopped. 185s 2025-05-02 04:53:50 Stopping service b... 185s 2025-05-02 04:53:50 Service b stopped. 185s 2025-05-02 04:53:50 Service b is now stopped. 185s 2025-05-02 04:53:50 Stopping service a... 185s 2025-05-02 04:53:50 Service a stopped. 185s 2025-05-02 04:53:50 Service a is now stopped. 185s 2025-05-02 04:53:50 Service b is not running. 185s 2025-05-02 04:53:50 Service c is not running. 185s 2025-05-02 04:53:50 Service first is not running. 185s 2025-05-02 04:53:50 Service second is not running. 185s + rm -f t-socket-3374 t-conf-3374 t-stamp-3374 t-log-3374 185s + test -f t-pid-3374 185s + cat t-pid-3374 185s + kill 3383 185s tests/one-shot.sh: 2: kill: No such process 185s 185s + true 185s + rm -f t-pid-3374 185s autopkgtest [04:53:50]: test tests-one-shot: -----------------------] 186s autopkgtest [04:53:51]: test tests-one-shot: - - - - - - - - - - results - - - - - - - - - - 186s tests-one-shot PASS 186s autopkgtest [04:53:51]: @@@@@@@@@@@@@@@@@@@@ summary 186s herd--help PASS 186s shepherd--help PASS 186s herd--version PASS 186s shepherd--version PASS 186s tests-basic PASS 186s tests-starting-status PASS 186s tests-one-shot PASS 191s nova [W] Using flock in prodstack6-ppc64el 191s Creating nova instance adt-questing-ppc64el-shepherd-20250502-045045-juju-7f2275-prod-proposed-migration-environment-2-20de6f5f-bd04-4c2d-b594-6e13398558ed from image adt/ubuntu-questing-ppc64el-server-20250502.img (UUID 7a0939ac-dfd3-4678-92e9-ba08dcd47f5c)... 191s nova [W] Timed out waiting for b93fb297-cc5a-486e-acde-b62450e10fba to get deleted.