0s autopkgtest [18:23:32]: starting date and time: 2025-10-18 18:23:32+0000 0s autopkgtest [18:23:32]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [18:23:32]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.33j0e5ss/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:python3-defaults --apt-upgrade fatrace --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=python3-defaults/3.13.7-2 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-cpu2-ram4-disk20-amd64 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@sto01-5.secgroup --name adt-resolute-amd64-fatrace-20251018-182332-juju-7f2275-prod-proposed-migration-environment-2-62a7ed6a-0935-450e-897b-b670c3401810 --image adt/ubuntu-resolute-amd64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-autopkgtest-workers-amd64 -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 4s Creating nova instance adt-resolute-amd64-fatrace-20251018-182332-juju-7f2275-prod-proposed-migration-environment-2-62a7ed6a-0935-450e-897b-b670c3401810 from image adt/ubuntu-resolute-amd64-server-20251018.img (UUID dd697a48-b6cc-4a02-84bf-0f9f2fad5f89)... 29s autopkgtest [18:24:00]: testbed dpkg architecture: amd64 29s autopkgtest [18:24:01]: testbed apt version: 3.1.6ubuntu2 29s autopkgtest [18:24:01]: @@@@@@@@@@@@@@@@@@@@ test bed setup 29s autopkgtest [18:24:01]: testbed release detected to be: None 31s autopkgtest [18:24:03]: updating testbed package index (apt update) 31s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [83.3 kB] 31s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 31s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 31s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 31s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [50.7 kB] 31s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [16.7 kB] 31s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/restricted Sources [5028 B] 31s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [456 kB] 31s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/main amd64 Packages [104 kB] 31s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/main i386 Packages [59.9 kB] 31s Get:11 http://ftpmaster.internal/ubuntu resolute-proposed/restricted amd64 Packages [28.0 kB] 31s Get:12 http://ftpmaster.internal/ubuntu resolute-proposed/restricted i386 Packages [3208 B] 31s Get:13 http://ftpmaster.internal/ubuntu resolute-proposed/universe amd64 Packages [331 kB] 32s Get:14 http://ftpmaster.internal/ubuntu resolute-proposed/universe i386 Packages [113 kB] 32s Get:15 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse i386 Packages [3088 B] 32s Get:16 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse amd64 Packages [9188 B] 32s Fetched 1262 kB in 1s (1702 kB/s) 32s Reading package lists... 33s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 33s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 33s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 33s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 33s Reading package lists... 33s Reading package lists... 34s Building dependency tree... 34s Reading state information... 34s Calculating upgrade... 34s The following packages will be upgraded: 34s apt gir1.2-girepository-2.0 libapt-pkg7.0 libgirepository-1.0-1 34s libpython3-stdlib python3 python3-minimal 34s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 34s Need to get 2751 kB of archives. 34s After this operation, 2048 B of additional disk space will be used. 34s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed/main amd64 python3-minimal amd64 3.13.7-2 [27.8 kB] 34s Get:2 http://ftpmaster.internal/ubuntu resolute-proposed/main amd64 python3 amd64 3.13.7-2 [23.9 kB] 34s Get:3 http://ftpmaster.internal/ubuntu resolute-proposed/main amd64 libpython3-stdlib amd64 3.13.7-2 [10.6 kB] 34s Get:4 http://ftpmaster.internal/ubuntu resolute/main amd64 libapt-pkg7.0 amd64 3.1.8ubuntu1 [1140 kB] 34s Get:5 http://ftpmaster.internal/ubuntu resolute/main amd64 apt amd64 3.1.8ubuntu1 [1438 kB] 35s Get:6 http://ftpmaster.internal/ubuntu resolute/main amd64 libgirepository-1.0-1 amd64 1.86.0-6 [85.9 kB] 35s Get:7 http://ftpmaster.internal/ubuntu resolute/main amd64 gir1.2-girepository-2.0 amd64 1.86.0-6 [25.3 kB] 35s dpkg-preconfigure: unable to re-open stdin: No such file or directory 35s Fetched 2751 kB in 1s (2700 kB/s) 35s (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 ... 78439 files and directories currently installed.) 35s Preparing to unpack .../python3-minimal_3.13.7-2_amd64.deb ... 35s Unpacking python3-minimal (3.13.7-2) over (3.13.7-1) ... 35s Setting up python3-minimal (3.13.7-2) ... 35s (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 ... 78439 files and directories currently installed.) 35s Preparing to unpack .../0-python3_3.13.7-2_amd64.deb ... 35s running python pre-rtupdate hooks for python3.13... 35s Unpacking python3 (3.13.7-2) over (3.13.7-1) ... 35s Preparing to unpack .../1-libpython3-stdlib_3.13.7-2_amd64.deb ... 35s Unpacking libpython3-stdlib:amd64 (3.13.7-2) over (3.13.7-1) ... 35s Preparing to unpack .../2-libapt-pkg7.0_3.1.8ubuntu1_amd64.deb ... 35s Unpacking libapt-pkg7.0:amd64 (3.1.8ubuntu1) over (3.1.6ubuntu2) ... 35s Preparing to unpack .../3-apt_3.1.8ubuntu1_amd64.deb ... 35s Unpacking apt (3.1.8ubuntu1) over (3.1.6ubuntu2) ... 36s Preparing to unpack .../4-libgirepository-1.0-1_1.86.0-6_amd64.deb ... 36s Unpacking libgirepository-1.0-1:amd64 (1.86.0-6) over (1.84.0-1) ... 36s Preparing to unpack .../5-gir1.2-girepository-2.0_1.86.0-6_amd64.deb ... 36s Unpacking gir1.2-girepository-2.0:amd64 (1.86.0-6) over (1.84.0-1) ... 36s Setting up libgirepository-1.0-1:amd64 (1.86.0-6) ... 36s Setting up libapt-pkg7.0:amd64 (3.1.8ubuntu1) ... 36s Setting up libpython3-stdlib:amd64 (3.13.7-2) ... 36s Setting up apt (3.1.8ubuntu1) ... 36s Setting up python3 (3.13.7-2) ... 36s running python rtupdate hooks for python3.13... 36s running python post-rtupdate hooks for python3.13... 36s Setting up gir1.2-girepository-2.0:amd64 (1.86.0-6) ... 36s Processing triggers for man-db (2.13.1-1) ... 37s Processing triggers for libc-bin (2.42-0ubuntu3) ... 37s autopkgtest [18:24:09]: upgrading testbed (apt dist-upgrade and autopurge) 38s Reading package lists... 38s Building dependency tree... 38s Reading state information... 38s Calculating upgrade... 38s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 38s Reading package lists... 38s Building dependency tree... 38s Reading state information... 38s Solving dependencies... 38s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 39s autopkgtest [18:24:11]: rebooting testbed after setup commands that affected boot 53s autopkgtest [18:24:25]: testbed running kernel: Linux 6.17.0-5-generic #5-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 22 10:00:33 UTC 2025 55s autopkgtest [18:24:27]: @@@@@@@@@@@@@@@@@@@@ apt-source fatrace 57s Get:1 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (dsc) [1888 B] 57s Get:2 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (tar) [26.2 kB] 57s Get:3 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (diff) [3772 B] 57s gpgv: Signature made Sun Jan 19 11:08:15 2025 UTC 57s gpgv: using RSA key 6C4B878B7E631F160557C3CDEE7BDDE4B86B5713 57s gpgv: Can't check signature: No public key 57s dpkg-source: warning: cannot verify inline signature for ./fatrace_0.18.0-1.dsc: no acceptable signature found 57s autopkgtest [18:24:29]: testing package fatrace version 0.18.0-1 57s autopkgtest [18:24:29]: build not needed 57s autopkgtest [18:24:29]: test fatrace: preparing testbed 57s Reading package lists... 58s Building dependency tree... 58s Reading state information... 58s Solving dependencies... 58s The following NEW packages will be installed: 58s fatrace 58s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 58s Need to get 14.0 kB of archives. 58s After this operation, 44.0 kB of additional disk space will be used. 58s Get:1 http://ftpmaster.internal/ubuntu resolute/universe amd64 fatrace amd64 0.18.0-1 [14.0 kB] 58s Fetched 14.0 kB in 0s (121 kB/s) 58s Selecting previously unselected package fatrace. 58s (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 ... 78439 files and directories currently installed.) 58s Preparing to unpack .../fatrace_0.18.0-1_amd64.deb ... 58s Unpacking fatrace (0.18.0-1) ... 58s Setting up fatrace (0.18.0-1) ... 58s Processing triggers for man-db (2.13.1-1) ... 59s autopkgtest [18:24:31]: test fatrace: [----------------------- 59s starting fatrace... 60s read a file... 60s create a file... 60s waiting for fatrace... 61s checking log... 61s RC\?O\? \+/usr/bin/head$ not found in log 62s autopkgtest [18:24:34]: test fatrace: -----------------------] 62s autopkgtest [18:24:34]: test fatrace: - - - - - - - - - - results - - - - - - - - - - 62s fatrace FAIL stderr: RC\?O\? \+/usr/bin/head$ not found in log 62s autopkgtest [18:24:34]: test fatrace: - - - - - - - - - - stderr - - - - - - - - - - 62s RC\?O\? \+/usr/bin/head$ not found in log 62s autopkgtest [18:24:34]: test fatrace-currentmount: preparing testbed 63s Reading package lists... 63s Building dependency tree... 63s Reading state information... 63s Solving dependencies... 63s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 63s autopkgtest [18:24:35]: test fatrace-currentmount: [----------------------- 64s starting fatrace... 65s read a file... 65s create a file... 65s moving a file within the same directory 65s robustness against ELOOP 65s waiting for fatrace... 66s checking log... 66s ^mv(.*): < /tmp/autopkgtest.m0nJ6O/build.Fl3/src$ not found in log 66s ^mv(.*): > /tmp/autopkgtest.m0nJ6O/build.Fl3/src/dest$ not found in log 66s autopkgtest [18:24:38]: test fatrace-currentmount: -----------------------] 66s autopkgtest [18:24:38]: test fatrace-currentmount: - - - - - - - - - - results - - - - - - - - - - 66s fatrace-currentmount FAIL stderr: ^mv(.*): < /tmp/autopkgtest.m0nJ6O/build.Fl3/src$ not found in log 67s autopkgtest [18:24:39]: test fatrace-currentmount: - - - - - - - - - - stderr - - - - - - - - - - 67s ^mv(.*): < /tmp/autopkgtest.m0nJ6O/build.Fl3/src$ not found in log 67s ^mv(.*): > /tmp/autopkgtest.m0nJ6O/build.Fl3/src/dest$ not found in log 67s autopkgtest [18:24:39]: test power-usage-report: preparing testbed 67s Reading package lists... 67s Building dependency tree... 67s Reading state information... 67s Solving dependencies... 67s The following NEW packages will be installed: 67s libnl-genl-3-200 powertop 67s 0 upgraded, 2 newly installed, 0 to remove and 0 not upgraded. 67s Need to get 209 kB of archives. 67s After this operation, 667 kB of additional disk space will be used. 67s Get:1 http://ftpmaster.internal/ubuntu resolute/main amd64 libnl-genl-3-200 amd64 3.7.0-2build1 [13.0 kB] 67s Get:2 http://ftpmaster.internal/ubuntu resolute/main amd64 powertop amd64 2.15-4 [196 kB] 68s Fetched 209 kB in 0s (852 kB/s) 68s Selecting previously unselected package libnl-genl-3-200:amd64. 68s (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 ... 78445 files and directories currently installed.) 68s Preparing to unpack .../libnl-genl-3-200_3.7.0-2build1_amd64.deb ... 68s Unpacking libnl-genl-3-200:amd64 (3.7.0-2build1) ... 68s Selecting previously unselected package powertop. 68s Preparing to unpack .../powertop_2.15-4_amd64.deb ... 68s Unpacking powertop (2.15-4) ... 68s Setting up libnl-genl-3-200:amd64 (3.7.0-2build1) ... 68s Setting up powertop (2.15-4) ... 68s Processing triggers for man-db (2.13.1-1) ... 68s Processing triggers for libc-bin (2.42-0ubuntu3) ... 69s autopkgtest [18:24:41]: test power-usage-report: [----------------------- 69s modprobe cpufreq_stats failed 69s RAPL device for cpu 0 69s RAPL device for cpu 0 69s RAPL device for cpu 1 69s RAPL device for cpu 1 69s Devfreq not enabled 69s glob returned GLOB_ABORTED 69s Preparing to take measurements 71s Taking 1 measurement(s) for a duration of 1 second(s) each. 72s PowerTOP outputting using base filename powertop.csv 72s Cannot load from file /var/cache/powertop/saved_results.powertop 72s Cannot load from file /var/cache/powertop/saved_parameters.powertop 72s File will be loaded after taking minimum number of measurement(s) with battery only 72s Cannot load from file /var/cache/powertop/saved_parameters.powertop 72s File will be loaded after taking minimum number of measurement(s) with battery only 72s /usr/sbin/power-usage-report:84: SyntaxWarning: invalid escape sequence '\d' 72s event_re = re.compile('(\d+.\d+) (\S+)\((\d+)\): ([A-Z]+) (.+)$') 72s Measurement will begin in 5 seconds. Please make sure that the 72s computer is idle, i. e. do not press keys, start or operate programs, and that 72s programs are not busy with active tasks other than the one you want to examine. 77s Starting measurement for 60 seconds... 77s modprobe cpufreq_stats failed 77s Loaded 0 prior measurements 77s RAPL device for cpu 0 77s RAPL device for cpu 0 77s RAPL device for cpu 1 77s RAPL device for cpu 1 77s Devfreq not enabled 77s glob returned GLOB_ABORTED 77s Preparing to take measurements 79s Taking 1 measurement(s) for a duration of 61 second(s) each. 140s PowerTOP outputting using base filename /tmp/powertopkhldaugq.csv 140s Measurement complete. Generating report... 140s Ignoring unparseable line: 1760811949.090349 cp(1846): + /var/backups 140s Ignoring unparseable line: 1760811949.098237 gzip(1854): + /var/backups 140s Ignoring unparseable line: 1760811949.100023 mv(1855): <> /var/backups 140s Ignoring unparseable line: 1760811949.100787 mv(1856): <> /var/backups 141s autopkgtest [18:25:53]: test power-usage-report: -----------------------] 141s autopkgtest [18:25:53]: test power-usage-report: - - - - - - - - - - results - - - - - - - - - - 141s power-usage-report PASS 141s autopkgtest [18:25:53]: @@@@@@@@@@@@@@@@@@@@ summary 141s fatrace FAIL stderr: RC\?O\? \+/usr/bin/head$ not found in log 141s fatrace-currentmount FAIL stderr: ^mv(.*): < /tmp/autopkgtest.m0nJ6O/build.Fl3/src$ not found in log 141s power-usage-report PASS