0s autopkgtest [14:24:25]: starting date and time: 2025-01-03 14:24:25+0000 0s autopkgtest [14:24:25]: git checkout: 325255d2 Merge branch 'pin-any-arch' into 'ubuntu/production' 0s autopkgtest [14:24:25]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.zfknrkph/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.1-1~exp2' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@bos03-arm64-43.secgroup --name adt-plucky-arm64-fatrace-20250103-142424-juju-7f2275-prod-proposed-migration-environment-15-c5b4b3d1-69a8-4355-80d4-f6e53e8d77d6 --image adt/ubuntu-plucky-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --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,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com,radosgw.ps5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 122s autopkgtest [14:26:27]: testbed dpkg architecture: arm64 123s autopkgtest [14:26:28]: testbed apt version: 2.9.18 123s autopkgtest [14:26:28]: @@@@@@@@@@@@@@@@@@@@ test bed setup 123s autopkgtest [14:26:28]: testbed release detected to be: None 124s autopkgtest [14:26:29]: updating testbed package index (apt update) 125s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 125s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 125s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 125s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 125s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [669 kB] 125s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [60.7 kB] 125s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [10.1 kB] 125s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [9708 B] 125s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 Packages [91.4 kB] 125s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/restricted arm64 Packages [57.8 kB] 125s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/universe arm64 Packages [589 kB] 125s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse arm64 Packages [8824 B] 125s Fetched 1570 kB in 1s (1703 kB/s) 127s Reading package lists... 127s Reading package lists... 128s Building dependency tree... 128s Reading state information... 129s Calculating upgrade... 129s The following packages will be upgraded: 129s base-passwd bash-completion 129s 2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 129s Need to get 267 kB of archives. 129s After this operation, 143 kB of additional disk space will be used. 129s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 base-passwd arm64 3.6.6 [53.6 kB] 130s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 bash-completion all 1:2.16.0-1 [214 kB] 130s Preconfiguring packages ... 130s Fetched 267 kB in 1s (529 kB/s) 131s (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 ... 80060 files and directories currently installed.) 131s Preparing to unpack .../base-passwd_3.6.6_arm64.deb ... 131s Unpacking base-passwd (3.6.6) over (3.6.5) ... 131s Setting up base-passwd (3.6.6) ... 131s (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 ... 80060 files and directories currently installed.) 131s Preparing to unpack .../bash-completion_1%3a2.16.0-1_all.deb ... 131s Unpacking bash-completion (1:2.16.0-1) over (1:2.14.0-2) ... 131s Setting up bash-completion (1:2.16.0-1) ... 131s Processing triggers for man-db (2.13.0-1) ... 133s Reading package lists... 134s Building dependency tree... 134s Reading state information... 136s 0 upgraded, 0 newly installed, 0 to remove and 3 not upgraded. 136s autopkgtest [14:26:41]: upgrading testbed (apt dist-upgrade and autopurge) 136s Reading package lists... 136s Building dependency tree... 136s Reading state information... 137s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 137s Starting 2 pkgProblemResolver with broken count: 0 137s Done 138s Entering ResolveByKeep 139s 139s The following packages were automatically installed and are no longer required: 139s python3.12 python3.12-minimal 139s Use 'sudo apt autoremove' to remove them. 139s The following NEW packages will be installed: 139s libpython3.13-minimal libpython3.13-stdlib python3.13 python3.13-minimal 139s The following packages will be upgraded: 139s libpython3-stdlib python3 python3-minimal 139s 3 upgraded, 4 newly installed, 0 to remove and 0 not upgraded. 139s Need to get 5992 kB of archives. 139s After this operation, 24.3 MB of additional disk space will be used. 139s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 libpython3.13-minimal arm64 3.13.1-2 [879 kB] 140s Get:2 http://ftpmaster.internal/ubuntu plucky/main arm64 python3.13-minimal arm64 3.13.1-2 [2262 kB] 140s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 python3-minimal arm64 3.13.1-1~exp2 [27.6 kB] 140s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 python3 arm64 3.13.1-1~exp2 [23.9 kB] 140s Get:5 http://ftpmaster.internal/ubuntu plucky/main arm64 libpython3.13-stdlib arm64 3.13.1-2 [2061 kB] 140s Get:6 http://ftpmaster.internal/ubuntu plucky/main arm64 python3.13 arm64 3.13.1-2 [729 kB] 140s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main arm64 libpython3-stdlib arm64 3.13.1-1~exp2 [10.2 kB] 140s Fetched 5992 kB in 1s (7517 kB/s) 141s Selecting previously unselected package libpython3.13-minimal:arm64. 141s (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 ... 80185 files and directories currently installed.) 141s Preparing to unpack .../libpython3.13-minimal_3.13.1-2_arm64.deb ... 141s Unpacking libpython3.13-minimal:arm64 (3.13.1-2) ... 141s Selecting previously unselected package python3.13-minimal. 141s Preparing to unpack .../python3.13-minimal_3.13.1-2_arm64.deb ... 141s Unpacking python3.13-minimal (3.13.1-2) ... 141s Setting up libpython3.13-minimal:arm64 (3.13.1-2) ... 141s Setting up python3.13-minimal (3.13.1-2) ... 142s (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 ... 80505 files and directories currently installed.) 142s Preparing to unpack .../python3-minimal_3.13.1-1~exp2_arm64.deb ... 142s Unpacking python3-minimal (3.13.1-1~exp2) over (3.12.8-1) ... 142s Setting up python3-minimal (3.13.1-1~exp2) ... 143s (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 ... 80505 files and directories currently installed.) 143s Preparing to unpack .../python3_3.13.1-1~exp2_arm64.deb ... 143s Unpacking python3 (3.13.1-1~exp2) over (3.12.8-1) ... 143s Selecting previously unselected package libpython3.13-stdlib:arm64. 143s Preparing to unpack .../libpython3.13-stdlib_3.13.1-2_arm64.deb ... 143s Unpacking libpython3.13-stdlib:arm64 (3.13.1-2) ... 143s Selecting previously unselected package python3.13. 143s Preparing to unpack .../python3.13_3.13.1-2_arm64.deb ... 143s Unpacking python3.13 (3.13.1-2) ... 143s Preparing to unpack .../libpython3-stdlib_3.13.1-1~exp2_arm64.deb ... 143s Unpacking libpython3-stdlib:arm64 (3.13.1-1~exp2) over (3.12.8-1) ... 143s Setting up libpython3.13-stdlib:arm64 (3.13.1-2) ... 143s Setting up libpython3-stdlib:arm64 (3.13.1-1~exp2) ... 143s Setting up python3.13 (3.13.1-2) ... 145s Setting up python3 (3.13.1-1~exp2) ... 146s /usr/bin/py3clean:101: DeprecationWarning: glob.glob1 is deprecated and will be removed in Python 3.15. Use glob.glob and pass a directory to its root_dir argument instead. 146s for fn in glob1(directory, "%s.*" % fname): 146s Processing triggers for man-db (2.13.0-1) ... 146s Processing triggers for systemd (257-2ubuntu1) ... 147s Reading package lists... 147s Building dependency tree... 147s Reading state information... 148s Starting pkgProblemResolver with broken count: 0 148s Starting 2 pkgProblemResolver with broken count: 0 148s Done 149s The following packages will be REMOVED: 149s python3.12* python3.12-minimal* 149s 0 upgraded, 0 newly installed, 2 to remove and 0 not upgraded. 149s After this operation, 8710 kB disk space will be freed. 149s (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 ... 80922 files and directories currently installed.) 149s Removing python3.12 (3.12.8-3) ... 149s Removing python3.12-minimal (3.12.8-3) ... 150s /usr/bin/py3clean:125: DeprecationWarning: glob.glob1 is deprecated and will be removed in Python 3.15. Use glob.glob and pass a directory to its root_dir argument instead. 150s for fn in glob1(directory, "%s.%s.py[co]" % (fname, magic_tag)): 150s Processing triggers for man-db (2.13.0-1) ... 151s Processing triggers for systemd (257-2ubuntu1) ... 151s (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 ... 80894 files and directories currently installed.) 151s Purging configuration files for python3.12-minimal (3.12.8-3) ... 154s autopkgtest [14:26:59]: testbed running kernel: Linux 6.11.0-8-generic #8-Ubuntu SMP PREEMPT_DYNAMIC Mon Sep 16 14:19:41 UTC 2024 154s autopkgtest [14:26:59]: @@@@@@@@@@@@@@@@@@@@ apt-source fatrace 156s Get:1 http://ftpmaster.internal/ubuntu plucky/universe fatrace 0.17.0-1 (dsc) [1888 B] 156s Get:2 http://ftpmaster.internal/ubuntu plucky/universe fatrace 0.17.0-1 (tar) [25.2 kB] 156s Get:3 http://ftpmaster.internal/ubuntu plucky/universe fatrace 0.17.0-1 (diff) [3660 B] 156s gpgv: Signature made Fri Nov 11 10:12:01 2022 UTC 156s gpgv: using RSA key 3DB46B55EFA59D40E6232148D14EF15DAFE11347 156s gpgv: Can't check signature: No public key 156s dpkg-source: warning: cannot verify inline signature for ./fatrace_0.17.0-1.dsc: no acceptable signature found 156s autopkgtest [14:27:01]: testing package fatrace version 0.17.0-1 157s autopkgtest [14:27:02]: build not needed 157s autopkgtest [14:27:02]: test fatrace: preparing testbed 157s Reading package lists... 158s Building dependency tree... 158s Reading state information... 158s Starting pkgProblemResolver with broken count: 0 158s Starting 2 pkgProblemResolver with broken count: 0 158s Done 160s The following NEW packages will be installed: 160s fatrace 160s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 160s Need to get 12.8 kB of archives. 160s After this operation, 89.1 kB of additional disk space will be used. 160s Get:1 http://ftpmaster.internal/ubuntu plucky/universe arm64 fatrace arm64 0.17.0-1 [12.8 kB] 160s Fetched 12.8 kB in 0s (77.9 kB/s) 160s Selecting previously unselected package fatrace. 160s (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 ... 80894 files and directories currently installed.) 160s Preparing to unpack .../fatrace_0.17.0-1_arm64.deb ... 160s Unpacking fatrace (0.17.0-1) ... 160s Setting up fatrace (0.17.0-1) ... 160s Processing triggers for man-db (2.13.0-1) ... 162s autopkgtest [14:27:07]: test fatrace: [----------------------- 162s starting fatrace... 163s read a file... 163s create a file... 163s waiting for fatrace... 164s checking log... 164s autopkgtest [14:27:09]: test fatrace: -----------------------] 165s fatrace PASS 165s autopkgtest [14:27:10]: test fatrace: - - - - - - - - - - results - - - - - - - - - - 165s autopkgtest [14:27:10]: test fatrace-currentmount: preparing testbed 165s Reading package lists... 166s Building dependency tree... 166s Reading state information... 166s Starting pkgProblemResolver with broken count: 0 166s Starting 2 pkgProblemResolver with broken count: 0 166s Done 168s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 168s autopkgtest [14:27:13]: test fatrace-currentmount: [----------------------- 169s starting fatrace... 170s read a file... 170s create a file... 170s moving a file within the same directory 170s robustness against ELOOP 170s waiting for fatrace... 171s checking log... 171s autopkgtest [14:27:16]: test fatrace-currentmount: -----------------------] 172s autopkgtest [14:27:17]: test fatrace-currentmount: - - - - - - - - - - results - - - - - - - - - - 172s fatrace-currentmount PASS 172s autopkgtest [14:27:17]: test power-usage-report: preparing testbed 172s Reading package lists... 173s Building dependency tree... 173s Reading state information... 173s Starting pkgProblemResolver with broken count: 0 173s Starting 2 pkgProblemResolver with broken count: 0 173s Done 174s The following NEW packages will be installed: 174s powertop 175s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 175s Need to get 169 kB of archives. 175s After this operation, 569 kB of additional disk space will be used. 175s Get:1 http://ftpmaster.internal/ubuntu plucky/main arm64 powertop arm64 2.15-3build1 [169 kB] 175s Fetched 169 kB in 0s (482 kB/s) 175s Selecting previously unselected package powertop. 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 ... 80900 files and directories currently installed.) 176s Preparing to unpack .../powertop_2.15-3build1_arm64.deb ... 176s Unpacking powertop (2.15-3build1) ... 176s Setting up powertop (2.15-3build1) ... 176s Processing triggers for man-db (2.13.0-1) ... 177s autopkgtest [14:27:22]: test power-usage-report: [----------------------- 177s modprobe cpufreq_stats failed 177s RAPL device for cpu 0 177s RAPL device for cpu 0 177s RAPL device for cpu 1 177s RAPL device for cpu 1 177s Devfreq not enabled 177s glob returned GLOB_ABORTED 177s Preparing to take measurements 179s Taking 1 measurement(s) for a duration of 1 second(s) each. 180s PowerTOP outputting using base filename powertop.csv 180s Cannot load from file /var/cache/powertop/saved_results.powertop 180s Cannot load from file /var/cache/powertop/saved_parameters.powertop 180s File will be loaded after taking minimum number of measurement(s) with battery only 180s Cannot load from file /var/cache/powertop/saved_parameters.powertop 180s File will be loaded after taking minimum number of measurement(s) with battery only 180s /usr/sbin/power-usage-report:84: SyntaxWarning: invalid escape sequence '\d' 180s event_re = re.compile('(\d+.\d+) (\S+)\((\d+)\): ([A-Z]+) (.+)$') 180s Measurement will begin in 5 seconds. Please make sure that the 180s computer is idle, i. e. do not press keys, start or operate programs, and that 180s programs are not busy with active tasks other than the one you want to examine. 185s Starting measurement for 60 seconds... 185s modprobe cpufreq_stats failed 185s Loaded 0 prior measurements 185s RAPL device for cpu 0 185s RAPL device for cpu 0 185s RAPL device for cpu 1 185s RAPL device for cpu 1 185s Devfreq not enabled 185s glob returned GLOB_ABORTED 185s Preparing to take measurements 186s Taking 1 measurement(s) for a duration of 61 second(s) each. 248s PowerTOP outputting using base filename /tmp/powertopobfj2dcy.csv 248s Measurement complete. Generating report... 248s autopkgtest [14:28:33]: test power-usage-report: -----------------------] 248s autopkgtest [14:28:33]: test power-usage-report: - - - - - - - - - - results - - - - - - - - - - 248s power-usage-report PASS 249s autopkgtest [14:28:34]: @@@@@@@@@@@@@@@@@@@@ summary 249s fatrace PASS 249s fatrace-currentmount PASS 249s power-usage-report PASS 266s nova [W] Using flock in prodstack6-arm64 266s flock: timeout while waiting to get lock 266s Creating nova instance adt-plucky-arm64-fatrace-20250103-142424-juju-7f2275-prod-proposed-migration-environment-15-c5b4b3d1-69a8-4355-80d4-f6e53e8d77d6 from image adt/ubuntu-plucky-arm64-server-20250102.img (UUID 4cb073f4-4206-4362-b576-2406cb25ddd8)... 266s nova [W] Timed out waiting for d928334f-a1d2-4f7d-b0db-469d8cd8f585 to get deleted.