0s autopkgtest [16:22:55]: starting date and time: 2025-10-18 16:22:55+0000 0s autopkgtest [16:22:55]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [16:22:55]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.kmuvps16/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 --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-12.secgroup --name adt-resolute-arm64-fatrace-20251018-162255-juju-7f2275-prod-proposed-migration-environment-2-c6d3f235-5b3c-4996-a646-0cfc916df158 --image adt/ubuntu-resolute-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 4s Creating nova instance adt-resolute-arm64-fatrace-20251018-162255-juju-7f2275-prod-proposed-migration-environment-2-c6d3f235-5b3c-4996-a646-0cfc916df158 from image adt/ubuntu-resolute-arm64-server-20251018.img (UUID f7a49384-4e4d-4350-9a26-1f59236f89dd)... 68s autopkgtest [16:24:03]: testbed dpkg architecture: arm64 68s autopkgtest [16:24:03]: testbed apt version: 3.1.6ubuntu2 69s autopkgtest [16:24:04]: @@@@@@@@@@@@@@@@@@@@ test bed setup 69s autopkgtest [16:24:04]: testbed release detected to be: None 70s autopkgtest [16:24:05]: updating testbed package index (apt update) 70s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [83.3 kB] 71s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 71s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 71s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 71s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [345 kB] 71s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [28.4 kB] 71s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/restricted Sources [5028 B] 71s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [15.4 kB] 71s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 Packages [81.1 kB] 71s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/restricted arm64 Packages [43.8 kB] 71s Get:11 http://ftpmaster.internal/ubuntu resolute-proposed/universe arm64 Packages [223 kB] 71s Get:12 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse arm64 Packages [5672 B] 72s Fetched 831 kB in 1s (656 kB/s) 73s Reading package lists... 74s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 74s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 74s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 74s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 75s Reading package lists... 75s Reading package lists... 76s Building dependency tree... 76s Reading state information... 76s Calculating upgrade... 77s The following packages will be upgraded: 77s apt flash-kernel gir1.2-girepository-2.0 libapt-pkg7.0 libgirepository-1.0-1 77s libpython3-stdlib lto-disabled-list python3 python3-minimal 77s 9 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 77s Need to get 2671 kB of archives. 77s After this operation, 66.6 kB of additional disk space will be used. 77s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 python3-minimal arm64 3.13.7-2 [27.8 kB] 77s Get:2 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 python3 arm64 3.13.7-2 [23.9 kB] 77s Get:3 http://ftpmaster.internal/ubuntu resolute-proposed/main arm64 libpython3-stdlib arm64 3.13.7-2 [10.6 kB] 77s Get:4 http://ftpmaster.internal/ubuntu resolute/main arm64 libapt-pkg7.0 arm64 3.1.8ubuntu1 [1055 kB] 79s Get:5 http://ftpmaster.internal/ubuntu resolute/main arm64 apt arm64 3.1.8ubuntu1 [1373 kB] 81s Get:6 http://ftpmaster.internal/ubuntu resolute/main arm64 libgirepository-1.0-1 arm64 1.86.0-6 [84.5 kB] 81s Get:7 http://ftpmaster.internal/ubuntu resolute/main arm64 gir1.2-girepository-2.0 arm64 1.86.0-6 [25.3 kB] 81s Get:8 http://ftpmaster.internal/ubuntu resolute/main arm64 flash-kernel arm64 3.109ubuntu7 [58.8 kB] 81s Get:9 http://ftpmaster.internal/ubuntu resolute/main arm64 lto-disabled-list all 71 [12.5 kB] 82s dpkg-preconfigure: unable to re-open stdin: No such file or directory 82s Fetched 2671 kB in 4s (601 kB/s) 82s (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 ... 83359 files and directories currently installed.) 82s Preparing to unpack .../python3-minimal_3.13.7-2_arm64.deb ... 82s Unpacking python3-minimal (3.13.7-2) over (3.13.7-1) ... 82s Setting up python3-minimal (3.13.7-2) ... 83s (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 ... 83359 files and directories currently installed.) 83s Preparing to unpack .../0-python3_3.13.7-2_arm64.deb ... 83s running python pre-rtupdate hooks for python3.13... 83s Unpacking python3 (3.13.7-2) over (3.13.7-1) ... 83s Preparing to unpack .../1-libpython3-stdlib_3.13.7-2_arm64.deb ... 83s Unpacking libpython3-stdlib:arm64 (3.13.7-2) over (3.13.7-1) ... 83s Preparing to unpack .../2-libapt-pkg7.0_3.1.8ubuntu1_arm64.deb ... 83s Unpacking libapt-pkg7.0:arm64 (3.1.8ubuntu1) over (3.1.6ubuntu2) ... 83s Preparing to unpack .../3-apt_3.1.8ubuntu1_arm64.deb ... 83s Unpacking apt (3.1.8ubuntu1) over (3.1.6ubuntu2) ... 84s Preparing to unpack .../4-libgirepository-1.0-1_1.86.0-6_arm64.deb ... 84s Unpacking libgirepository-1.0-1:arm64 (1.86.0-6) over (1.84.0-1) ... 84s Preparing to unpack .../5-gir1.2-girepository-2.0_1.86.0-6_arm64.deb ... 84s Unpacking gir1.2-girepository-2.0:arm64 (1.86.0-6) over (1.84.0-1) ... 84s Preparing to unpack .../6-flash-kernel_3.109ubuntu7_arm64.deb ... 84s Unpacking flash-kernel (3.109ubuntu7) over (3.109ubuntu6) ... 84s Preparing to unpack .../7-lto-disabled-list_71_all.deb ... 84s Unpacking lto-disabled-list (71) over (69) ... 84s Setting up lto-disabled-list (71) ... 84s Setting up libgirepository-1.0-1:arm64 (1.86.0-6) ... 84s Setting up libapt-pkg7.0:arm64 (3.1.8ubuntu1) ... 84s Setting up libpython3-stdlib:arm64 (3.13.7-2) ... 84s Setting up apt (3.1.8ubuntu1) ... 85s Setting up python3 (3.13.7-2) ... 85s running python rtupdate hooks for python3.13... 85s running python post-rtupdate hooks for python3.13... 85s Setting up gir1.2-girepository-2.0:arm64 (1.86.0-6) ... 85s Setting up flash-kernel (3.109ubuntu7) ... 86s flash-kernel: deferring update (trigger activated) 86s Processing triggers for libc-bin (2.42-0ubuntu3) ... 86s Processing triggers for man-db (2.13.1-1) ... 88s Processing triggers for initramfs-tools (0.150ubuntu3) ... 89s update-initramfs: Generating /boot/initrd.img-6.17.0-5-generic 116s System running in EFI mode, skipping. 116s Processing triggers for flash-kernel (3.109ubuntu7) ... 116s System running in EFI mode, skipping. 117s autopkgtest [16:24:52]: upgrading testbed (apt dist-upgrade and autopurge) 118s Reading package lists... 118s Building dependency tree... 118s Reading state information... 119s Calculating upgrade... 119s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 119s Reading package lists... 120s Building dependency tree... 120s Reading state information... 120s Solving dependencies... 120s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 121s autopkgtest [16:24:56]: rebooting testbed after setup commands that affected boot 151s autopkgtest [16:25:26]: testbed running kernel: Linux 6.17.0-5-generic #5-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 22 09:50:31 UTC 2025 154s autopkgtest [16:25:29]: @@@@@@@@@@@@@@@@@@@@ apt-source fatrace 157s Get:1 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (dsc) [1888 B] 157s Get:2 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (tar) [26.2 kB] 157s Get:3 http://ftpmaster.internal/ubuntu resolute/universe fatrace 0.18.0-1 (diff) [3772 B] 157s gpgv: Signature made Sun Jan 19 11:08:15 2025 UTC 157s gpgv: using RSA key 6C4B878B7E631F160557C3CDEE7BDDE4B86B5713 157s gpgv: Can't check signature: No public key 157s dpkg-source: warning: cannot verify inline signature for ./fatrace_0.18.0-1.dsc: no acceptable signature found 157s autopkgtest [16:25:32]: testing package fatrace version 0.18.0-1 158s autopkgtest [16:25:33]: build not needed 159s autopkgtest [16:25:34]: test fatrace: preparing testbed 160s Reading package lists... 160s Building dependency tree... 160s Reading state information... 160s Solving dependencies... 161s The following NEW packages will be installed: 161s fatrace 161s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 161s Need to get 13.6 kB of archives. 161s After this operation, 89.1 kB of additional disk space will be used. 161s Get:1 http://ftpmaster.internal/ubuntu resolute/universe arm64 fatrace arm64 0.18.0-1 [13.6 kB] 162s Fetched 13.6 kB in 0s (58.1 kB/s) 162s Selecting previously unselected package fatrace. 162s (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 ... 83359 files and directories currently installed.) 162s Preparing to unpack .../fatrace_0.18.0-1_arm64.deb ... 162s Unpacking fatrace (0.18.0-1) ... 162s Setting up fatrace (0.18.0-1) ... 162s Processing triggers for man-db (2.13.1-1) ... 164s autopkgtest [16:25:39]: test fatrace: [----------------------- 164s starting fatrace... 165s read a file... 165s create a file... 165s waiting for fatrace... 166s checking log... 166s RC\?O\? \+/usr/bin/head$ not found in log 166s autopkgtest [16:25:41]: test fatrace: -----------------------] 167s autopkgtest [16:25:42]: test fatrace: - - - - - - - - - - results - - - - - - - - - - 167s fatrace FAIL stderr: RC\?O\? \+/usr/bin/head$ not found in log 167s autopkgtest [16:25:42]: test fatrace: - - - - - - - - - - stderr - - - - - - - - - - 167s RC\?O\? \+/usr/bin/head$ not found in log 168s autopkgtest [16:25:43]: test fatrace-currentmount: preparing testbed 168s Reading package lists... 168s Building dependency tree... 168s Reading state information... 168s Solving dependencies... 169s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 170s autopkgtest [16:25:45]: test fatrace-currentmount: [----------------------- 170s starting fatrace... 171s read a file... 171s create a file... 171s moving a file within the same directory 171s robustness against ELOOP 172s waiting for fatrace... 172s checking log... 173s autopkgtest [16:25:48]: test fatrace-currentmount: -----------------------] 173s fatrace-currentmount PASS 173s autopkgtest [16:25:48]: test fatrace-currentmount: - - - - - - - - - - results - - - - - - - - - - 174s autopkgtest [16:25:49]: test power-usage-report: preparing testbed 174s Reading package lists... 175s Building dependency tree... 175s Reading state information... 175s Solving dependencies... 175s The following NEW packages will be installed: 175s libnl-genl-3-200 powertop 175s 0 upgraded, 2 newly installed, 0 to remove and 0 not upgraded. 175s Need to get 187 kB of archives. 175s After this operation, 658 kB of additional disk space will be used. 175s Get:1 http://ftpmaster.internal/ubuntu resolute/main arm64 libnl-genl-3-200 arm64 3.7.0-2build1 [13.3 kB] 176s Get:2 http://ftpmaster.internal/ubuntu resolute/main arm64 powertop arm64 2.15-4 [174 kB] 176s Fetched 187 kB in 1s (356 kB/s) 176s Selecting previously unselected package libnl-genl-3-200:arm64. 176s (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 ... 83365 files and directories currently installed.) 176s Preparing to unpack .../libnl-genl-3-200_3.7.0-2build1_arm64.deb ... 176s Unpacking libnl-genl-3-200:arm64 (3.7.0-2build1) ... 176s Selecting previously unselected package powertop. 176s Preparing to unpack .../powertop_2.15-4_arm64.deb ... 176s Unpacking powertop (2.15-4) ... 176s Setting up libnl-genl-3-200:arm64 (3.7.0-2build1) ... 176s Setting up powertop (2.15-4) ... 177s Processing triggers for man-db (2.13.1-1) ... 177s Processing triggers for libc-bin (2.42-0ubuntu3) ... 178s autopkgtest [16:25:53]: test power-usage-report: [----------------------- 178s modprobe cpufreq_stats failed 178s RAPL device for cpu 0 178s RAPL device for cpu 0 178s RAPL device for cpu 1 178s RAPL device for cpu 1 178s Devfreq not enabled 178s glob returned GLOB_ABORTED 178s Preparing to take measurements 180s Taking 1 measurement(s) for a duration of 1 second(s) each. 181s PowerTOP outputting using base filename powertop.csv 181s Cannot load from file /var/cache/powertop/saved_results.powertop 181s Cannot load from file /var/cache/powertop/saved_parameters.powertop 181s File will be loaded after taking minimum number of measurement(s) with battery only 181s Cannot load from file /var/cache/powertop/saved_parameters.powertop 181s File will be loaded after taking minimum number of measurement(s) with battery only 181s /usr/sbin/power-usage-report:84: SyntaxWarning: invalid escape sequence '\d' 181s event_re = re.compile('(\d+.\d+) (\S+)\((\d+)\): ([A-Z]+) (.+)$') 181s Measurement will begin in 5 seconds. Please make sure that the 181s computer is idle, i. e. do not press keys, start or operate programs, and that 181s programs are not busy with active tasks other than the one you want to examine. 186s Starting measurement for 60 seconds... 186s modprobe cpufreq_stats failed 186s Loaded 0 prior measurements 186s RAPL device for cpu 0 186s RAPL device for cpu 0 186s RAPL device for cpu 1 186s RAPL device for cpu 1 186s Devfreq not enabled 186s glob returned GLOB_ABORTED 186s Preparing to take measurements 188s Taking 1 measurement(s) for a duration of 61 second(s) each. 249s PowerTOP outputting using base filename /tmp/powertopkkwv4ize.csv 249s Measurement complete. Generating report... 250s autopkgtest [16:27:05]: test power-usage-report: -----------------------] 250s autopkgtest [16:27:05]: test power-usage-report: - - - - - - - - - - results - - - - - - - - - - 250s power-usage-report PASS 251s autopkgtest [16:27:06]: @@@@@@@@@@@@@@@@@@@@ summary 251s fatrace FAIL stderr: RC\?O\? \+/usr/bin/head$ not found in log 251s fatrace-currentmount PASS 251s power-usage-report PASS