0s autopkgtest [12:25:04]: starting date and time: 2024-03-22 12:25:04+0000 0s autopkgtest [12:25:04]: git checkout: 4a1cd702 l/adt_testbed: don't blame the testbed for unsolvable build deps 0s autopkgtest [12:25:04]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.80wqbjje/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --setup-commands /home/ubuntu/autopkgtest/setup-commands/setup-testbed --apt-pocket=proposed=src:sphinx --apt-upgrade ppft --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=sphinx/7.2.6-6 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-s390x-13.secgroup --name adt-noble-s390x-ppft-20240322-122504-juju-7f2275-prod-proposed-migration-environment-3 --image adt/ubuntu-noble-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 71s autopkgtest [12:26:15]: testbed dpkg architecture: s390x 71s autopkgtest [12:26:15]: testbed apt version: 2.7.12 71s autopkgtest [12:26:15]: @@@@@@@@@@@@@@@@@@@@ test bed setup 72s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 72s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [3807 kB] 73s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [496 kB] 73s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [54.0 kB] 73s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [6540 B] 73s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [665 kB] 73s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 73s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [1372 B] 73s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 73s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [3992 kB] 73s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 73s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x Packages [45.1 kB] 73s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 75s Fetched 9195 kB in 2s (3944 kB/s) 75s Reading package lists... 78s Reading package lists... 78s Building dependency tree... 78s Reading state information... 78s Calculating upgrade... 78s The following packages will be upgraded: 78s cloud-init debianutils fonts-ubuntu-console python3-markupsafe 79s 4 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 79s Need to get 719 kB of archives. 79s After this operation, 11.3 kB disk space will be freed. 79s Get:1 http://ftpmaster.internal/ubuntu noble/main s390x debianutils s390x 5.17 [90.1 kB] 79s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x fonts-ubuntu-console all 0.869+git20240321-0ubuntu1 [18.7 kB] 79s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x python3-markupsafe s390x 2.1.5-1build1 [12.8 kB] 79s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x cloud-init all 24.1.2-0ubuntu1 [597 kB] 79s Preconfiguring packages ... 79s Fetched 719 kB in 1s (1351 kB/s) 79s (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 ... 52171 files and directories currently installed.) 79s Preparing to unpack .../debianutils_5.17_s390x.deb ... 79s Unpacking debianutils (5.17) over (5.16) ... 79s Setting up debianutils (5.17) ... 80s (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 ... 52171 files and directories currently installed.) 80s Preparing to unpack .../fonts-ubuntu-console_0.869+git20240321-0ubuntu1_all.deb ... 80s Unpacking fonts-ubuntu-console (0.869+git20240321-0ubuntu1) over (0.869-0ubuntu1) ... 80s Preparing to unpack .../python3-markupsafe_2.1.5-1build1_s390x.deb ... 80s Unpacking python3-markupsafe (2.1.5-1build1) over (2.1.5-1) ... 80s Preparing to unpack .../cloud-init_24.1.2-0ubuntu1_all.deb ... 80s Unpacking cloud-init (24.1.2-0ubuntu1) over (24.1.1-0ubuntu1) ... 80s Setting up fonts-ubuntu-console (0.869+git20240321-0ubuntu1) ... 80s Setting up cloud-init (24.1.2-0ubuntu1) ... 81s Setting up python3-markupsafe (2.1.5-1build1) ... 81s Processing triggers for man-db (2.12.0-3) ... 82s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 82s Reading package lists... 83s Building dependency tree... 83s Reading state information... 83s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 83s Unknown architecture, assuming PC-style ttyS0 83s sh: Attempting to set up Debian/Ubuntu apt sources automatically 83s sh: Distribution appears to be Ubuntu 84s Reading package lists... 84s Building dependency tree... 84s Reading state information... 84s eatmydata is already the newest version (131-1). 84s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 84s Reading package lists... 84s Building dependency tree... 84s Reading state information... 85s dbus is already the newest version (1.14.10-4ubuntu1). 85s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 85s Reading package lists... 85s Building dependency tree... 85s Reading state information... 85s rng-tools-debian is already the newest version (2.4). 85s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 85s Reading package lists... 85s Building dependency tree... 85s Reading state information... 85s The following packages will be REMOVED: 85s cloud-init* python3-configobj* python3-debconf* 86s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded. 86s After this operation, 3256 kB disk space will be freed. 86s (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 ... 52170 files and directories currently installed.) 86s Removing cloud-init (24.1.2-0ubuntu1) ... 86s Removing python3-configobj (5.0.8-3) ... 86s Removing python3-debconf (1.5.86) ... 86s Processing triggers for man-db (2.12.0-3) ... 86s (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 ... 51781 files and directories currently installed.) 86s Purging configuration files for cloud-init (24.1.2-0ubuntu1) ... 87s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed 87s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 87s invoke-rc.d: policy-rc.d denied execution of try-restart. 87s Reading package lists... 87s Building dependency tree... 87s Reading state information... 88s linux-generic is already the newest version (6.8.0-11.11+1). 88s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 88s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 88s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 88s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 90s Reading package lists... 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s Calculating upgrade... 90s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 91s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 91s autopkgtest [12:26:35]: rebooting testbed after setup commands that affected boot 108s autopkgtest [12:26:52]: testbed running kernel: Linux 6.8.0-11-generic #11-Ubuntu SMP Tue Feb 13 23:45:46 UTC 2024 111s autopkgtest [12:26:55]: @@@@@@@@@@@@@@@@@@@@ apt-source ppft 113s Get:1 http://ftpmaster.internal/ubuntu noble/universe ppft 1.7.6.8+dfsg-1 (dsc) [3087 B] 113s Get:2 http://ftpmaster.internal/ubuntu noble/universe ppft 1.7.6.8+dfsg-1 (tar) [111 kB] 113s Get:3 http://ftpmaster.internal/ubuntu noble/universe ppft 1.7.6.8+dfsg-1 (diff) [4172 B] 113s gpgv: Signature made Wed Jan 31 00:18:28 2024 UTC 113s gpgv: using RSA key 7E7729476D87D6F11D91ACCBC293E7B461825ACE 113s gpgv: Can't check signature: No public key 113s dpkg-source: warning: cannot verify inline signature for ./ppft_1.7.6.8+dfsg-1.dsc: no acceptable signature found 113s autopkgtest [12:26:57]: testing package ppft version 1.7.6.8+dfsg-1 113s autopkgtest [12:26:57]: build not needed 114s autopkgtest [12:26:58]: test pytest: preparing testbed 115s 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 116s The following additional packages will be installed: 116s python3-all python3-ppft 116s The following NEW packages will be installed: 116s autopkgtest-satdep python3-all python3-ppft 116s 0 upgraded, 3 newly installed, 0 to remove and 0 not upgraded. 116s Need to get 24.8 kB/25.5 kB of archives. 116s After this operation, 165 kB of additional disk space will be used. 116s Get:1 /tmp/autopkgtest.apdOC2/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [712 B] 116s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x python3-all s390x 3.12.1-0ubuntu2 [908 B] 116s Get:3 http://ftpmaster.internal/ubuntu noble/universe s390x python3-ppft all 1.7.6.8+dfsg-1 [23.9 kB] 116s Fetched 24.8 kB in 0s (88.8 kB/s) 116s Selecting previously unselected package python3-all. 116s (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 ... 51726 files and directories currently installed.) 116s Preparing to unpack .../python3-all_3.12.1-0ubuntu2_s390x.deb ... 116s Unpacking python3-all (3.12.1-0ubuntu2) ... 116s Selecting previously unselected package python3-ppft. 116s Preparing to unpack .../python3-ppft_1.7.6.8+dfsg-1_all.deb ... 116s Unpacking python3-ppft (1.7.6.8+dfsg-1) ... 116s Selecting previously unselected package autopkgtest-satdep. 116s Preparing to unpack .../1-autopkgtest-satdep.deb ... 116s Unpacking autopkgtest-satdep (0) ... 116s Setting up python3-ppft (1.7.6.8+dfsg-1) ... 117s Setting up python3-all (3.12.1-0ubuntu2) ... 117s Setting up autopkgtest-satdep (0) ... 117s Processing triggers for man-db (2.12.0-3) ... 119s (Reading database ... 51760 files and directories currently installed.) 119s Removing autopkgtest-satdep (0) ... 120s autopkgtest [12:27:04]: test pytest: [----------------------- 120s Testing with python3.12: 122s Usage: python sum_primes.py [ncpus] 122s [ncpus] - the number of workers to run in parallel, 122s if omitted it will be set to the number of processors in the system 122s 122s Starting pp with 1 workers 122s Sum of primes below 100 is 1060 122s Sum of primes below 100000 is 454396537 122s Sum of primes below 100100 is 454996777 122s Sum of primes below 100200 is 455898156 122s Sum of primes below 100300 is 456700218 122s Sum of primes below 100400 is 457603451 122s Sum of primes below 100500 is 458407033 122s Sum of primes below 100600 is 459412387 122s Sum of primes below 100700 is 460217613 122s Job execution statistics: 122s job count | % of all jobs | job time sum | time per job | job server 122s 9 | 100.00 | 1.7688 | 0.196537 | local 122s Time elapsed since server creation 1.7708854675292969 122s 0 active tasks, 1 cores 122s 123s .Usage: python auto_diff.py [ncpus] 123s [ncpus] - the number of workers to run in parallel, 123s if omitted it will be set to the number of processors in the system 123s 123s Starting pp with 1 workers 123s t_log(1.000000) = 0.000000, t_log'(1.000000) = 1.000000 123s t_log(1.031250) = 0.030772, t_log'(1.031250) = 0.969697 123s t_log(1.062500) = 0.060625, t_log'(1.062500) = 0.941176 123s t_log(1.093750) = 0.089612, t_log'(1.093750) = 0.914286 123s t_log(1.125000) = 0.117783, t_log'(1.125000) = 0.888889 123s t_log(1.156250) = 0.145182, t_log'(1.156250) = 0.864865 123s t_log(1.187500) = 0.171850, t_log'(1.187500) = 0.842105 123s t_log(1.218750) = 0.197826, t_log'(1.218750) = 0.820513 123s t_log(1.250000) = 0.223144, t_log'(1.250000) = 0.800000 123s t_log(1.281250) = 0.247836, t_log'(1.281250) = 0.780488 123s t_log(1.312500) = 0.271934, t_log'(1.312500) = 0.761905 123s t_log(1.343750) = 0.295464, t_log'(1.343750) = 0.744186 123s t_log(1.375000) = 0.318454, t_log'(1.375000) = 0.727273 123s t_log(1.406250) = 0.340927, t_log'(1.406250) = 0.711111 123s t_log(1.437500) = 0.362905, t_log'(1.437500) = 0.695652 123s t_log(1.468750) = 0.384412, t_log'(1.468750) = 0.680851 123s t_log(1.500000) = 0.405465, t_log'(1.500000) = 0.666667 123s t_log(1.531250) = 0.426084, t_log'(1.531250) = 0.653061 123s t_log(1.562500) = 0.446287, t_log'(1.562500) = 0.640000 123s t_log(1.593750) = 0.466090, t_log'(1.593750) = 0.627451 123s t_log(1.625000) = 0.485508, t_log'(1.625000) = 0.615385 123s t_log(1.656250) = 0.504556, t_log'(1.656250) = 0.603774 123s t_log(1.687500) = 0.523248, t_log'(1.687500) = 0.592593 123s t_log(1.718750) = 0.541597, t_log'(1.718750) = 0.581818 123s t_log(1.750000) = 0.559616, t_log'(1.750000) = 0.571429 123s t_log(1.781250) = 0.577315, t_log'(1.781250) = 0.561404 123s t_log(1.812500) = 0.594707, t_log'(1.812500) = 0.551724 123s t_log(1.843750) = 0.611802, t_log'(1.843750) = 0.542373 123s t_log(1.875000) = 0.628609, t_log'(1.875000) = 0.533333 123s t_log(1.906250) = 0.645138, t_log'(1.906250) = 0.524590 123s t_log(1.937500) = 0.661398, t_log'(1.937500) = 0.516129 123s t_log(1.968750) = 0.677399, t_log'(1.968750) = 0.507937 123s Job execution statistics: 123s job count | % of all jobs | job time sum | time per job | job server 123s 32 | 100.00 | 1.5617 | 0.048802 | local 123s Time elapsed since server creation 1.5686883926391602 123s 0 active tasks, 1 cores 123s 126s .Usage: python reverse_md5.py [ncpus] 126s [ncpus] - the number of workers to run in parallel, 126s if omitted it will be set to the number of processors in the system 126s 126s Starting ppft with 1 workers 126s hash = 48ae4d2d384dcc470e471f4169daa96a 126s Reverse md5 for 48ae4d2d384dcc470e471f4169daa96a is 1829182 126s Job execution statistics: 126s job count | % of all jobs | job time sum | time per job | job server 126s 119 | 100.00 | 2.0831 | 0.017505 | local 126s Time elapsed since server creation 2.0922205448150635 126s 1 active tasks, 1 cores 126s 140s .Usage: python dynamic_ncpus.py 140s 140s Starting pp with 1 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 2.252920389175415 s 140s 140s Starting pp with 2 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 2.2296249866485596 s 140s 140s Starting pp with 4 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 2.271634101867676 s 140s 140s Starting pp with 8 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 3.7599353790283203 s 140s 140s Starting pp with 16 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 2.262115001678467 s 140s 140s Starting pp with 1 workers 140s Partial sum is 0.693147205559988 | diff = -2.5000042702671976e-08 140s Time elapsed: 2.324375867843628 s 140s 140s Job execution statistics: 140s job count | % of all jobs | job time sum | time per job | job server 140s 384 | 100.00 | 68.8058 | 0.179182 | local 140s Time elapsed since server creation 15.696542024612427 140s 0 active tasks, 1 cores 140s 142s .Usage: python callback.py [ncpus] 142s [ncpus] - the number of workers to run in parallel, 142s if omitted it will be set to the number of processors in the system 142s 142s Starting pp with 1 workers 142s Partial sum is 0.6931472055599898 | diff = -2.5000044479028816e-08 142s Job execution statistics: 142s job count | % of all jobs | job time sum | time per job | job server 142s 128 | 100.00 | 2.2355 | 0.017465 | local 142s Time elapsed since server creation 2.2437429428100586 142s 0 active tasks, 1 cores 142s 147s .Usage: python quicksort.py [ncpus] 147s [ncpus] - the number of workers to run in parallel, 147s if omitted it will be set to the number of processors in the system 147s 147s Starting pp with 1 workers 147s first 30 numbers in increasing order: [0, 0, 0, 0, 0, 0, 0, 0, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 1, 2, 2, 2, 2, 2, 2, 2, 2, 2, 2, 3] 147s Job execution statistics: 147s job count | % of all jobs | job time sum | time per job | job server 147s 32 | 100.00 | 3.3179 | 0.103684 | local 147s Time elapsed since server creation 4.087347745895386 147s 0 active tasks, 1 cores 147s 149s .Usage: python sum_primes.py [ncpus] 149s [ncpus] - the number of workers to run in parallel, 149s if omitted it will be set to the number of processors in the system 149s Starting pp with 1 workers 149s Sum of primes below 100 is 1060 149s Sum of primes below 100000 is 454396537 149s Sum of primes below 100100 is 454996777 149s Sum of primes below 100200 is 455898156 149s Sum of primes below 100300 is 456700218 149s Sum of primes below 100400 is 457603451 149s Sum of primes below 100500 is 458407033 149s Sum of primes below 100600 is 459412387 149s Sum of primes below 100700 is 460217613 149s Job execution statistics: 149s job count | % of all jobs | job time sum | time per job | job server 149s 9 | 100.00 | 1.8061 | 0.200681 | local 149s Time elapsed since server creation 1.8080906867980957 149s 0 active tasks, 1 cores 149s 149s . 149s autopkgtest [12:27:33]: test pytest: -----------------------] 149s pytest PASS 149s autopkgtest [12:27:33]: test pytest: - - - - - - - - - - results - - - - - - - - - - 150s autopkgtest [12:27:34]: @@@@@@@@@@@@@@@@@@@@ summary 150s pytest PASS 174s Creating nova instance adt-noble-s390x-ppft-20240322-122504-juju-7f2275-prod-proposed-migration-environment-3 from image adt/ubuntu-noble-s390x-server-20240321.img (UUID f7ee8f0f-480f-4014-94f0-3be2a19e259d)...