0s autopkgtest [08:08:00]: starting date and time: 2026-02-08 08:08:00+0000 0s autopkgtest [08:08:00]: git checkout: 4b346b80 nova: make wait_reboot return success even when a no-op 0s autopkgtest [08:08:00]: host juju-7f2275-prod-proposed-migration-environment-15; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.m41enhlv/out --timeout-copy=6000 --needs-internet=try --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:wsl-pro-service --apt-upgrade wsl-pro-service --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=wsl-pro-service/0.1.18build1 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-cpu2-ram4-disk20-s390x --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-15@sto01-s390x-34.secgroup --name adt-resolute-s390x-wsl-pro-service-20260208-080800-juju-7f2275-prod-proposed-migration-environment-15-944e6aef-4e35-4077-9c78-0d02d44661a8 --image adt/ubuntu-resolute-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-15 --net-id=net_prod-autopkgtest-workers-s390x -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 6s Creating nova instance adt-resolute-s390x-wsl-pro-service-20260208-080800-juju-7f2275-prod-proposed-migration-environment-15-944e6aef-4e35-4077-9c78-0d02d44661a8 from image adt/ubuntu-resolute-s390x-server-20260208.img (UUID bf8d2066-816d-4293-b7d1-06f39d3d29cb)... 179s autopkgtest [08:10:59]: testbed dpkg architecture: s390x 180s autopkgtest [08:11:00]: testbed apt version: 3.1.15 182s autopkgtest [08:11:02]: @@@@@@@@@@@@@@@@@@@@ test bed setup 183s autopkgtest [08:11:03]: testbed release detected to be: None 186s autopkgtest [08:11:06]: updating testbed package index (apt update) 188s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease [124 kB] 188s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 188s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 188s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 188s Get:5 http://ftpmaster.internal/ubuntu resolute-proposed/universe Sources [1523 kB] 189s Get:6 http://ftpmaster.internal/ubuntu resolute-proposed/main Sources [175 kB] 189s Get:7 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse Sources [28.2 kB] 189s Get:8 http://ftpmaster.internal/ubuntu resolute-proposed/main s390x Packages [202 kB] 189s Get:9 http://ftpmaster.internal/ubuntu resolute-proposed/universe s390x Packages [1342 kB] 189s Get:10 http://ftpmaster.internal/ubuntu resolute-proposed/multiverse s390x Packages [7384 B] 193s Fetched 3401 kB in 5s (750 kB/s) 199s Reading package lists... 203s Hit:1 http://ftpmaster.internal/ubuntu resolute-proposed InRelease 203s Hit:2 http://ftpmaster.internal/ubuntu resolute InRelease 203s Hit:3 http://ftpmaster.internal/ubuntu resolute-updates InRelease 204s Hit:4 http://ftpmaster.internal/ubuntu resolute-security InRelease 211s Reading package lists... 211s Reading package lists... 212s Building dependency tree... 212s Reading state information... 213s Calculating upgrade... 214s The following packages will be upgraded: 214s libxau6 libxkbcommon0 ubuntu-kernel-accessories ubuntu-standard 215s 4 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 215s Need to get 199 kB of archives. 215s After this operation, 4096 B of additional disk space will be used. 215s Get:1 http://ftpmaster.internal/ubuntu resolute/main s390x libxau6 s390x 1:1.0.11-1build2 [7410 B] 215s Get:2 http://ftpmaster.internal/ubuntu resolute/main s390x libxkbcommon0 s390x 1.13.1-1 [165 kB] 215s Get:3 http://ftpmaster.internal/ubuntu resolute/main s390x ubuntu-standard s390x 1.564 [13.3 kB] 215s Get:4 http://ftpmaster.internal/ubuntu resolute/main s390x ubuntu-kernel-accessories s390x 1.564 [13.1 kB] 216s dpkg-preconfigure: unable to re-open stdin: No such file or directory 217s Fetched 199 kB in 0s (940 kB/s) 218s (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 ... 88711 files and directories currently installed.) 218s Preparing to unpack .../libxau6_1%3a1.0.11-1build2_s390x.deb ... 218s Unpacking libxau6:s390x (1:1.0.11-1build2) over (1:1.0.11-1build1) ... 219s Preparing to unpack .../libxkbcommon0_1.13.1-1_s390x.deb ... 219s Unpacking libxkbcommon0:s390x (1.13.1-1) over (1.12.3-1) ... 219s Preparing to unpack .../ubuntu-standard_1.564_s390x.deb ... 219s Unpacking ubuntu-standard (1.564) over (1.563) ... 219s Preparing to unpack .../ubuntu-kernel-accessories_1.564_s390x.deb ... 220s Unpacking ubuntu-kernel-accessories (1.564) over (1.563) ... 220s Setting up libxau6:s390x (1:1.0.11-1build2) ... 220s Setting up ubuntu-kernel-accessories (1.564) ... 220s Setting up ubuntu-standard (1.564) ... 220s Setting up libxkbcommon0:s390x (1.13.1-1) ... 220s Processing triggers for libc-bin (2.42-2ubuntu4) ... 221s autopkgtest [08:11:41]: upgrading testbed (apt dist-upgrade and autopurge) 222s Reading package lists... 222s Building dependency tree... 222s Reading state information... 223s Calculating upgrade... 224s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 225s Reading package lists... 226s Building dependency tree... 226s Reading state information... 226s Solving dependencies... 227s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 232s autopkgtest [08:11:52]: testbed running kernel: Linux 6.19.0-3-generic #3-Ubuntu SMP Fri Jan 23 19:02:49 UTC 2026 232s autopkgtest [08:11:52]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 235s Get:1 http://ftpmaster.internal/ubuntu resolute-proposed/main wsl-pro-service 0.1.18build1 (dsc) [2088 B] 235s Get:2 http://ftpmaster.internal/ubuntu resolute-proposed/main wsl-pro-service 0.1.18build1 (tar) [1792 kB] 236s gpgv: Signature made Mon Feb 2 20:53:03 2026 UTC 236s gpgv: using RSA key 92FE4F8B40CADC4ECCD60C1F5961FDBE9C619809 236s gpgv: Can't check signature: No public key 236s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.18build1.dsc: no acceptable signature found 238s autopkgtest [08:11:58]: testing package wsl-pro-service version 0.1.18build1 238s autopkgtest [08:11:58]: build not needed 239s autopkgtest [08:11:59]: test command1: preparing testbed 240s Reading package lists... 241s Building dependency tree... 241s Reading state information... 242s Solving dependencies... 243s The following NEW packages will be installed: 243s autoconf automake autopoint autotools-dev build-essential cpp cpp-15 243s cpp-15-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit dh-apport 243s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-15 243s g++-15-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-15 gcc-15-s390x-linux-gnu 243s gcc-s390x-linux-gnu gettext golang-1.25-go golang-1.25-src golang-go 243s golang-src intltool-debian libarchive-zip-perl libasan8 libc-dev-bin 243s libc6-dev libcc1-0 libcrypt-dev libdebhelper-perl 243s libfile-stripnondeterminism-perl libgcc-15-dev libgomp1 libisl23 libitm1 243s liblsan0 libmpc3 libstdc++-15-dev libtool libtsan2 libubsan1 linux-libc-dev 243s m4 po-debconf rpcsvc-proto 243s 0 upgraded, 52 newly installed, 0 to remove and 0 not upgraded. 243s Need to get 104 MB of archives. 243s After this operation, 427 MB of additional disk space will be used. 243s Get:1 http://ftpmaster.internal/ubuntu resolute/main s390x m4 s390x 1.4.20-2 [223 kB] 243s Get:2 http://ftpmaster.internal/ubuntu resolute/main s390x autoconf all 2.72-3.1ubuntu1 [384 kB] 243s Get:3 http://ftpmaster.internal/ubuntu resolute/main s390x autotools-dev all 20240727.1build1 [43.4 kB] 244s Get:4 http://ftpmaster.internal/ubuntu resolute/main s390x automake all 1:1.18.1-3build1 [582 kB] 244s Get:5 http://ftpmaster.internal/ubuntu resolute/main s390x autopoint all 0.23.2-1 [620 kB] 244s Get:6 http://ftpmaster.internal/ubuntu resolute/main s390x libc-dev-bin s390x 2.42-2ubuntu4 [22.9 kB] 244s Get:7 http://ftpmaster.internal/ubuntu resolute/main s390x linux-libc-dev s390x 6.19.0-3.3 [1839 kB] 244s Get:8 http://ftpmaster.internal/ubuntu resolute/main s390x libcrypt-dev s390x 1:4.5.1-1 [127 kB] 244s Get:9 http://ftpmaster.internal/ubuntu resolute/main s390x rpcsvc-proto s390x 1.4.3-1build1 [67.1 kB] 244s Get:10 http://ftpmaster.internal/ubuntu resolute/main s390x libc6-dev s390x 2.42-2ubuntu4 [1696 kB] 244s Get:11 http://ftpmaster.internal/ubuntu resolute/main s390x libisl23 s390x 0.27-1build1 [702 kB] 244s Get:12 http://ftpmaster.internal/ubuntu resolute/main s390x libmpc3 s390x 1.3.1-2 [57.4 kB] 244s Get:13 http://ftpmaster.internal/ubuntu resolute/main s390x cpp-15-s390x-linux-gnu s390x 15.2.0-12ubuntu1 [10.2 MB] 244s Get:14 http://ftpmaster.internal/ubuntu resolute/main s390x cpp-15 s390x 15.2.0-12ubuntu1 [1028 B] 244s Get:15 http://ftpmaster.internal/ubuntu resolute/main s390x cpp-s390x-linux-gnu s390x 4:15.2.0-4ubuntu1 [5746 B] 244s Get:16 http://ftpmaster.internal/ubuntu resolute/main s390x cpp s390x 4:15.2.0-4ubuntu1 [22.4 kB] 244s Get:17 http://ftpmaster.internal/ubuntu resolute/main s390x libcc1-0 s390x 15.2.0-12ubuntu1 [50.0 kB] 244s Get:18 http://ftpmaster.internal/ubuntu resolute/main s390x libgomp1 s390x 15.2.0-12ubuntu1 [154 kB] 244s Get:19 http://ftpmaster.internal/ubuntu resolute/main s390x libitm1 s390x 15.2.0-12ubuntu1 [30.9 kB] 244s Get:20 http://ftpmaster.internal/ubuntu resolute/main s390x libasan8 s390x 15.2.0-12ubuntu1 [2968 kB] 245s Get:21 http://ftpmaster.internal/ubuntu resolute/main s390x liblsan0 s390x 15.2.0-12ubuntu1 [1354 kB] 245s Get:22 http://ftpmaster.internal/ubuntu resolute/main s390x libtsan2 s390x 15.2.0-12ubuntu1 [2685 kB] 245s Get:23 http://ftpmaster.internal/ubuntu resolute/main s390x libubsan1 s390x 15.2.0-12ubuntu1 [1211 kB] 245s Get:24 http://ftpmaster.internal/ubuntu resolute/main s390x libgcc-15-dev s390x 15.2.0-12ubuntu1 [1294 kB] 245s Get:25 http://ftpmaster.internal/ubuntu resolute/main s390x gcc-15-s390x-linux-gnu s390x 15.2.0-12ubuntu1 [19.9 MB] 245s Get:26 http://ftpmaster.internal/ubuntu resolute/main s390x gcc-15 s390x 15.2.0-12ubuntu1 [519 kB] 245s Get:27 http://ftpmaster.internal/ubuntu resolute/main s390x gcc-s390x-linux-gnu s390x 4:15.2.0-4ubuntu1 [1208 B] 245s Get:28 http://ftpmaster.internal/ubuntu resolute/main s390x gcc s390x 4:15.2.0-4ubuntu1 [5018 B] 245s Get:29 http://ftpmaster.internal/ubuntu resolute/main s390x libstdc++-15-dev s390x 15.2.0-12ubuntu1 [2660 kB] 246s Get:30 http://ftpmaster.internal/ubuntu resolute/main s390x g++-15-s390x-linux-gnu s390x 15.2.0-12ubuntu1 [11.7 MB] 246s Get:31 http://ftpmaster.internal/ubuntu resolute/main s390x g++-15 s390x 15.2.0-12ubuntu1 [25.3 kB] 246s Get:32 http://ftpmaster.internal/ubuntu resolute/main s390x g++-s390x-linux-gnu s390x 4:15.2.0-4ubuntu1 [956 B] 246s Get:33 http://ftpmaster.internal/ubuntu resolute/main s390x g++ s390x 4:15.2.0-4ubuntu1 [1078 B] 246s Get:34 http://ftpmaster.internal/ubuntu resolute/main s390x build-essential s390x 12.12ubuntu2 [5258 B] 246s Get:35 http://ftpmaster.internal/ubuntu resolute/main s390x libdebhelper-perl all 13.28ubuntu1 [97.4 kB] 246s Get:36 http://ftpmaster.internal/ubuntu resolute/main s390x libtool all 2.5.4-9 [169 kB] 246s Get:37 http://ftpmaster.internal/ubuntu resolute/main s390x dh-autoreconf all 21+nmu1 [11.9 kB] 246s Get:38 http://ftpmaster.internal/ubuntu resolute/main s390x libarchive-zip-perl all 1.68-1 [90.2 kB] 246s Get:39 http://ftpmaster.internal/ubuntu resolute/main s390x libfile-stripnondeterminism-perl all 1.15.0-1build1 [20.6 kB] 246s Get:40 http://ftpmaster.internal/ubuntu resolute/main s390x dh-strip-nondeterminism all 1.15.0-1build1 [5110 B] 246s Get:41 http://ftpmaster.internal/ubuntu resolute/main s390x debugedit s390x 1:5.2-3build1 [52.7 kB] 246s Get:42 http://ftpmaster.internal/ubuntu resolute/main s390x dwz s390x 0.16-2build1 [121 kB] 246s Get:43 http://ftpmaster.internal/ubuntu resolute/main s390x gettext s390x 0.23.2-1 [1062 kB] 246s Get:44 http://ftpmaster.internal/ubuntu resolute/main s390x intltool-debian all 0.35.0+20060710.6build1 [24.1 kB] 246s Get:45 http://ftpmaster.internal/ubuntu resolute/main s390x po-debconf all 1.0.22 [215 kB] 246s Get:46 http://ftpmaster.internal/ubuntu resolute/main s390x debhelper all 13.28ubuntu1 [916 kB] 246s Get:47 http://ftpmaster.internal/ubuntu resolute/universe s390x dh-apport all 2.33.1-0ubuntu3 [20.2 kB] 246s Get:48 http://ftpmaster.internal/ubuntu resolute/main s390x golang-1.25-src all 1.25.0-0ubuntu1 [23.0 MB] 247s Get:49 http://ftpmaster.internal/ubuntu resolute/main s390x golang-1.25-go s390x 1.25.0-0ubuntu1 [17.1 MB] 247s Get:50 http://ftpmaster.internal/ubuntu resolute/main s390x golang-src all 2:1.25~1 [5206 B] 247s Get:51 http://ftpmaster.internal/ubuntu resolute/main s390x golang-go s390x 2:1.25~1 [44.1 kB] 247s Get:52 http://ftpmaster.internal/ubuntu resolute/main s390x dh-golang all 1.63build1 [25.0 kB] 248s Fetched 104 MB in 4s (25.3 MB/s) 248s Selecting previously unselected package m4. 249s (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 ... 88711 files and directories currently installed.) 249s Preparing to unpack .../00-m4_1.4.20-2_s390x.deb ... 249s Unpacking m4 (1.4.20-2) ... 249s Selecting previously unselected package autoconf. 249s Preparing to unpack .../01-autoconf_2.72-3.1ubuntu1_all.deb ... 249s Unpacking autoconf (2.72-3.1ubuntu1) ... 250s Selecting previously unselected package autotools-dev. 250s Preparing to unpack .../02-autotools-dev_20240727.1build1_all.deb ... 250s Unpacking autotools-dev (20240727.1build1) ... 250s Selecting previously unselected package automake. 250s Preparing to unpack .../03-automake_1%3a1.18.1-3build1_all.deb ... 250s Unpacking automake (1:1.18.1-3build1) ... 250s Selecting previously unselected package autopoint. 250s Preparing to unpack .../04-autopoint_0.23.2-1_all.deb ... 250s Unpacking autopoint (0.23.2-1) ... 250s Selecting previously unselected package libc-dev-bin. 250s Preparing to unpack .../05-libc-dev-bin_2.42-2ubuntu4_s390x.deb ... 250s Unpacking libc-dev-bin (2.42-2ubuntu4) ... 250s Selecting previously unselected package linux-libc-dev:s390x. 250s Preparing to unpack .../06-linux-libc-dev_6.19.0-3.3_s390x.deb ... 250s Unpacking linux-libc-dev:s390x (6.19.0-3.3) ... 253s Selecting previously unselected package libcrypt-dev:s390x. 253s Preparing to unpack .../07-libcrypt-dev_1%3a4.5.1-1_s390x.deb ... 253s Unpacking libcrypt-dev:s390x (1:4.5.1-1) ... 253s Selecting previously unselected package rpcsvc-proto. 253s Preparing to unpack .../08-rpcsvc-proto_1.4.3-1build1_s390x.deb ... 253s Unpacking rpcsvc-proto (1.4.3-1build1) ... 253s Selecting previously unselected package libc6-dev:s390x. 253s Preparing to unpack .../09-libc6-dev_2.42-2ubuntu4_s390x.deb ... 253s Unpacking libc6-dev:s390x (2.42-2ubuntu4) ... 253s Selecting previously unselected package libisl23:s390x. 253s Preparing to unpack .../10-libisl23_0.27-1build1_s390x.deb ... 253s Unpacking libisl23:s390x (0.27-1build1) ... 253s Selecting previously unselected package libmpc3:s390x. 253s Preparing to unpack .../11-libmpc3_1.3.1-2_s390x.deb ... 253s Unpacking libmpc3:s390x (1.3.1-2) ... 253s Selecting previously unselected package cpp-15-s390x-linux-gnu. 253s Preparing to unpack .../12-cpp-15-s390x-linux-gnu_15.2.0-12ubuntu1_s390x.deb ... 253s Unpacking cpp-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 256s Selecting previously unselected package cpp-15. 256s Preparing to unpack .../13-cpp-15_15.2.0-12ubuntu1_s390x.deb ... 256s Unpacking cpp-15 (15.2.0-12ubuntu1) ... 256s Selecting previously unselected package cpp-s390x-linux-gnu. 256s Preparing to unpack .../14-cpp-s390x-linux-gnu_4%3a15.2.0-4ubuntu1_s390x.deb ... 256s Unpacking cpp-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 256s Selecting previously unselected package cpp. 256s Preparing to unpack .../15-cpp_4%3a15.2.0-4ubuntu1_s390x.deb ... 256s Unpacking cpp (4:15.2.0-4ubuntu1) ... 256s Selecting previously unselected package libcc1-0:s390x. 256s Preparing to unpack .../16-libcc1-0_15.2.0-12ubuntu1_s390x.deb ... 256s Unpacking libcc1-0:s390x (15.2.0-12ubuntu1) ... 256s Selecting previously unselected package libgomp1:s390x. 256s Preparing to unpack .../17-libgomp1_15.2.0-12ubuntu1_s390x.deb ... 256s Unpacking libgomp1:s390x (15.2.0-12ubuntu1) ... 257s Selecting previously unselected package libitm1:s390x. 257s Preparing to unpack .../18-libitm1_15.2.0-12ubuntu1_s390x.deb ... 257s Unpacking libitm1:s390x (15.2.0-12ubuntu1) ... 257s Selecting previously unselected package libasan8:s390x. 257s Preparing to unpack .../19-libasan8_15.2.0-12ubuntu1_s390x.deb ... 257s Unpacking libasan8:s390x (15.2.0-12ubuntu1) ... 257s Selecting previously unselected package liblsan0:s390x. 257s Preparing to unpack .../20-liblsan0_15.2.0-12ubuntu1_s390x.deb ... 257s Unpacking liblsan0:s390x (15.2.0-12ubuntu1) ... 258s Selecting previously unselected package libtsan2:s390x. 258s Preparing to unpack .../21-libtsan2_15.2.0-12ubuntu1_s390x.deb ... 258s Unpacking libtsan2:s390x (15.2.0-12ubuntu1) ... 259s Selecting previously unselected package libubsan1:s390x. 259s Preparing to unpack .../22-libubsan1_15.2.0-12ubuntu1_s390x.deb ... 259s Unpacking libubsan1:s390x (15.2.0-12ubuntu1) ... 259s Selecting previously unselected package libgcc-15-dev:s390x. 259s Preparing to unpack .../23-libgcc-15-dev_15.2.0-12ubuntu1_s390x.deb ... 259s Unpacking libgcc-15-dev:s390x (15.2.0-12ubuntu1) ... 259s Selecting previously unselected package gcc-15-s390x-linux-gnu. 259s Preparing to unpack .../24-gcc-15-s390x-linux-gnu_15.2.0-12ubuntu1_s390x.deb ... 259s Unpacking gcc-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 262s Selecting previously unselected package gcc-15. 262s Preparing to unpack .../25-gcc-15_15.2.0-12ubuntu1_s390x.deb ... 262s Unpacking gcc-15 (15.2.0-12ubuntu1) ... 262s Selecting previously unselected package gcc-s390x-linux-gnu. 262s Preparing to unpack .../26-gcc-s390x-linux-gnu_4%3a15.2.0-4ubuntu1_s390x.deb ... 262s Unpacking gcc-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 262s Selecting previously unselected package gcc. 262s Preparing to unpack .../27-gcc_4%3a15.2.0-4ubuntu1_s390x.deb ... 262s Unpacking gcc (4:15.2.0-4ubuntu1) ... 262s Selecting previously unselected package libstdc++-15-dev:s390x. 262s Preparing to unpack .../28-libstdc++-15-dev_15.2.0-12ubuntu1_s390x.deb ... 262s Unpacking libstdc++-15-dev:s390x (15.2.0-12ubuntu1) ... 264s Selecting previously unselected package g++-15-s390x-linux-gnu. 264s Preparing to unpack .../29-g++-15-s390x-linux-gnu_15.2.0-12ubuntu1_s390x.deb ... 264s Unpacking g++-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 266s Selecting previously unselected package g++-15. 266s Preparing to unpack .../30-g++-15_15.2.0-12ubuntu1_s390x.deb ... 266s Unpacking g++-15 (15.2.0-12ubuntu1) ... 266s Selecting previously unselected package g++-s390x-linux-gnu. 266s Preparing to unpack .../31-g++-s390x-linux-gnu_4%3a15.2.0-4ubuntu1_s390x.deb ... 266s Unpacking g++-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 267s Selecting previously unselected package g++. 267s Preparing to unpack .../32-g++_4%3a15.2.0-4ubuntu1_s390x.deb ... 267s Unpacking g++ (4:15.2.0-4ubuntu1) ... 267s Selecting previously unselected package build-essential. 267s Preparing to unpack .../33-build-essential_12.12ubuntu2_s390x.deb ... 267s Unpacking build-essential (12.12ubuntu2) ... 267s Selecting previously unselected package libdebhelper-perl. 267s Preparing to unpack .../34-libdebhelper-perl_13.28ubuntu1_all.deb ... 267s Unpacking libdebhelper-perl (13.28ubuntu1) ... 267s Selecting previously unselected package libtool. 267s Preparing to unpack .../35-libtool_2.5.4-9_all.deb ... 267s Unpacking libtool (2.5.4-9) ... 267s Selecting previously unselected package dh-autoreconf. 267s Preparing to unpack .../36-dh-autoreconf_21+nmu1_all.deb ... 267s Unpacking dh-autoreconf (21+nmu1) ... 267s Selecting previously unselected package libarchive-zip-perl. 267s Preparing to unpack .../37-libarchive-zip-perl_1.68-1_all.deb ... 267s Unpacking libarchive-zip-perl (1.68-1) ... 267s Selecting previously unselected package libfile-stripnondeterminism-perl. 267s Preparing to unpack .../38-libfile-stripnondeterminism-perl_1.15.0-1build1_all.deb ... 267s Unpacking libfile-stripnondeterminism-perl (1.15.0-1build1) ... 267s Selecting previously unselected package dh-strip-nondeterminism. 267s Preparing to unpack .../39-dh-strip-nondeterminism_1.15.0-1build1_all.deb ... 267s Unpacking dh-strip-nondeterminism (1.15.0-1build1) ... 267s Selecting previously unselected package debugedit. 267s Preparing to unpack .../40-debugedit_1%3a5.2-3build1_s390x.deb ... 267s Unpacking debugedit (1:5.2-3build1) ... 267s Selecting previously unselected package dwz. 267s Preparing to unpack .../41-dwz_0.16-2build1_s390x.deb ... 267s Unpacking dwz (0.16-2build1) ... 267s Selecting previously unselected package gettext. 268s Preparing to unpack .../42-gettext_0.23.2-1_s390x.deb ... 268s Unpacking gettext (0.23.2-1) ... 268s Selecting previously unselected package intltool-debian. 268s Preparing to unpack .../43-intltool-debian_0.35.0+20060710.6build1_all.deb ... 268s Unpacking intltool-debian (0.35.0+20060710.6build1) ... 268s Selecting previously unselected package po-debconf. 268s Preparing to unpack .../44-po-debconf_1.0.22_all.deb ... 268s Unpacking po-debconf (1.0.22) ... 268s Selecting previously unselected package debhelper. 268s Preparing to unpack .../45-debhelper_13.28ubuntu1_all.deb ... 268s Unpacking debhelper (13.28ubuntu1) ... 268s Selecting previously unselected package dh-apport. 268s Preparing to unpack .../46-dh-apport_2.33.1-0ubuntu3_all.deb ... 268s Unpacking dh-apport (2.33.1-0ubuntu3) ... 269s Selecting previously unselected package golang-1.25-src. 269s Preparing to unpack .../47-golang-1.25-src_1.25.0-0ubuntu1_all.deb ... 269s Unpacking golang-1.25-src (1.25.0-0ubuntu1) ... 277s Selecting previously unselected package golang-1.25-go. 277s Preparing to unpack .../48-golang-1.25-go_1.25.0-0ubuntu1_s390x.deb ... 277s Unpacking golang-1.25-go (1.25.0-0ubuntu1) ... 282s Selecting previously unselected package golang-src. 282s Preparing to unpack .../49-golang-src_2%3a1.25~1_all.deb ... 282s Unpacking golang-src (2:1.25~1) ... 282s Selecting previously unselected package golang-go:s390x. 282s Preparing to unpack .../50-golang-go_2%3a1.25~1_s390x.deb ... 282s Unpacking golang-go:s390x (2:1.25~1) ... 282s Selecting previously unselected package dh-golang. 282s Preparing to unpack .../51-dh-golang_1.63build1_all.deb ... 282s Unpacking dh-golang (1.63build1) ... 283s Setting up libarchive-zip-perl (1.68-1) ... 283s Setting up libdebhelper-perl (13.28ubuntu1) ... 283s Setting up linux-libc-dev:s390x (6.19.0-3.3) ... 283s Setting up m4 (1.4.20-2) ... 283s Setting up libgomp1:s390x (15.2.0-12ubuntu1) ... 283s Setting up dh-apport (2.33.1-0ubuntu3) ... 283s Setting up autotools-dev (20240727.1build1) ... 283s Setting up rpcsvc-proto (1.4.3-1build1) ... 283s Setting up libmpc3:s390x (1.3.1-2) ... 283s Setting up autopoint (0.23.2-1) ... 283s Setting up autoconf (2.72-3.1ubuntu1) ... 283s Setting up libubsan1:s390x (15.2.0-12ubuntu1) ... 283s Setting up dwz (0.16-2build1) ... 283s Setting up golang-1.25-src (1.25.0-0ubuntu1) ... 283s Setting up libcrypt-dev:s390x (1:4.5.1-1) ... 283s Setting up libasan8:s390x (15.2.0-12ubuntu1) ... 283s Setting up debugedit (1:5.2-3build1) ... 283s Setting up libtsan2:s390x (15.2.0-12ubuntu1) ... 283s Setting up libisl23:s390x (0.27-1build1) ... 283s Setting up libc-dev-bin (2.42-2ubuntu4) ... 283s Setting up golang-src (2:1.25~1) ... 283s Setting up libcc1-0:s390x (15.2.0-12ubuntu1) ... 283s Setting up liblsan0:s390x (15.2.0-12ubuntu1) ... 283s Setting up libitm1:s390x (15.2.0-12ubuntu1) ... 283s Setting up automake (1:1.18.1-3build1) ... 283s update-alternatives: using /usr/bin/automake-1.18 to provide /usr/bin/automake (automake) in auto mode 283s Setting up libfile-stripnondeterminism-perl (1.15.0-1build1) ... 283s Setting up golang-1.25-go (1.25.0-0ubuntu1) ... 283s Setting up gettext (0.23.2-1) ... 283s Setting up libgcc-15-dev:s390x (15.2.0-12ubuntu1) ... 283s Setting up golang-go:s390x (2:1.25~1) ... 283s Setting up intltool-debian (0.35.0+20060710.6build1) ... 283s Setting up dh-strip-nondeterminism (1.15.0-1build1) ... 283s Setting up cpp-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 283s Setting up libc6-dev:s390x (2.42-2ubuntu4) ... 283s Setting up gcc-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 283s Setting up cpp-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 283s Setting up po-debconf (1.0.22) ... 283s Setting up libstdc++-15-dev:s390x (15.2.0-12ubuntu1) ... 283s Setting up gcc-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 283s Setting up cpp-15 (15.2.0-12ubuntu1) ... 283s Setting up cpp (4:15.2.0-4ubuntu1) ... 283s Setting up g++-15-s390x-linux-gnu (15.2.0-12ubuntu1) ... 283s Setting up g++-s390x-linux-gnu (4:15.2.0-4ubuntu1) ... 283s Setting up gcc-15 (15.2.0-12ubuntu1) ... 283s Setting up g++-15 (15.2.0-12ubuntu1) ... 283s Setting up libtool (2.5.4-9) ... 283s Setting up gcc (4:15.2.0-4ubuntu1) ... 283s Setting up dh-autoreconf (21+nmu1) ... 283s Setting up g++ (4:15.2.0-4ubuntu1) ... 283s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 283s Setting up build-essential (12.12ubuntu2) ... 283s Setting up debhelper (13.28ubuntu1) ... 283s Setting up dh-golang (1.63build1) ... 283s Processing triggers for man-db (2.13.1-1build1) ... 291s Processing triggers for install-info (7.2-5) ... 291s Processing triggers for libc-bin (2.42-2ubuntu4) ... 292s autopkgtest [08:12:52]: test command1: ./debian/tests/test 292s autopkgtest [08:12:52]: test command1: [----------------------- 580s === RUN TestRunSignal 580s === RUN TestRunSignal/Send_SIGINT_exits 580s INFO Starting WSL Pro Service version Dev 580s === RUN TestRunSignal/Send_SIGTERM_exits 580s INFO Starting WSL Pro Service version Dev 580s --- PASS: TestRunSignal (0.28s) 580s --- PASS: TestRunSignal/Send_SIGINT_exits (0.18s) 580s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 580s === RUN TestRun 580s === PAUSE TestRun 580s === CONT TestRun 580s === RUN TestRun/Run_and_exit_successfully 580s === PAUSE TestRun/Run_and_exit_successfully 580s === RUN TestRun/Run_and_return_error 580s === PAUSE TestRun/Run_and_return_error 580s === RUN TestRun/Run_and_return_usage_error 580s === PAUSE TestRun/Run_and_return_usage_error 580s === RUN TestRun/Run_and_usage_error_only_does_not_fail 580s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 580s === CONT TestRun/Run_and_exit_successfully 580s INFO Starting WSL Pro Service version Dev 580s === CONT TestRun/Run_and_usage_error_only_does_not_fail 580s INFO Starting WSL Pro Service version Dev 580s === CONT TestRun/Run_and_return_usage_error 580s INFO Starting WSL Pro Service version Dev 580s === CONT TestRun/Run_and_return_error 580s INFO Starting WSL Pro Service version Dev 580s ERROR context.Background Error requested 580s ERROR context.Background Error requested 580s --- PASS: TestRun (0.00s) 580s --- PASS: TestRun/Run_and_exit_successfully (0.22s) 580s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.22s) 580s --- PASS: TestRun/Run_and_return_error (0.16s) 580s --- PASS: TestRun/Run_and_return_usage_error (0.16s) 580s PASS 580s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.818s 665s === RUN TestHelp 665s --- PASS: TestHelp (0.00s) 665s === RUN TestCompletion 665s --- PASS: TestCompletion (0.01s) 665s === RUN TestVersion 665s --- PASS: TestVersion (0.00s) 665s === RUN TestConfigBadArg 665s --- PASS: TestConfigBadArg (0.00s) 665s === RUN TestConfigArg 665s --- PASS: TestConfigArg (0.00s) 665s === RUN TestConfigAutoDetect 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/service.go:64 New.func1() Debug mode is enabled" 665s --- PASS: TestConfigAutoDetect (0.00s) 665s === RUN TestNoUsageError 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/service.go:64 New.func1() Debug mode is enabled" 665s --- PASS: TestNoUsageError (0.00s) 665s === RUN TestUsageError 665s === PAUSE TestUsageError 665s === RUN TestCanQuitWhenExecute 665s === PAUSE TestCanQuitWhenExecute 665s === RUN TestCanQuitTwice 665s === PAUSE TestCanQuitTwice 665s === RUN TestAppCanQuitWithoutExecute 665s === PAUSE TestAppCanQuitWithoutExecute 665s === RUN TestAppRunFailsOnComponentsCreationAndQuit 665s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 665s === RUN TestAppGetRootCmd 665s === PAUSE TestAppGetRootCmd 665s === RUN TestWithProMock 665s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 665s --- SKIP: TestWithProMock (0.00s) 665s === RUN TestWithWslPathMock 665s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 665s --- SKIP: TestWithWslPathMock (0.00s) 665s === RUN TestWithWslInfoMock 665s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 665s --- SKIP: TestWithWslInfoMock (0.00s) 665s === RUN TestWithCmdExeMock 665s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 665s --- SKIP: TestWithCmdExeMock (0.00s) 665s === CONT TestAppGetRootCmd 665s === CONT TestUsageError 665s --- PASS: TestAppGetRootCmd (0.00s) 665s === CONT TestAppCanQuitWithoutExecute 665s service_test.go:190: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 665s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 665s === CONT TestAppRunFailsOnComponentsCreationAndQuit 665s --- PASS: TestUsageError (0.00s) 665s === CONT TestCanQuitTwice 665s time="2026-02-08T08:20:00Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46063" 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/service.go:64 New.func1() Debug mode is enabled" 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:74 New() Building new daemon" 665s time="2026-02-08T08:20:00Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33585" 665s time="2026-02-08T08:20:00Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/config.go:53 initViperConfig() Using configuration file: /tmp/go-build2735206181/b386/wsl-pro-service.yaml" 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/service.go:64 New.func1() Debug mode is enabled" 665s time="2026-02-08T08:20:00Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:74 New() Building new daemon" 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:55 (*System).syncWithCloudInit() Checking cloud-init status" 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:45 (*System).EnsureValidLandscapeConfig() No Landscape configuration detected: nothing to do" 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s === CONT TestCanQuitWhenExecute 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36711" 665s time="2026-02-08T08:20:33Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/config.go:53 initViperConfig() Using configuration file: /tmp/go-build2735206181/b386/wsl-pro-service.yaml" 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/cmd/wsl-pro-service/service/service.go:64 New.func1() Debug mode is enabled" 665s time="2026-02-08T08:20:33Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:74 New() Building new daemon" 665s --- PASS: TestCanQuitTwice (32.77s) 665s time="2026-02-08T08:20:37Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:55 (*System).syncWithCloudInit() Checking cloud-init status" 665s time="2026-02-08T08:20:37Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:45 (*System).EnsureValidLandscapeConfig() No Landscape configuration detected: nothing to do" 665s time="2026-02-08T08:20:37Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:163 (*Daemon).serveOnce() Daemon: connecting to Windows Agent from PID 6492" 665s time="2026-02-08T08:20:56Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:20:56Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:20:56Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (55.50s) 665s time="2026-02-08T08:21:07Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:55 (*System).syncWithCloudInit() Checking cloud-init status" 665s time="2026-02-08T08:21:07Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/landscape.go:45 (*System).EnsureValidLandscapeConfig() No Landscape configuration detected: nothing to do" 665s time="2026-02-08T08:21:07Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:163 (*Daemon).serveOnce() Daemon: connecting to Windows Agent from PID 6492" 665s time="2026-02-08T08:21:08Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:21:08Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:21:19Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:282 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:36711" 665s time="2026-02-08T08:21:19Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:183 (*Daemon).serveOnce() Daemon: completed connection to Windows Agent" 665s time="2026-02-08T08:21:19Z" level=warning msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:194 (*Daemon).serveOnce() Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:36711: connect: connection refused\"" 665s time="2026-02-08T08:21:19Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:144 (*Daemon).Serve.func2() Reconnecting to Windows host in 1 seconds" 665s time="2026-02-08T08:21:19Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s time="2026-02-08T08:21:19Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:215 (*Daemon).Quit() Stopping daemon requested." 665s time="2026-02-08T08:21:19Z" level=info msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:221 (*Daemon).Quit() Waiting for active requests to close." 665s time="2026-02-08T08:21:19Z" level=debug msg="/tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon.go:229 (*Daemon).Quit() All connections have now ended." 665s --- PASS: TestCanQuitWhenExecute (46.59s) 665s PASS 665s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 79.416s 665s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 668s === RUN TestApplyProToken 668s === PAUSE TestApplyProToken 668s === RUN TestApplyLandscapeConfig 668s === PAUSE TestApplyLandscapeConfig 668s === RUN TestWithProMock 668s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithProMock (0.00s) 668s === RUN TestWithLandscapeConfigMock 668s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithLandscapeConfigMock (0.00s) 668s === RUN TestWithWslPathMock 668s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithWslPathMock (0.00s) 668s === RUN TestWithWslInfoMock 668s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithWslInfoMock (0.00s) 668s === RUN TestWithCmdExeMock 668s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithCmdExeMock (0.00s) 668s === CONT TestApplyProToken 668s === RUN TestApplyProToken/Success_attaching 668s === PAUSE TestApplyProToken/Success_attaching 668s === RUN TestApplyProToken/Success_detaching 668s === PAUSE TestApplyProToken/Success_detaching 668s === RUN TestApplyProToken/Error_calling_pro_detach 668s === PAUSE TestApplyProToken/Error_calling_pro_detach 668s === RUN TestApplyProToken/Error_calling_pro_attach 668s === PAUSE TestApplyProToken/Error_calling_pro_attach 668s === CONT TestApplyProToken/Success_attaching 668s time="2026-02-08T08:20:10Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 668s === CONT TestApplyLandscapeConfig 668s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 668s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 668s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 668s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 668s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 668s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 668s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 668s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 668s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 668s time="2026-02-08T08:20:10Z" level=info msg="ApplyLandscapeConfig: received config: registering" 668s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 668s time="2026-02-08T08:20:27Z" level=info msg="ApplyLandscapeConfig: received config: registering" 668s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 668s time="2026-02-08T08:20:36Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 668s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 668s time="2026-02-08T08:20:43Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 668s === CONT TestApplyProToken/Error_calling_pro_detach 668s time="2026-02-08T08:20:54Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 668s --- PASS: TestApplyLandscapeConfig (0.00s) 668s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (16.57s) 668s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (15.86s) 668s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (17.91s) 668s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (16.57s) 668s === CONT TestApplyProToken/Error_calling_pro_attach 668s time="2026-02-08T08:20:59Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 668s === CONT TestApplyProToken/Success_detaching 668s time="2026-02-08T08:21:07Z" level=info msg="ApplyProToken: Received empty token: detaching" 668s --- PASS: TestApplyProToken (0.00s) 668s --- PASS: TestApplyProToken/Success_attaching (25.79s) 668s --- PASS: TestApplyProToken/Error_calling_pro_detach (13.00s) 668s --- PASS: TestApplyProToken/Success_detaching (11.20s) 668s --- PASS: TestApplyProToken/Error_calling_pro_attach (23.09s) 668s PASS 668s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 72.407s 668s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 1269s === RUN TestNew 1269s === PAUSE TestNew 1269s === RUN TestServe 1269s === PAUSE TestServe 1269s === RUN TestServeAndQuit 1269s === PAUSE TestServeAndQuit 1269s === RUN TestRetryLogic 1269s === PAUSE TestRetryLogic 1269s === RUN TestReconnection 1269s === PAUSE TestReconnection 1269s === RUN TestWithProMock 1269s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1269s --- SKIP: TestWithProMock (0.00s) 1269s === RUN TestWithWslPathMock 1269s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1269s --- SKIP: TestWithWslPathMock (0.00s) 1269s === RUN TestWithWslInfoMock 1269s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1269s --- SKIP: TestWithWslInfoMock (0.00s) 1269s === RUN TestWithCmdExeMock 1269s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1269s --- SKIP: TestWithCmdExeMock (0.00s) 1269s === CONT TestNew 1269s === RUN TestNew/Success 1269s === PAUSE TestNew/Success 1269s === RUN TestNew/Error_when_WslPath_returns_error 1269s === PAUSE TestNew/Error_when_WslPath_returns_error 1269s === CONT TestNew/Success 1269s time="2026-02-08T08:21:26Z" level=debug msg="Building new daemon" 1269s === CONT TestRetryLogic 1269s === RUN TestRetryLogic/Without_retries 1269s === PAUSE TestRetryLogic/Without_retries 1269s === RUN TestRetryLogic/With_the_context_pre-cancelled 1269s === PAUSE TestRetryLogic/With_the_context_pre-cancelled 1269s === RUN TestRetryLogic/With_the_context_cancelled_while_waiting 1269s === PAUSE TestRetryLogic/With_the_context_cancelled_while_waiting 1269s === RUN TestRetryLogic/When_max_attempts_are_exhausted 1269s === PAUSE TestRetryLogic/When_max_attempts_are_exhausted 1269s === RUN TestRetryLogic/Error_only_when_action_errors 1269s === PAUSE TestRetryLogic/Error_only_when_action_errors 1269s === CONT TestReconnection 1269s === RUN TestReconnection/Success_connecting_after_failing_to_connect 1269s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 1269s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 1269s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 1269s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 1269s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 1269s === CONT TestServe 1269s === RUN TestServe/Error_because_the_notifier_returns_an_error 1269s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 1269s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 1269s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 1269s === RUN TestServe/Success 1269s === PAUSE TestServe/Success 1269s === RUN TestServe/Success_with_systemd_notifier_returning_true 1269s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 1269s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 1269s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 1269s === RUN TestServe/No_connection_because_the_port_file_is_empty 1269s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 1269s === RUN TestServe/No_connection_because_the_port_file_has_port_0 1269s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 1269s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 1269s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 1269s === RUN TestServe/No_connection_because_there_are_no_certificates 1269s === PAUSE TestServe/No_connection_because_there_are_no_certificates 1269s === RUN TestServe/Error_because_the_context_is_pre-cancelled 1269s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 1269s === RUN TestServe/Success_with_a_broken_Landscape_config 1269s === PAUSE TestServe/Success_with_a_broken_Landscape_config 1269s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 1269s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 1269s === RUN TestServe/No_connection_because_there_is_no_server 1269s === PAUSE TestServe/No_connection_because_there_is_no_server 1269s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 1269s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 1269s === CONT TestServeAndQuit 1269s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 1269s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 1269s === RUN TestServeAndQuit/Success_with_graceful_quit 1269s === PAUSE TestServeAndQuit/Success_with_graceful_quit 1269s === RUN TestServeAndQuit/Success_with_forceful_quit 1269s === PAUSE TestServeAndQuit/Success_with_forceful_quit 1269s === RUN TestServeAndQuit/Success_with_double_quit 1269s === PAUSE TestServeAndQuit/Success_with_double_quit 1269s === CONT TestNew/Error_when_WslPath_returns_error 1269s time="2026-02-08T08:21:26Z" level=debug msg="Building new daemon" 1269s === CONT TestRetryLogic/Without_retries 1269s === CONT TestReconnection/Success_connecting_after_failing_to_connect 1269s time="2026-02-08T08:21:58Z" level=debug msg="Building new daemon" 1269s --- PASS: TestNew (0.00s) 1269s --- PASS: TestNew/Error_when_WslPath_returns_error (30.92s) 1269s --- PASS: TestNew/Success (33.64s) 1269s === CONT TestRetryLogic/Error_only_when_action_errors 1269s === CONT TestRetryLogic/When_max_attempts_are_exhausted 1269s === CONT TestRetryLogic/With_the_context_cancelled_while_waiting 1269s === CONT TestRetryLogic/With_the_context_pre-cancelled 1269s --- PASS: TestRetryLogic (0.03s) 1269s --- PASS: TestRetryLogic/Without_retries (0.98s) 1269s --- PASS: TestRetryLogic/Error_only_when_action_errors (0.00s) 1269s --- PASS: TestRetryLogic/When_max_attempts_are_exhausted (0.47s) 1269s --- PASS: TestRetryLogic/With_the_context_cancelled_while_waiting (0.03s) 1269s --- PASS: TestRetryLogic/With_the_context_pre-cancelled (0.00s) 1269s === CONT TestServe/Error_because_the_notifier_returns_an_error 1269s time="2026-02-08T08:22:00Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43653" 1269s time="2026-02-08T08:22:00Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:22:16Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:22:16Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:22:16Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:22:16Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:22:16Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:22:16Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3638838118/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3638838118/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 1269s time="2026-02-08T08:22:16Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:22:16Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 1269s time="2026-02-08T08:22:17Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46363" 1269s time="2026-02-08T08:22:17Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:22:17Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:22:21Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 1269s time="2026-02-08T08:22:21Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:22:21Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:22:21Z" level=debug msg="All connections have now ended." 1269s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 1269s time="2026-02-08T08:22:21Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:22:33Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46363" 1269s time="2026-02-08T08:22:33Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:22:33Z" level=debug msg="Updated systemd status to \"Connected\"" 1269s time="2026-02-08T08:22:33Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:22:33Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s === NAME TestReconnection/Success_connecting_after_failing_to_connect 1269s daemon_test.go:465: 1269s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:465 1269s Error: Condition never satisfied 1269s Test: TestReconnection/Success_connecting_after_failing_to_connect 1269s Messages: Daemon never connected to agent's service 1269s time="2026-02-08T08:22:37Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:22:37Z" level=info msg="Stopping active requests." 1269s time="2026-02-08T08:22:37Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:22:37Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:22:37Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:22:50Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s time="2026-02-08T08:22:50Z" level=debug msg="All connections have now ended." 1269s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 1269s time="2026-02-08T08:22:50Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:22:53Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46375" 1269s time="2026-02-08T08:22:53Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:22:53Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:22:53Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:22:53Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:22:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:23:12Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46375" 1269s time="2026-02-08T08:23:12Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:23:12Z" level=debug msg="Updated systemd status to \"Connected\"" 1269s time="2026-02-08T08:23:12Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:23:12Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s === NAME TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 1269s daemon_test.go:448: 1269s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:448 1269s Error: Condition never satisfied 1269s Test: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 1269s Messages: Daemon never connected to agent's service 1269s time="2026-02-08T08:23:23Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:23Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:23Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:23Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:23:23Z" level=info msg="Stopping active requests." 1269s time="2026-02-08T08:23:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40675" 1269s time="2026-02-08T08:23:25Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:23:25Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:23:25Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:23:25Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:23:25Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:23:34Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s time="2026-02-08T08:23:34Z" level=debug msg="All connections have now ended." 1269s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 1269s time="2026-02-08T08:23:34Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34323" 1269s time="2026-02-08T08:23:34Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:23:43Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40675" 1269s time="2026-02-08T08:23:43Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:23:43Z" level=debug msg="Updated systemd status to \"Connected\"" 1269s time="2026-02-08T08:23:44Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s time="2026-02-08T08:23:44Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s === NAME TestReconnection/Success_connecting_after_previous_connection_dropped 1269s daemon_test.go:448: 1269s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:448 1269s Error: Condition never satisfied 1269s Test: TestReconnection/Success_connecting_after_previous_connection_dropped 1269s Messages: Daemon never connected to agent's service 1269s time="2026-02-08T08:23:54Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:54Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:54Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:23:54Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:23:54Z" level=info msg="Stopping active requests." 1269s time="2026-02-08T08:24:00Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s time="2026-02-08T08:24:00Z" level=debug msg="All connections have now ended." 1269s --- FAIL: TestReconnection (0.00s) 1269s --- FAIL: TestReconnection/Success_connecting_after_failing_to_connect (52.30s) 1269s --- FAIL: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (73.27s) 1269s --- FAIL: TestReconnection/Success_connecting_after_previous_connection_dropped (69.97s) 1269s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 1269s time="2026-02-08T08:24:00Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34807" 1269s time="2026-02-08T08:24:00Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:24:12Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:24:12Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:24:12Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:24:12Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:24:12Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s === CONT TestServe/No_connection_because_there_is_no_server 1269s time="2026-02-08T08:24:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46501" 1269s time="2026-02-08T08:24:12Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:24:37Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:24:37Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:24:37Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:24:45Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:24:46Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:24:46Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:24:54Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34807" 1269s time="2026-02-08T08:24:54Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_571732489/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 1269s time="2026-02-08T08:24:54Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:24:54Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:24:54Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:24:54Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 1269s time="2026-02-08T08:24:54Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45533" 1269s time="2026-02-08T08:24:54Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:25:00Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46501" 1269s time="2026-02-08T08:25:00Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:25:00Z" level=warning msg="Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:46501: connect: connection refused\"" 1269s time="2026-02-08T08:25:00Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:25:01Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:25:01Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:25:01Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/Success_with_a_broken_Landscape_config 1269s time="2026-02-08T08:25:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45063" 1269s time="2026-02-08T08:25:01Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:25:29Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:25:29Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:25:29Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:25:29Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:portyMcPortface\": could not parse port as an integer: strconv.Atoi: parsing \"portyMcPortface\": invalid syntax" 1269s time="2026-02-08T08:25:29Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:25:30Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:25:30Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:25:30Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/Error_because_the_context_is_pre-cancelled 1269s time="2026-02-08T08:25:30Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39573" 1269s time="2026-02-08T08:25:30Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:25:39Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:25:40Z" level=warning msg="Could not ensure valid Landscape configuration: could not ensure valid Landscape configuration: read /tmp/TestServeSuccess_with_a_broken_Landscape_config3395374454/001/etc/landscape/client.conf: is a directory" 1269s time="2026-02-08T08:25:40Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:25:56Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45063" 1269s time="2026-02-08T08:25:56Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:25:56Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:25:56Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s time="2026-02-08T08:26:05Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:26:05Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:26:05Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/No_connection_because_there_are_no_certificates 1269s time="2026-02-08T08:26:05Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40769" 1269s time="2026-02-08T08:26:05Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:26:15Z" level=debug msg="Server: sent preface messages to all streams" 1269s time="2026-02-08T08:26:15Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 1269s time="2026-02-08T08:26:15Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 1269s time="2026-02-08T08:26:15Z" level=info msg="MockWindowsAgent: Connected ready" 1269s time="2026-02-08T08:26:16Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:26:16Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:26:16Z" level=warning msg="Daemon: disconnected from Windows host" 1269s time="2026-02-08T08:26:16Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:26:16Z" level=debug msg="All connections have now ended." 1269s time="2026-02-08T08:26:16Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 1269s time="2026-02-08T08:26:16Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:26:16Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:26:16Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34123" 1269s time="2026-02-08T08:26:16Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:26:40Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:26:40Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:26:40Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:26:56Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:26:57Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:26:57Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:26:57Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:-5\": port cannot be negative" 1269s time="2026-02-08T08:26:57Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:26:57Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40769" 1269s time="2026-02-08T08:26:57Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates2595049381/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 1269s time="2026-02-08T08:26:57Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:26:57Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:26:57Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:26:57Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/No_connection_because_the_port_file_has_port_0 1269s time="2026-02-08T08:26:57Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43431" 1269s time="2026-02-08T08:26:57Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:26:58Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:26:58Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:26:58Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/No_connection_because_the_port_file_is_empty 1269s time="2026-02-08T08:26:58Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38693" 1269s time="2026-02-08T08:26:58Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:27:38Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:27:38Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:27:38Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:27:38Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"\": could not split address: missing port in address" 1269s time="2026-02-08T08:27:38Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:27:38Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:27:38Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:27:38Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:27:38Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:0\": port cannot be zero" 1269s time="2026-02-08T08:27:38Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:27:39Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:27:39Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:27:39Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 1269s time="2026-02-08T08:27:39Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42559" 1269s time="2026-02-08T08:27:39Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:27:39Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:27:39Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:27:39Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/Success_with_systemd_notifier_returning_true 1269s time="2026-02-08T08:27:39Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40449" 1269s time="2026-02-08T08:27:39Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:28:11Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:28:11Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:28:11Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:28:11Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_the_port_file_does_not_exist3645418128/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist3645418128/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 1269s time="2026-02-08T08:28:11Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:28:12Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:28:12Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:28:12Z" level=debug msg="All connections have now ended." 1269s === CONT TestServe/Success 1269s time="2026-02-08T08:28:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43515" 1269s time="2026-02-08T08:28:12Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:28:20Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:28:20Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:28:20Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:28:20Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:28:20Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:28:39Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40449" 1269s time="2026-02-08T08:28:39Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:28:39Z" level=debug msg="Updated systemd status to \"Connected\"" 1269s time="2026-02-08T08:28:39Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:28:39Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s time="2026-02-08T08:28:49Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:28:49Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:28:49Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:28:59Z" level=debug msg="Server: sent preface messages to all streams" 1269s time="2026-02-08T08:28:59Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 1269s time="2026-02-08T08:28:59Z" level=info msg="MockWindowsAgent: Connected ready" 1269s time="2026-02-08T08:28:59Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 1269s time="2026-02-08T08:29:01Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:29:01Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:29:01Z" level=warning msg="Daemon: disconnected from Windows host" 1269s time="2026-02-08T08:29:01Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:29:01Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 1269s time="2026-02-08T08:29:01Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s time="2026-02-08T08:29:01Z" level=debug msg="All connections have now ended." 1269s time="2026-02-08T08:29:01Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 1269s time="2026-02-08T08:29:01Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:29:01Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:29:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36017" 1269s time="2026-02-08T08:29:01Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:29:07Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43515" 1269s time="2026-02-08T08:29:07Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:29:07Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:29:07Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s time="2026-02-08T08:29:25Z" level=debug msg="Server: sent preface messages to all streams" 1269s time="2026-02-08T08:29:25Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 1269s time="2026-02-08T08:29:25Z" level=info msg="MockWindowsAgent: Connected ready" 1269s time="2026-02-08T08:29:25Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 1269s time="2026-02-08T08:29:26Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:29:26Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:29:26Z" level=warning msg="Daemon: disconnected from Windows host" 1269s time="2026-02-08T08:29:26Z" level=info msg="Reconnecting to Windows host in 1 seconds" 1269s time="2026-02-08T08:29:26Z" level=debug msg="All connections have now ended." 1269s time="2026-02-08T08:29:26Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s === CONT TestServeAndQuit/Success_with_forceful_quit 1269s time="2026-02-08T08:29:26Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:29:26Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:29:26Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:32967" 1269s time="2026-02-08T08:29:26Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:29:36Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:29:37Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:29:37Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:29:52Z" level=info msg="Stopping daemon requested." 1269s time="2026-02-08T08:29:52Z" level=info msg="Waiting for active requests to close." 1269s time="2026-02-08T08:29:52Z" level=debug msg="All connections have now ended." 1269s --- PASS: TestServe (0.00s) 1269s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (20.85s) 1269s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (54.14s) 1269s --- PASS: TestServe/No_connection_because_there_is_no_server (48.76s) 1269s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (35.75s) 1269s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (35.16s) 1269s --- PASS: TestServe/Success_with_a_broken_Landscape_config (75.46s) 1269s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (40.64s) 1269s --- PASS: TestServe/No_connection_because_there_are_no_certificates (52.66s) 1269s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (41.00s) 1269s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (41.83s) 1269s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (33.65s) 1269s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (82.04s) 1269s --- PASS: TestServe/Success (73.63s) 1269s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (51.28s) 1269s === CONT TestServeAndQuit/Success_with_double_quit 1269s time="2026-02-08T08:29:52Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38419" 1269s time="2026-02-08T08:29:52Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:29:59Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:29:59Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:29:59Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:29:59Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:29:59Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s time="2026-02-08T08:30:17Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:32967" 1269s time="2026-02-08T08:30:17Z" level=info msg="Daemon: completed connection to Windows Agent" 1269s time="2026-02-08T08:30:17Z" level=debug msg="Updated systemd status to \"Connected\"" 1269s time="2026-02-08T08:30:18Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1269s time="2026-02-08T08:30:18Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1269s time="2026-02-08T08:30:25Z" level=debug msg="Ready state sent to systemd" 1269s time="2026-02-08T08:30:25Z" level=debug msg="Checking cloud-init status" 1269s time="2026-02-08T08:30:25Z" level=debug msg="No Landscape configuration detected: nothing to do" 1269s time="2026-02-08T08:30:25Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1269s time="2026-02-08T08:30:25Z" level=debug msg="Updated systemd status to \"Connecting\"" 1269s === NAME TestServeAndQuit/Success_with_forceful_quit 1269s daemon_test.go:302: 1269s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:302 1269s Error: Condition never satisfied 1269s Test: TestServeAndQuit/Success_with_forceful_quit 1269s Messages: Daemon never connected to agent's service 1269s time="2026-02-08T08:30:28Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s === CONT TestServeAndQuit/Success_with_graceful_quit 1269s time="2026-02-08T08:30:28Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40401" 1269s time="2026-02-08T08:30:28Z" level=debug msg="Building new daemon" 1269s time="2026-02-08T08:30:28Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:30:28Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1269s time="2026-02-08T08:30:36Z" level=debug msg="Updated systemd status to \"Stopped\"" 1269s === NAME TestServeAndQuit/Success_with_double_quit 1270s daemon_test.go:296: 1270s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:296 1270s Error: Condition never satisfied 1270s Test: TestServeAndQuit/Success_with_double_quit 1270s Messages: Systemd state should have been set to "STATUS=Connected" 1270s time="2026-02-08T08:30:48Z" level=debug msg="Updated systemd status to \"Stopped\"" 1270s time="2026-02-08T08:31:00Z" level=debug msg="Ready state sent to systemd" 1270s time="2026-02-08T08:31:00Z" level=debug msg="Checking cloud-init status" 1270s time="2026-02-08T08:31:00Z" level=debug msg="No Landscape configuration detected: nothing to do" 1270s time="2026-02-08T08:31:00Z" level=info msg="Daemon: connecting to Windows Agent from PID 7573" 1270s time="2026-02-08T08:31:00Z" level=debug msg="Updated systemd status to \"Connecting\"" 1270s time="2026-02-08T08:31:13Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40401" 1270s time="2026-02-08T08:31:13Z" level=info msg="Daemon: completed connection to Windows Agent" 1270s time="2026-02-08T08:31:13Z" level=debug msg="Updated systemd status to \"Connected\"" 1270s time="2026-02-08T08:31:13Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 1270s time="2026-02-08T08:31:13Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 1270s === NAME TestServeAndQuit/Success_with_graceful_quit 1270s daemon_test.go:302: 1270s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/daemon/daemon_test.go:302 1270s Error: Condition never satisfied 1270s Test: TestServeAndQuit/Success_with_graceful_quit 1270s Messages: Daemon never connected to agent's service 1270s time="2026-02-08T08:31:24Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s time="2026-02-08T08:31:24Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s time="2026-02-08T08:31:24Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s --- FAIL: TestServeAndQuit (0.00s) 1270s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (38.10s) 1270s --- FAIL: TestServeAndQuit/Success_with_forceful_quit (61.89s) 1270s --- FAIL: TestServeAndQuit/Success_with_double_quit (53.07s) 1270s --- FAIL: TestServeAndQuit/Success_with_graceful_quit (55.71s) 1270s FAIL 1270s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 597.916s 1270s === RUN TestConnect 1270s === PAUSE TestConnect 1270s === RUN TestSendAndRecv 1270s --- PASS: TestSendAndRecv (0.86s) 1270s === RUN TestServe 1270s === PAUSE TestServe 1270s === RUN TestStop 1270s === PAUSE TestStop 1270s === RUN TestWithProMock 1270s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1270s --- SKIP: TestWithProMock (0.00s) 1270s === RUN TestWithWslPathMock 1270s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1270s --- SKIP: TestWithWslPathMock (0.00s) 1270s === RUN TestWithWslInfoMock 1270s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1270s --- SKIP: TestWithWslInfoMock (0.00s) 1270s === RUN TestWithCmdExeMock 1270s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1270s --- SKIP: TestWithCmdExeMock (0.00s) 1270s === CONT TestConnect 1270s === RUN TestConnect/Success 1270s === PAUSE TestConnect/Success 1270s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 1270s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 1270s === CONT TestConnect/Success 1270s === CONT TestStop 1270s time="2026-02-08T08:21:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44147" 1270s === CONT TestServe 1270s time="2026-02-08T08:21:37Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39715" 1270s === NAME TestStop 1270s server_test.go:111: 1270s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/streams/server_test.go:111 1270s Error: Condition never satisfied 1270s Test: TestStop 1270s Messages: Setup: Agent service never became ready 1270s time="2026-02-08T08:21:56Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s time="2026-02-08T08:21:56Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s time="2026-02-08T08:21:56Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s --- FAIL: TestStop (20.06s) 1270s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 1270s === NAME TestServe 1270s server_test.go:41: 1270s Error Trace: /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/streams/server_test.go:41 1270s Error: Condition never satisfied 1270s Test: TestServe 1270s Messages: Setup: Agent service never became ready 1270s time="2026-02-08T08:21:57Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s --- FAIL: TestServe (20.04s) 1270s time="2026-02-08T08:21:57Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s time="2026-02-08T08:21:57Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 1270s --- PASS: TestConnect (0.00s) 1270s --- PASS: TestConnect/Success (0.43s) 1270s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.01s) 1270s FAIL 1270s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 40.945s 1340s === RUN TestNew 1340s === PAUSE TestNew 1340s === RUN TestInfo 1340s === PAUSE TestInfo 1340s === RUN TestWslDistroName 1340s === PAUSE TestWslDistroName 1340s === RUN TestUserProfileDir 1340s === PAUSE TestUserProfileDir 1340s === RUN TestProStatus 1340s === PAUSE TestProStatus 1340s === RUN TestProAttach 1340s === PAUSE TestProAttach 1340s === RUN TestProDetach 1340s === PAUSE TestProDetach 1340s === RUN TestLandscapeEnable 1340s === PAUSE TestLandscapeEnable 1340s === RUN TestWindowsHostAddress 1340s === PAUSE TestWindowsHostAddress 1340s === RUN TestLandscapeDisable 1340s === PAUSE TestLandscapeDisable 1340s === RUN TestEnsureValidLandscapeConfig 1340s === PAUSE TestEnsureValidLandscapeConfig 1340s === RUN TestRealBackend 1340s === PAUSE TestRealBackend 1340s === RUN TestWithProMock 1340s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1340s --- SKIP: TestWithProMock (0.00s) 1340s === RUN TestWithLandscapeConfigMock 1340s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1340s --- SKIP: TestWithLandscapeConfigMock (0.00s) 1340s === RUN TestWithWslPathMock 1340s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1340s --- SKIP: TestWithWslPathMock (0.00s) 1340s === RUN TestWithWslInfoMock 1340s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1340s --- SKIP: TestWithWslInfoMock (0.00s) 1340s === RUN TestWithCmdExeMock 1340s mock_executables.go:650: Skipped because it is not a real test, but rather a mocked executable 1340s --- SKIP: TestWithCmdExeMock (0.00s) 1340s === CONT TestNew 1340s === RUN TestNew/Return_a_new_system 1340s === PAUSE TestNew/Return_a_new_system 1340s === CONT TestProDetach 1340s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 1340s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 1340s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 1340s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 1340s === RUN TestProDetach/success_on_unattached_distro 1340s === PAUSE TestProDetach/success_on_unattached_distro 1340s === RUN TestProDetach/success_on_attached_distro 1340s === PAUSE TestProDetach/success_on_attached_distro 1340s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 1340s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 1340s === CONT TestRealBackend 1340s --- PASS: TestRealBackend (0.00s) 1340s === CONT TestEnsureValidLandscapeConfig 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_can_not_get_WSL_Distro_name 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_can_not_get_WSL_Distro_name 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_landscape_user_does_not_exist 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_landscape_user_does_not_exist 1340s === RUN TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path 1340s === PAUSE TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path 1340s === RUN TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s === PAUSE TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s === RUN TestEnsureValidLandscapeConfig/Regular_with_additional_keys 1340s === PAUSE TestEnsureValidLandscapeConfig/Regular_with_additional_keys 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_new_config_cannot_be_parsed 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_new_config_cannot_be_parsed 1340s === RUN TestEnsureValidLandscapeConfig/Do_not_modify_other_sections_and_keys 1340s === PAUSE TestEnsureValidLandscapeConfig/Do_not_modify_other_sections_and_keys 1340s === RUN TestEnsureValidLandscapeConfig/No_Landscape_configuration_means_no_landscape_command_nor_config_created 1340s === PAUSE TestEnsureValidLandscapeConfig/No_Landscape_configuration_means_no_landscape_command_nor_config_created 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_new_config_do_not_have_client_section 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_new_config_do_not_have_client_section 1340s === RUN TestEnsureValidLandscapeConfig/Appends_any_required_fields_-_no_ssl 1340s === PAUSE TestEnsureValidLandscapeConfig/Appends_any_required_fields_-_no_ssl 1340s === RUN TestEnsureValidLandscapeConfig/Do_not_transform_Windows_SSL_certificate_empty_path 1340s === PAUSE TestEnsureValidLandscapeConfig/Do_not_transform_Windows_SSL_certificate_empty_path 1340s === RUN TestEnsureValidLandscapeConfig/Refresh_computer_title_if_changed 1340s === PAUSE TestEnsureValidLandscapeConfig/Refresh_computer_title_if_changed 1340s === RUN TestEnsureValidLandscapeConfig/Reformat_Landscape_config_to_proper_ini 1340s === PAUSE TestEnsureValidLandscapeConfig/Reformat_Landscape_config_to_proper_ini 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_failing_to_override_the_SSL_certficate_path 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_failing_to_override_the_SSL_certficate_path 1340s === RUN TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_without_modifications 1340s === PAUSE TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_without_modifications 1340s === RUN TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_due_whitespace_changes 1340s === PAUSE TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_due_whitespace_changes 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_config_file_cannot_be_read 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_config_file_cannot_be_read 1340s === RUN TestEnsureValidLandscapeConfig/Error_when_the_landscape-config_command_fails 1340s === PAUSE TestEnsureValidLandscapeConfig/Error_when_the_landscape-config_command_fails 1340s === CONT TestLandscapeDisable 1340s === RUN TestLandscapeDisable/Success 1340s === PAUSE TestLandscapeDisable/Success 1340s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 1340s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 1340s === CONT TestWindowsHostAddress 1340s === RUN TestWindowsHostAddress/Without_NAT 1340s === PAUSE TestWindowsHostAddress/Without_NAT 1340s === RUN TestWindowsHostAddress/With_NAT 1340s === PAUSE TestWindowsHostAddress/With_NAT 1340s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 1340s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 1340s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 1340s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 1340s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 1340s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 1340s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 1340s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 1340s === CONT TestLandscapeEnable 1340s === RUN TestLandscapeEnable/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s === PAUSE TestLandscapeEnable/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s === RUN TestLandscapeEnable/Reformat_Landscape_config_to_proper_ini 1340s === PAUSE TestLandscapeEnable/Reformat_Landscape_config_to_proper_ini 1340s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 1340s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 1340s === RUN TestLandscapeEnable/Error_when_the_can_not_get_WSL_Distro_name 1340s === PAUSE TestLandscapeEnable/Error_when_the_can_not_get_WSL_Distro_name 1340s === RUN TestLandscapeEnable/Transform_Windows_SSL_certificate_path 1340s === PAUSE TestLandscapeEnable/Transform_Windows_SSL_certificate_path 1340s === RUN TestLandscapeEnable/Refresh_computer_title_if_changed 1340s === PAUSE TestLandscapeEnable/Refresh_computer_title_if_changed 1340s === RUN TestLandscapeEnable/Error_when_the_new_config_do_not_have_client_section 1340s === PAUSE TestLandscapeEnable/Error_when_the_new_config_do_not_have_client_section 1340s === RUN TestLandscapeEnable/Error_when_the_config_directory_cannot_be_created 1340s === PAUSE TestLandscapeEnable/Error_when_the_config_directory_cannot_be_created 1340s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 1340s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 1340s === RUN TestLandscapeEnable/Appends_any_required_fields_-_no_ssl 1340s === PAUSE TestLandscapeEnable/Appends_any_required_fields_-_no_ssl 1340s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_renamed 1340s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_renamed 1340s === RUN TestLandscapeEnable/Regular_with_additional_keys 1340s === PAUSE TestLandscapeEnable/Regular_with_additional_keys 1340s === RUN TestLandscapeEnable/Do_not_modify_other_sections_and_keys 1340s === PAUSE TestLandscapeEnable/Do_not_modify_other_sections_and_keys 1340s === RUN TestLandscapeEnable/Rerun_landscape_even_without_modifications 1340s === PAUSE TestLandscapeEnable/Rerun_landscape_even_without_modifications 1340s === RUN TestLandscapeEnable/Error_when_the_new_config_cannot_be_parsed 1340s === PAUSE TestLandscapeEnable/Error_when_the_new_config_cannot_be_parsed 1340s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 1340s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 1340s === CONT TestUserProfileDir 1340s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 1340s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 1340s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 1340s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 1340s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 1340s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 1340s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 1340s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 1340s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 1340s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 1340s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 1340s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 1340s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 1340s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 1340s === RUN TestUserProfileDir/Error_on_cmd.exe_error 1340s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 1340s === RUN TestUserProfileDir/Error_when_UserProfile_env_var_is_empty 1340s === PAUSE TestUserProfileDir/Error_when_UserProfile_env_var_is_empty 1340s === RUN TestUserProfileDir/Error_on_wslpath_error 1340s === PAUSE TestUserProfileDir/Error_on_wslpath_error 1340s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 1340s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 1340s === CONT TestProAttach 1340s === RUN TestProAttach/success 1340s === PAUSE TestProAttach/success 1340s === RUN TestProAttach/error_on_'pro_attach'_error 1340s === PAUSE TestProAttach/error_on_'pro_attach'_error 1340s === CONT TestProStatus 1340s === RUN TestProStatus/success_on_unattached_distro 1340s === PAUSE TestProStatus/success_on_unattached_distro 1340s === RUN TestProStatus/success_on_attached_distro 1340s === PAUSE TestProStatus/success_on_attached_distro 1340s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 1340s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 1340s === RUN TestProStatus/error_on_'pro_attach'_error 1340s === PAUSE TestProStatus/error_on_'pro_attach'_error 1340s === CONT TestWslDistroName 1340s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 1340s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 1340s === RUN TestWslDistroName/Success_using_wslpath 1340s === PAUSE TestWslDistroName/Success_using_wslpath 1340s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 1340s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 1340s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 1340s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 1340s === CONT TestInfo 1340s === RUN TestInfo/Error_when_WslDistroName_fails 1340s === PAUSE TestInfo/Error_when_WslDistroName_fails 1340s === RUN TestInfo/Error_when_pro_status_command_fails 1340s === PAUSE TestInfo/Error_when_pro_status_command_fails 1340s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 1340s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 1340s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 1340s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 1340s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 1340s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 1340s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 1340s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 1340s === RUN TestInfo/Success 1340s === PAUSE TestInfo/Success 1340s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 1340s === RUN TestNew/Ignore_errors_when_the_Landscape_config_validation_failed_(only_warnings) 1340s === PAUSE TestNew/Ignore_errors_when_the_Landscape_config_validation_failed_(only_warnings) 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_can_not_get_WSL_Distro_name 1340s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 1340s === CONT TestProDetach/success_on_attached_distro 1340s === CONT TestProDetach/success_on_unattached_distro 1340s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 1340s === CONT TestLandscapeDisable/Success 1340s --- PASS: TestProDetach (0.00s) 1340s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (18.87s) 1340s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (15.39s) 1340s --- PASS: TestProDetach/success_on_attached_distro (18.98s) 1340s --- PASS: TestProDetach/success_on_unattached_distro (15.58s) 1340s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (15.43s) 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_landscape-config_command_fails 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_config_file_cannot_be_read 1340s === CONT TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_due_whitespace_changes 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/do_not_rerun_landscape_due_whitespace_changes 1340s === CONT TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_without_modifications 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_failing_to_override_the_SSL_certficate_path 1340s === NAME TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_without_modifications 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/do_not_rerun_landscape_without_modifications 1340s === CONT TestEnsureValidLandscapeConfig/Reformat_Landscape_config_to_proper_ini 1340s === CONT TestEnsureValidLandscapeConfig/Refresh_computer_title_if_changed 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/refresh_computer_title_if_changed 1340s === CONT TestEnsureValidLandscapeConfig/Do_not_transform_Windows_SSL_certificate_empty_path 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/do_not_transform_windows_ssl_certificate_empty_path 1340s === CONT TestEnsureValidLandscapeConfig/Appends_any_required_fields_-_no_ssl 1340s === NAME TestEnsureValidLandscapeConfig/Reformat_Landscape_config_to_proper_ini 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/reformat_landscape_config_to_proper_ini 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_new_config_do_not_have_client_section 1340s === CONT TestEnsureValidLandscapeConfig/No_Landscape_configuration_means_no_landscape_command_nor_config_created 1340s === CONT TestEnsureValidLandscapeConfig/Do_not_modify_other_sections_and_keys 1340s === NAME TestEnsureValidLandscapeConfig/Appends_any_required_fields_-_no_ssl 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/appends_any_required_fields_-_no_ssl 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_new_config_cannot_be_parsed 1340s === CONT TestEnsureValidLandscapeConfig/Regular_with_additional_keys 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/regular_with_additional_keys 1340s === CONT TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s === NAME TestEnsureValidLandscapeConfig/Do_not_modify_other_sections_and_keys 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/do_not_modify_other_sections_and_keys 1340s === CONT TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/transform_windows_ssl_certificate_path 1340s === CONT TestEnsureValidLandscapeConfig/Error_when_the_landscape_user_does_not_exist 1340s === NAME TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s system_test.go:768: testdata/TestEnsureValidLandscapeConfig/golden/transform_windows_ssl_certificate_path_with_forward_slash 1340s === CONT TestWindowsHostAddress/Without_NAT 1340s --- PASS: TestEnsureValidLandscapeConfig (0.00s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_can_not_get_WSL_Distro_name (21.23s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_config_file_cannot_be_read (1.11s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_due_whitespace_changes (15.11s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_landscape-config_command_fails (33.04s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Do_not_rerun_landscape_without_modifications (17.11s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_failing_to_override_the_SSL_certficate_path (14.01s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Refresh_computer_title_if_changed (17.56s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Do_not_transform_Windows_SSL_certificate_empty_path (0.50s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Reformat_Landscape_config_to_proper_ini (36.61s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_new_config_do_not_have_client_section (0.54s) 1340s --- PASS: TestEnsureValidLandscapeConfig/No_Landscape_configuration_means_no_landscape_command_nor_config_created (0.26s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Appends_any_required_fields_-_no_ssl (16.64s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_new_config_cannot_be_parsed (0.20s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Regular_with_additional_keys (33.88s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Do_not_modify_other_sections_and_keys (34.48s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path (30.54s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Transform_Windows_SSL_certificate_path_with_forward_slash (30.86s) 1340s --- PASS: TestEnsureValidLandscapeConfig/Error_when_the_landscape_user_does_not_exist (15.60s) 1340s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 1340s === CONT TestLandscapeEnable/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s --- PASS: TestLandscapeDisable (0.00s) 1340s --- PASS: TestLandscapeDisable/Success (16.64s) 1340s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (13.28s) 1340s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 1340s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 1340s === NAME TestLandscapeEnable/Transform_Windows_SSL_certificate_path_with_forward_slash 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/transform_windows_ssl_certificate_path_with_forward_slash 1340s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 1340s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 1340s === CONT TestWindowsHostAddress/With_NAT 1340s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 1340s --- PASS: TestWindowsHostAddress (0.00s) 1340s --- PASS: TestWindowsHostAddress/Without_NAT (18.70s) 1340s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (16.28s) 1340s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (15.84s) 1340s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (17.05s) 1340s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (17.35s) 1340s --- PASS: TestWindowsHostAddress/With_NAT (18.27s) 1340s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 1340s === CONT TestLandscapeEnable/Error_when_the_new_config_cannot_be_parsed 1340s === CONT TestLandscapeEnable/Rerun_landscape_even_without_modifications 1340s === CONT TestLandscapeEnable/Do_not_modify_other_sections_and_keys 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/do_not_modify_other_sections_and_keys 1340s === CONT TestLandscapeEnable/Regular_with_additional_keys 1340s === NAME TestLandscapeEnable/Rerun_landscape_even_without_modifications 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/rerun_landscape_even_without_modifications 1340s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_renamed 1340s === CONT TestLandscapeEnable/Appends_any_required_fields_-_no_ssl 1340s === NAME TestLandscapeEnable/Regular_with_additional_keys 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/regular_with_additional_keys 1340s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 1340s === NAME TestLandscapeEnable/Appends_any_required_fields_-_no_ssl 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/appends_any_required_fields_-_no_ssl 1340s === CONT TestLandscapeEnable/Error_when_the_config_directory_cannot_be_created 1340s === CONT TestLandscapeEnable/Error_when_the_new_config_do_not_have_client_section 1340s === CONT TestLandscapeEnable/Refresh_computer_title_if_changed 1340s === CONT TestLandscapeEnable/Transform_Windows_SSL_certificate_path 1340s === NAME TestLandscapeEnable/Refresh_computer_title_if_changed 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/refresh_computer_title_if_changed 1340s === CONT TestLandscapeEnable/Error_when_the_can_not_get_WSL_Distro_name 1340s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 1340s === NAME TestLandscapeEnable/Transform_Windows_SSL_certificate_path 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/transform_windows_ssl_certificate_path 1340s === CONT TestLandscapeEnable/Reformat_Landscape_config_to_proper_ini 1340s === CONT TestProAttach/success 1340s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 1340s === NAME TestLandscapeEnable/Reformat_Landscape_config_to_proper_ini 1340s system_test.go:526: testdata/TestLandscapeEnable/golden/reformat_landscape_config_to_proper_ini 1340s --- PASS: TestLandscapeEnable (0.00s) 1340s --- PASS: TestLandscapeEnable/Transform_Windows_SSL_certificate_path_with_forward_slash (30.23s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_new_config_cannot_be_parsed (0.00s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (32.31s) 1340s --- PASS: TestLandscapeEnable/Do_not_modify_other_sections_and_keys (29.18s) 1340s --- PASS: TestLandscapeEnable/Rerun_landscape_even_without_modifications (39.12s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_renamed (18.20s) 1340s --- PASS: TestLandscapeEnable/Regular_with_additional_keys (34.19s) 1340s --- PASS: TestLandscapeEnable/Appends_any_required_fields_-_no_ssl (16.41s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (16.20s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_new_config_do_not_have_client_section (0.00s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_config_directory_cannot_be_created (20.36s) 1340s --- PASS: TestLandscapeEnable/Refresh_computer_title_if_changed (16.37s) 1340s --- PASS: TestLandscapeEnable/Error_when_the_can_not_get_WSL_Distro_name (19.08s) 1340s --- PASS: TestLandscapeEnable/Transform_Windows_SSL_certificate_path (37.36s) 1340s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (18.39s) 1340s --- PASS: TestLandscapeEnable/Reformat_Landscape_config_to_proper_ini (32.11s) 1340s === CONT TestUserProfileDir/Error_on_wslpath_error 1340s === CONT TestUserProfileDir/Error_when_UserProfile_env_var_is_empty 1340s === CONT TestUserProfileDir/Error_on_cmd.exe_error 1340s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 1340s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 1340s system_test.go:245: Removing default proc/mounts 1340s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 1340s system_test.go:245: Removing default proc/mounts 1340s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 1340s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 1340s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 1340s === CONT TestProStatus/success_on_unattached_distro 1340s === CONT TestProAttach/error_on_'pro_attach'_error 1340s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 1340s --- PASS: TestUserProfileDir (0.00s) 1340s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (30.56s) 1340s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (28.71s) 1340s --- PASS: TestUserProfileDir/Error_on_wslpath_error (31.45s) 1340s --- PASS: TestUserProfileDir/Error_when_UserProfile_env_var_is_empty (12.10s) 1340s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 1340s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 1340s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.01s) 1340s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (11.16s) 1340s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (23.13s) 1340s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (22.77s) 1340s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (22.32s) 1340s === CONT TestProStatus/error_on_'pro_attach'_error 1340s --- PASS: TestProAttach (0.00s) 1340s --- PASS: TestProAttach/success (16.29s) 1340s --- PASS: TestProAttach/error_on_'pro_attach'_error (9.15s) 1340s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 1340s === CONT TestProStatus/success_on_attached_distro 1340s === CONT TestInfo/Error_when_WslDistroName_fails 1340s --- PASS: TestProStatus (0.00s) 1340s --- PASS: TestProStatus/success_on_unattached_distro (9.34s) 1340s --- PASS: TestProStatus/error_on_'pro_attach'_error (7.73s) 1340s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (9.51s) 1340s --- PASS: TestProStatus/success_on_attached_distro (7.77s) 1340s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 1340s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 1340s === CONT TestWslDistroName/Success_using_wslpath 1340s === CONT TestInfo/Success 1340s --- PASS: TestWslDistroName (0.00s) 1340s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 1340s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (7.92s) 1340s --- PASS: TestWslDistroName/Success_using_wslpath (7.92s) 1340s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (9.38s) 1340s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 1340s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 1340s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 1340s panic: test timed out after 10m0s 1340s running tests: 1340s TestInfo/Error_whem_/etc/os-release_returns_bad_contents (2s) 1340s TestInfo/Error_when_/etc/os-release_cannot_be_read (2s) 1340s 1340s goroutine 276 [running]: 1340s testing.(*M).startAlarm.func1() 1340s /usr/lib/go-1.25/src/testing/testing.go:2682 +0x444 1340s created by time.goFunc 1340s /usr/lib/go-1.25/src/time/sleep.go:215 +0x42 1340s 1340s goroutine 1 [chan receive, 2 minutes]: 1340s testing.tRunner.func1() 1340s /usr/lib/go-1.25/src/testing/testing.go:1891 +0x4f8 1340s testing.tRunner(0xc0001de380, 0xc0001dbca0) 1340s /usr/lib/go-1.25/src/testing/testing.go:1940 +0x182 1340s testing.runTests(0xc00000ec78, {0xca6520, 0x11, 0x11}, {0xc25a306891ad11e1, 0x8bb31687e2, 0xcb3f80}) 1340s /usr/lib/go-1.25/src/testing/testing.go:2475 +0x50a 1340s testing.(*M).Run(0xc0001f4be0) 1340s /usr/lib/go-1.25/src/testing/testing.go:2337 +0x6ec 1340s main.main() 1340s _testmain.go:79 +0xd8 1340s 1340s goroutine 7 [chan receive, 2 minutes]: 1340s testing.tRunner.func1() 1340s /usr/lib/go-1.25/src/testing/testing.go:1891 +0x4f8 1340s testing.tRunner(0xc0001de540, 0x802070) 1340s /usr/lib/go-1.25/src/testing/testing.go:1940 +0x182 1340s created by testing.(*T).Run in goroutine 1 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 8 [chan receive]: 1340s testing.tRunner.func1() 1340s /usr/lib/go-1.25/src/testing/testing.go:1891 +0x4f8 1340s testing.tRunner(0xc0001de8c0, 0x802058) 1340s /usr/lib/go-1.25/src/testing/testing.go:1940 +0x182 1340s created by testing.(*T).Run in goroutine 1 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 25 [chan receive, 2 minutes]: 1340s testing.(*testState).waitParallel(0xc000021090) 1340s /usr/lib/go-1.25/src/testing/testing.go:2116 +0x128 1340s testing.(*T).Parallel(0xc0001c1a40) 1340s /usr/lib/go-1.25/src/testing/testing.go:1709 +0x2d4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestNew.func1(0xc0001c1a40) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:38 +0x4e 1340s testing.tRunner(0xc0001c1a40, 0xc00000f080) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 7 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 273 [IO wait]: 1340s internal/poll.runtime_pollWait(0x3ff8457a200, 0x72) 1340s /usr/lib/go-1.25/src/runtime/netpoll.go:351 +0xfe 1340s internal/poll.(*pollDesc).wait(0xc0001f3100, 0x72, 0x1) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:84 +0x42 1340s internal/poll.(*pollDesc).waitRead(...) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:89 1340s internal/poll.(*FD).Read(0xc0001f30e0, {0xc0000cf800, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/internal/poll/fd_unix.go:165 +0x27a 1340s os.(*File).read(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:29 1340s os.(*File).Read(0xc0000b84b0, {0xc0000cf800, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/os/file.go:144 +0x98 1340s bytes.(*Buffer).ReadFrom(0xc000482f60, {0x8ae820, 0xc00049a228}) 1340s /usr/lib/go-1.25/src/bytes/buffer.go:217 +0xba 1340s io.copyBuffer({0x8ae9e0, 0xc000482f60}, {0x8ae820, 0xc00049a228}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:415 +0x1ce 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os.genericWriteTo(0xc0000b84b0, {0x8ae9e0, 0xc000482f60}) 1340s /usr/lib/go-1.25/src/os/file.go:295 +0x76 1340s os.(*File).WriteTo(0xc0000b84b0, {0x8ae9e0, 0xc000482f60}) 1340s /usr/lib/go-1.25/src/os/file.go:273 +0xfc 1340s io.copyBuffer({0x8ae9e0, 0xc000482f60}, {0x8ae8a0, 0xc0000b84b0}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:411 +0xc2 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os/exec.(*Cmd).writerDescriptor.func1() 1340s /usr/lib/go-1.25/src/os/exec/exec.go:596 +0x5c 1340s os/exec.(*Cmd).Start.func2(0xc000435020) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:749 +0x4c 1340s created by os/exec.(*Cmd).Start in goroutine 106 1340s /usr/lib/go-1.25/src/os/exec/exec.go:748 +0xa6a 1340s 1340s goroutine 275 [IO wait]: 1340s internal/poll.runtime_pollWait(0x3ff84579c00, 0x72) 1340s /usr/lib/go-1.25/src/runtime/netpoll.go:351 +0xfe 1340s internal/poll.(*pollDesc).wait(0xc0001f39a0, 0x72, 0x1) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:84 +0x42 1340s internal/poll.(*pollDesc).waitRead(...) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:89 1340s internal/poll.(*FD).Read(0xc0001f3980, {0xc0000cfc00, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/internal/poll/fd_unix.go:165 +0x27a 1340s os.(*File).read(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:29 1340s os.(*File).Read(0xc0000b85a8, {0xc0000cfc00, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/os/file.go:144 +0x98 1340s bytes.(*Buffer).ReadFrom(0xc0004834a0, {0x8ae820, 0xc00049a238}) 1340s /usr/lib/go-1.25/src/bytes/buffer.go:217 +0xba 1340s io.copyBuffer({0x8ae9e0, 0xc0004834a0}, {0x8ae820, 0xc00049a238}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:415 +0x1ce 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os.genericWriteTo(0xc0000b85a8, {0x8ae9e0, 0xc0004834a0}) 1340s /usr/lib/go-1.25/src/os/file.go:295 +0x76 1340s os.(*File).WriteTo(0xc0000b85a8, {0x8ae9e0, 0xc0004834a0}) 1340s /usr/lib/go-1.25/src/os/file.go:273 +0xfc 1340s io.copyBuffer({0x8ae9e0, 0xc0004834a0}, {0x8ae8a0, 0xc0000b85a8}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:411 +0xc2 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os/exec.(*Cmd).writerDescriptor.func1() 1340s /usr/lib/go-1.25/src/os/exec/exec.go:596 +0x5c 1340s os/exec.(*Cmd).Start.func2(0xc000435360) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:749 +0x4c 1340s created by os/exec.(*Cmd).Start in goroutine 105 1340s /usr/lib/go-1.25/src/os/exec/exec.go:748 +0xa6a 1340s 1340s goroutine 103 [chan receive, 2 minutes]: 1340s testing.(*testState).waitParallel(0xc000021090) 1340s /usr/lib/go-1.25/src/testing/testing.go:2116 +0x128 1340s testing.(*T).Parallel(0xc0002436c0) 1340s /usr/lib/go-1.25/src/testing/testing.go:1709 +0x2d4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestInfo.func1(0xc0002436c0) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:88 +0x3c 1340s testing.tRunner(0xc0002436c0, 0xc0000a89f0) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 8 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 104 [chan receive, 2 minutes]: 1340s testing.(*testState).waitParallel(0xc000021090) 1340s /usr/lib/go-1.25/src/testing/testing.go:2116 +0x128 1340s testing.(*T).Parallel(0xc000243a40) 1340s /usr/lib/go-1.25/src/testing/testing.go:1709 +0x2d4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestInfo.func1(0xc000243a40) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:88 +0x3c 1340s testing.tRunner(0xc000243a40, 0xc0000a8a80) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 8 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 105 [syscall]: 1340s syscall.Syscall6(0x119, 0x3, 0x10, 0xc000246ae0, 0x4, 0xc0001baf30, 0x0) 1340s /usr/lib/go-1.25/src/syscall/syscall_linux.go:96 +0x18 1340s internal/syscall/unix.Waitid(0x3, 0x10, 0xc000246ae0, 0x4, 0xc0001baf30) 1340s /usr/lib/go-1.25/src/internal/syscall/unix/waitid_linux.go:18 +0x6c 1340s os.(*Process).pidfdWait.func1(...) 1340s /usr/lib/go-1.25/src/os/pidfd_linux.go:109 1340s os.ignoringEINTR(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:256 1340s os.(*Process).pidfdWait(0xc0000c4500) 1340s /usr/lib/go-1.25/src/os/pidfd_linux.go:108 +0x178 1340s os.(*Process).wait(0xc0000c4500) 1340s /usr/lib/go-1.25/src/os/exec_unix.go:25 +0x3c 1340s os.(*Process).Wait(...) 1340s /usr/lib/go-1.25/src/os/exec.go:340 1340s os/exec.(*Cmd).Wait(0xc0001a9380) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:922 +0x4a 1340s os/exec.(*Cmd).Run(0xc0001a9380) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:626 +0x66 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.runCommand(0xc0001a9380) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system.go:226 +0x1b6 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.System.ProStatus({{0x8b6fd0, 0xc0001f3800}, {0x0, 0x0}, {0x0, 0x0}}, {0x8b3de8, 0xce4040}) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/pro.go:16 +0xe4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.System.Info({{0x8b6fd0, 0xc0001f3800}, {0x0, 0x0}, {0x0, 0x0}}, {0x8b3de8, 0xce4040}) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system.go:88 +0x8a 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestInfo.func1(0xc000243dc0) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:124 +0x87c 1340s testing.tRunner(0xc000243dc0, 0xc0000a8ae0) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 8 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 106 [syscall]: 1340s syscall.Syscall6(0x119, 0x3, 0xf, 0xc000247ae0, 0x4, 0xc0001bae10, 0x0) 1340s /usr/lib/go-1.25/src/syscall/syscall_linux.go:96 +0x18 1340s internal/syscall/unix.Waitid(0x3, 0xf, 0xc000247ae0, 0x4, 0xc0001bae10) 1340s /usr/lib/go-1.25/src/internal/syscall/unix/waitid_linux.go:18 +0x6c 1340s os.(*Process).pidfdWait.func1(...) 1340s /usr/lib/go-1.25/src/os/pidfd_linux.go:109 1340s os.ignoringEINTR(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:256 1340s os.(*Process).pidfdWait(0xc0000c4440) 1340s /usr/lib/go-1.25/src/os/pidfd_linux.go:108 +0x178 1340s os.(*Process).wait(0xc0000c4440) 1340s /usr/lib/go-1.25/src/os/exec_unix.go:25 +0x3c 1340s os.(*Process).Wait(...) 1340s /usr/lib/go-1.25/src/os/exec.go:340 1340s os/exec.(*Cmd).Wait(0xc0001a9200) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:922 +0x4a 1340s os/exec.(*Cmd).Run(0xc0001a9200) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:626 +0x66 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.runCommand(0xc0001a9200) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system.go:226 +0x1b6 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.System.ProStatus({{0x8b6fd0, 0xc0001f2f00}, {0x0, 0x0}, {0x0, 0x0}}, {0x8b3de8, 0xce4040}) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/pro.go:16 +0xe4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system.System.Info({{0x8b6fd0, 0xc0001f2f00}, {0x0, 0x0}, {0x0, 0x0}}, {0x8b3de8, 0xce4040}) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system.go:88 +0x8a 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestInfo.func1(0xc00024e1c0) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:124 +0x87c 1340s testing.tRunner(0xc00024e1c0, 0xc0000a8b40) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 8 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s 1340s goroutine 274 [IO wait]: 1340s internal/poll.runtime_pollWait(0x3ff8457a400, 0x72) 1340s /usr/lib/go-1.25/src/runtime/netpoll.go:351 +0xfe 1340s internal/poll.(*pollDesc).wait(0xc0001f38e0, 0x72, 0x1) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:84 +0x42 1340s internal/poll.(*pollDesc).waitRead(...) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:89 1340s internal/poll.(*FD).Read(0xc0001f38c0, {0xc0000cfa00, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/internal/poll/fd_unix.go:165 +0x27a 1340s os.(*File).read(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:29 1340s os.(*File).Read(0xc0000b8590, {0xc0000cfa00, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/os/file.go:144 +0x98 1340s bytes.(*Buffer).ReadFrom(0xc000483470, {0x8ae820, 0xc00049a230}) 1340s /usr/lib/go-1.25/src/bytes/buffer.go:217 +0xba 1340s io.copyBuffer({0x8ae9e0, 0xc000483470}, {0x8ae820, 0xc00049a230}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:415 +0x1ce 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os.genericWriteTo(0xc0000b8590, {0x8ae9e0, 0xc000483470}) 1340s /usr/lib/go-1.25/src/os/file.go:295 +0x76 1340s os.(*File).WriteTo(0xc0000b8590, {0x8ae9e0, 0xc000483470}) 1340s /usr/lib/go-1.25/src/os/file.go:273 +0xfc 1340s io.copyBuffer({0x8ae9e0, 0xc000483470}, {0x8ae8a0, 0xc0000b8590}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:411 +0xc2 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os/exec.(*Cmd).writerDescriptor.func1() 1340s /usr/lib/go-1.25/src/os/exec/exec.go:596 +0x5c 1340s os/exec.(*Cmd).Start.func2(0xc000435320) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:749 +0x4c 1340s created by os/exec.(*Cmd).Start in goroutine 105 1340s /usr/lib/go-1.25/src/os/exec/exec.go:748 +0xa6a 1340s 1340s goroutine 272 [IO wait]: 1340s internal/poll.runtime_pollWait(0x3ff8457a000, 0x72) 1340s /usr/lib/go-1.25/src/runtime/netpoll.go:351 +0xfe 1340s internal/poll.(*pollDesc).wait(0xc0001f3040, 0x72, 0x1) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:84 +0x42 1340s internal/poll.(*pollDesc).waitRead(...) 1340s /usr/lib/go-1.25/src/internal/poll/fd_poll_runtime.go:89 1340s internal/poll.(*FD).Read(0xc0001f3020, {0xc0000cf200, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/internal/poll/fd_unix.go:165 +0x27a 1340s os.(*File).read(...) 1340s /usr/lib/go-1.25/src/os/file_posix.go:29 1340s os.(*File).Read(0xc0000b8498, {0xc0000cf200, 0x200, 0x200}) 1340s /usr/lib/go-1.25/src/os/file.go:144 +0x98 1340s bytes.(*Buffer).ReadFrom(0xc000482f30, {0x8ae820, 0xc00049a220}) 1340s /usr/lib/go-1.25/src/bytes/buffer.go:217 +0xba 1340s io.copyBuffer({0x8ae9e0, 0xc000482f30}, {0x8ae820, 0xc00049a220}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:415 +0x1ce 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os.genericWriteTo(0xc0000b8498, {0x8ae9e0, 0xc000482f30}) 1340s /usr/lib/go-1.25/src/os/file.go:295 +0x76 1340s os.(*File).WriteTo(0xc0000b8498, {0x8ae9e0, 0xc000482f30}) 1340s /usr/lib/go-1.25/src/os/file.go:273 +0xfc 1340s io.copyBuffer({0x8ae9e0, 0xc000482f30}, {0x8ae8a0, 0xc0000b8498}, {0x0, 0x0, 0x0}) 1340s /usr/lib/go-1.25/src/io/io.go:411 +0xc2 1340s io.Copy(...) 1340s /usr/lib/go-1.25/src/io/io.go:388 1340s os/exec.(*Cmd).writerDescriptor.func1() 1340s /usr/lib/go-1.25/src/os/exec/exec.go:596 +0x5c 1340s os/exec.(*Cmd).Start.func2(0xc000434fe0) 1340s /usr/lib/go-1.25/src/os/exec/exec.go:749 +0x4c 1340s created by os/exec.(*Cmd).Start in goroutine 106 1340s /usr/lib/go-1.25/src/os/exec/exec.go:748 +0xa6a 1340s 1340s goroutine 26 [chan receive, 2 minutes]: 1340s testing.(*testState).waitParallel(0xc000021090) 1340s /usr/lib/go-1.25/src/testing/testing.go:2116 +0x128 1340s testing.(*T).Parallel(0xc0001c1c00) 1340s /usr/lib/go-1.25/src/testing/testing.go:1709 +0x2d4 1340s github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system_test.TestNew.func1(0xc0001c1c00) 1340s /tmp/autopkgtest.Gg6QYb/build.noM/src/internal/system/system_test.go:38 +0x4e 1340s testing.tRunner(0xc0001c1c00, 0xc00000f0c8) 1340s /usr/lib/go-1.25/src/testing/testing.go:1934 +0x12e 1340s created by testing.(*T).Run in goroutine 7 1340s /usr/lib/go-1.25/src/testing/testing.go:1997 +0x548 1340s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 600.016s 1340s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 1340s FAIL 1342s autopkgtest [08:30:22]: test command1: -----------------------] 1345s autopkgtest [08:30:25]: test command1: - - - - - - - - - - results - - - - - - - - - - 1345s command1 FAIL non-zero exit status 1 1347s autopkgtest [08:30:27]: @@@@@@@@@@@@@@@@@@@@ summary 1347s command1 FAIL non-zero exit status 1