0s autopkgtest [22:47:02]: starting date and time: 2024-05-28 22:47:02+0000 0s autopkgtest [22:47:02]: git checkout: d60bd36 autopkgtest-build-lxd: Add missing remote prefix in get_boot_id(). 0s autopkgtest [22:47:02]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.klyp9q9q/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:ubuntu-advantage-tools --apt-upgrade wsl-pro-service --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=ubuntu-advantage-tools/32.3~24.04' -- lxd -r lxd-armhf-10.145.243.70 lxd-armhf-10.145.243.70:autopkgtest/ubuntu/noble/armhf 30s autopkgtest [22:47:32]: testbed dpkg architecture: armhf 32s autopkgtest [22:47:34]: testbed apt version: 2.7.14build2 32s autopkgtest [22:47:34]: @@@@@@@@@@@@@@@@@@@@ test bed setup 40s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [256 kB] 41s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [15.4 kB] 41s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [7672 B] 41s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2080 B] 41s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [37.0 kB] 41s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main armhf Packages [75.3 kB] 41s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main armhf c-n-f Metadata [2492 B] 41s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf c-n-f Metadata [116 B] 41s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf Packages [63.2 kB] 41s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf c-n-f Metadata [7776 B] 41s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf c-n-f Metadata [116 B] 43s Fetched 467 kB in 1s (511 kB/s) 43s Reading package lists... 59s tee: /proc/self/fd/2: Permission denied 82s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 82s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 82s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 82s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 85s Reading package lists... 85s Reading package lists... 85s Building dependency tree... 85s Reading state information... 86s Calculating upgrade... 86s The following packages will be upgraded: 86s ubuntu-pro-client ubuntu-pro-client-l10n 86s 2 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 86s Need to get 250 kB of archives. 86s After this operation, 99.3 kB of additional disk space will be used. 86s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main armhf ubuntu-pro-client-l10n armhf 32.3~24.04 [19.4 kB] 87s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main armhf ubuntu-pro-client armhf 32.3~24.04 [231 kB] 88s Fetched 250 kB in 0s (546 kB/s) 88s (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 ... 57874 files and directories currently installed.) 88s Preparing to unpack .../ubuntu-pro-client-l10n_32.3~24.04_armhf.deb ... 88s Unpacking ubuntu-pro-client-l10n (32.3~24.04) over (31.2.3) ... 88s Preparing to unpack .../ubuntu-pro-client_32.3~24.04_armhf.deb ... 89s Unpacking ubuntu-pro-client (32.3~24.04) over (31.2.3) ... 89s Setting up ubuntu-pro-client (32.3~24.04) ... 89s Installing new version of config file /etc/apparmor.d/ubuntu_pro_apt_news ... 89s apparmor_parser: Unable to replace "ubuntu_pro_apt_news". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 89s 90s apparmor_parser: Unable to replace "apt_methods". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 90s 90s apparmor_parser: Unable to replace "ubuntu_pro_esm_cache". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 90s 95s Setting up ubuntu-pro-client-l10n (32.3~24.04) ... 95s Processing triggers for man-db (2.12.0-4build2) ... 96s Reading package lists... 97s Building dependency tree... 97s Reading state information... 98s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 100s autopkgtest [22:48:42]: rebooting testbed after setup commands that affected boot 167s autopkgtest [22:49:49]: testbed running kernel: Linux 6.5.0-35-generic #35~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Tue May 7 11:19:33 UTC 2 198s autopkgtest [22:50:20]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 220s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 220s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 222s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 222s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 222s gpgv: Can't check signature: No public key 222s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 225s autopkgtest [22:50:47]: testing package wsl-pro-service version 0.1.4 227s autopkgtest [22:50:49]: build not needed 230s autopkgtest [22:50:52]: test command1: preparing testbed 241s Reading package lists... 241s Building dependency tree... 241s Reading state information... 241s Starting pkgProblemResolver with broken count: 0 241s Starting 2 pkgProblemResolver with broken count: 0 241s Done 242s The following additional packages will be installed: 242s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 242s cpp-13-arm-linux-gnueabihf cpp-arm-linux-gnueabihf debhelper debugedit 242s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 242s g++-13-arm-linux-gnueabihf g++-arm-linux-gnueabihf gcc gcc-13 242s gcc-13-arm-linux-gnueabihf gcc-13-base gcc-arm-linux-gnueabihf gettext 242s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 242s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 242s libcrypt-dev libdebhelper-perl libdw1t64 libfile-stripnondeterminism-perl 242s libgcc-13-dev libgomp1 libisl23 libmpc3 libstdc++-13-dev 242s libsub-override-perl libtool libubsan1 linux-libc-dev m4 po-debconf 242s rpcsvc-proto 242s Suggested packages: 242s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 242s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 242s gcc-doc gdb-arm-linux-gnueabihf gettext-doc libasprintf-dev libgettextpo-dev 242s bzr | brz git mercurial subversion glibc-doc libstdc++-13-doc libtool-doc 242s gfortran | fortran95-compiler gcj-jdk m4-doc libmail-box-perl 242s Recommended packages: 242s pkg-config manpages manpages-dev libc-devtools libarchive-cpio-perl 242s libltdl-dev libmail-sendmail-perl 242s The following NEW packages will be installed: 242s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 242s cpp cpp-13 cpp-13-arm-linux-gnueabihf cpp-arm-linux-gnueabihf debhelper 242s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 242s g++-13 g++-13-arm-linux-gnueabihf g++-arm-linux-gnueabihf gcc gcc-13 242s gcc-13-arm-linux-gnueabihf gcc-13-base gcc-arm-linux-gnueabihf gettext 242s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 242s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 242s libcrypt-dev libdebhelper-perl libdw1t64 libfile-stripnondeterminism-perl 242s libgcc-13-dev libgomp1 libisl23 libmpc3 libstdc++-13-dev 242s libsub-override-perl libtool libubsan1 linux-libc-dev m4 po-debconf 242s rpcsvc-proto 242s 0 upgraded, 54 newly installed, 0 to remove and 0 not upgraded. 242s Need to get 95.3 MB/95.3 MB of archives. 242s After this operation, 377 MB of additional disk space will be used. 242s Get:1 /tmp/autopkgtest.7bZ5VP/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [760 B] 242s Get:2 http://ftpmaster.internal/ubuntu noble/main armhf m4 armhf 1.4.19-4build1 [235 kB] 243s Get:3 http://ftpmaster.internal/ubuntu noble/main armhf autoconf all 2.71-3 [339 kB] 243s Get:4 http://ftpmaster.internal/ubuntu noble/main armhf autotools-dev all 20220109.1 [44.9 kB] 243s Get:5 http://ftpmaster.internal/ubuntu noble/main armhf automake all 1:1.16.5-1.3ubuntu1 [558 kB] 243s Get:6 http://ftpmaster.internal/ubuntu noble/main armhf autopoint all 0.21-14ubuntu2 [422 kB] 243s Get:7 http://ftpmaster.internal/ubuntu noble-updates/main armhf libc-dev-bin armhf 2.39-0ubuntu8.1 [19.1 kB] 243s Get:8 http://ftpmaster.internal/ubuntu noble/main armhf linux-libc-dev armhf 6.8.0-31.31 [1557 kB] 243s Get:9 http://ftpmaster.internal/ubuntu noble/main armhf libcrypt-dev armhf 1:4.4.36-4build1 [120 kB] 243s Get:10 http://ftpmaster.internal/ubuntu noble/main armhf rpcsvc-proto armhf 1.4.2-0ubuntu7 [62.2 kB] 243s Get:11 http://ftpmaster.internal/ubuntu noble-updates/main armhf libc6-dev armhf 2.39-0ubuntu8.1 [1351 kB] 243s Get:12 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13-base armhf 13.2.0-23ubuntu4 [48.9 kB] 243s Get:13 http://ftpmaster.internal/ubuntu noble/main armhf libisl23 armhf 0.26-3build1 [544 kB] 243s Get:14 http://ftpmaster.internal/ubuntu noble/main armhf libmpc3 armhf 1.3.1-1build1 [46.7 kB] 243s Get:15 http://ftpmaster.internal/ubuntu noble/main armhf cpp-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [8759 kB] 243s Get:16 http://ftpmaster.internal/ubuntu noble/main armhf cpp-13 armhf 13.2.0-23ubuntu4 [1034 B] 243s Get:17 http://ftpmaster.internal/ubuntu noble/main armhf cpp-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [5320 B] 243s Get:18 http://ftpmaster.internal/ubuntu noble/main armhf cpp armhf 4:13.2.0-7ubuntu1 [22.4 kB] 243s Get:19 http://ftpmaster.internal/ubuntu noble/main armhf libcc1-0 armhf 14-20240412-0ubuntu1 [39.0 kB] 243s Get:20 http://ftpmaster.internal/ubuntu noble/main armhf libgomp1 armhf 14-20240412-0ubuntu1 [125 kB] 243s Get:21 http://ftpmaster.internal/ubuntu noble/main armhf libatomic1 armhf 14-20240412-0ubuntu1 [7816 B] 243s Get:22 http://ftpmaster.internal/ubuntu noble/main armhf libasan8 armhf 14-20240412-0ubuntu1 [2942 kB] 243s Get:23 http://ftpmaster.internal/ubuntu noble/main armhf libubsan1 armhf 14-20240412-0ubuntu1 [1154 kB] 243s Get:24 http://ftpmaster.internal/ubuntu noble/main armhf libgcc-13-dev armhf 13.2.0-23ubuntu4 [899 kB] 243s Get:25 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [16.9 MB] 244s Get:26 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13 armhf 13.2.0-23ubuntu4 [453 kB] 244s Get:27 http://ftpmaster.internal/ubuntu noble/main armhf gcc-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [1220 B] 244s Get:28 http://ftpmaster.internal/ubuntu noble/main armhf gcc armhf 4:13.2.0-7ubuntu1 [5022 B] 244s Get:29 http://ftpmaster.internal/ubuntu noble/main armhf libstdc++-13-dev armhf 13.2.0-23ubuntu4 [2456 kB] 244s Get:30 http://ftpmaster.internal/ubuntu noble/main armhf g++-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [9941 kB] 244s Get:31 http://ftpmaster.internal/ubuntu noble/main armhf g++-13 armhf 13.2.0-23ubuntu4 [14.5 kB] 244s Get:32 http://ftpmaster.internal/ubuntu noble/main armhf g++-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [966 B] 244s Get:33 http://ftpmaster.internal/ubuntu noble/main armhf g++ armhf 4:13.2.0-7ubuntu1 [1090 B] 244s Get:34 http://ftpmaster.internal/ubuntu noble/main armhf build-essential armhf 12.10ubuntu1 [4928 B] 244s Get:35 http://ftpmaster.internal/ubuntu noble/main armhf libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 244s Get:36 http://ftpmaster.internal/ubuntu noble/main armhf libtool all 2.4.7-7build1 [166 kB] 244s Get:37 http://ftpmaster.internal/ubuntu noble/main armhf dh-autoreconf all 20 [16.1 kB] 244s Get:38 http://ftpmaster.internal/ubuntu noble/main armhf libarchive-zip-perl all 1.68-1 [90.2 kB] 244s Get:39 http://ftpmaster.internal/ubuntu noble/main armhf libsub-override-perl all 0.10-1 [10.0 kB] 244s Get:40 http://ftpmaster.internal/ubuntu noble/main armhf libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 244s Get:41 http://ftpmaster.internal/ubuntu noble/main armhf dh-strip-nondeterminism all 1.13.1-1 [5362 B] 244s Get:42 http://ftpmaster.internal/ubuntu noble/main armhf libdw1t64 armhf 0.190-1.1build4 [235 kB] 244s Get:43 http://ftpmaster.internal/ubuntu noble/main armhf debugedit armhf 1:5.0-5build2 [42.3 kB] 244s Get:44 http://ftpmaster.internal/ubuntu noble/main armhf dwz armhf 0.15-1build6 [116 kB] 244s Get:45 http://ftpmaster.internal/ubuntu noble/main armhf gettext armhf 0.21-14ubuntu2 [800 kB] 244s Get:46 http://ftpmaster.internal/ubuntu noble/main armhf intltool-debian all 0.35.0+20060710.6 [23.2 kB] 244s Get:47 http://ftpmaster.internal/ubuntu noble/main armhf po-debconf all 1.0.21+nmu1 [233 kB] 244s Get:48 http://ftpmaster.internal/ubuntu noble/main armhf debhelper all 13.14.1ubuntu5 [869 kB] 244s Get:49 http://ftpmaster.internal/ubuntu noble-updates/universe armhf dh-apport all 2.28.1-0ubuntu3 [17.2 kB] 244s Get:50 http://ftpmaster.internal/ubuntu noble/main armhf golang-1.22-src all 1.22.2-2 [19.7 MB] 245s Get:51 http://ftpmaster.internal/ubuntu noble/main armhf golang-1.22-go armhf 1.22.2-2 [23.7 MB] 245s Get:52 http://ftpmaster.internal/ubuntu noble/main armhf golang-src all 2:1.22~2build1 [5078 B] 245s Get:53 http://ftpmaster.internal/ubuntu noble/main armhf golang-go armhf 2:1.22~2build1 [43.9 kB] 245s Get:54 http://ftpmaster.internal/ubuntu noble/main armhf dh-golang all 1.62 [25.2 kB] 255s Fetched 95.3 MB in 3s (28.0 MB/s) 255s Selecting previously unselected package m4. 256s (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 ... 57901 files and directories currently installed.) 256s Preparing to unpack .../00-m4_1.4.19-4build1_armhf.deb ... 256s Unpacking m4 (1.4.19-4build1) ... 256s Selecting previously unselected package autoconf. 258s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 258s Unpacking autoconf (2.71-3) ... 259s Selecting previously unselected package autotools-dev. 261s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 261s Unpacking autotools-dev (20220109.1) ... 261s Selecting previously unselected package automake. 263s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 263s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 263s Selecting previously unselected package autopoint. 267s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 267s Unpacking autopoint (0.21-14ubuntu2) ... 267s Selecting previously unselected package libc-dev-bin. 269s Preparing to unpack .../05-libc-dev-bin_2.39-0ubuntu8.1_armhf.deb ... 269s Unpacking libc-dev-bin (2.39-0ubuntu8.1) ... 271s Selecting previously unselected package linux-libc-dev:armhf. 272s Preparing to unpack .../06-linux-libc-dev_6.8.0-31.31_armhf.deb ... 272s Unpacking linux-libc-dev:armhf (6.8.0-31.31) ... 273s Selecting previously unselected package libcrypt-dev:armhf. 274s Preparing to unpack .../07-libcrypt-dev_1%3a4.4.36-4build1_armhf.deb ... 274s Unpacking libcrypt-dev:armhf (1:4.4.36-4build1) ... 275s Selecting previously unselected package rpcsvc-proto. 275s Preparing to unpack .../08-rpcsvc-proto_1.4.2-0ubuntu7_armhf.deb ... 275s Unpacking rpcsvc-proto (1.4.2-0ubuntu7) ... 275s Selecting previously unselected package libc6-dev:armhf. 276s Preparing to unpack .../09-libc6-dev_2.39-0ubuntu8.1_armhf.deb ... 276s Unpacking libc6-dev:armhf (2.39-0ubuntu8.1) ... 276s Selecting previously unselected package gcc-13-base:armhf. 276s Preparing to unpack .../10-gcc-13-base_13.2.0-23ubuntu4_armhf.deb ... 276s Unpacking gcc-13-base:armhf (13.2.0-23ubuntu4) ... 277s Selecting previously unselected package libisl23:armhf. 277s Preparing to unpack .../11-libisl23_0.26-3build1_armhf.deb ... 277s Unpacking libisl23:armhf (0.26-3build1) ... 277s Selecting previously unselected package libmpc3:armhf. 278s Preparing to unpack .../12-libmpc3_1.3.1-1build1_armhf.deb ... 278s Unpacking libmpc3:armhf (1.3.1-1build1) ... 278s Selecting previously unselected package cpp-13-arm-linux-gnueabihf. 278s Preparing to unpack .../13-cpp-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 278s Unpacking cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 278s Selecting previously unselected package cpp-13. 278s Preparing to unpack .../14-cpp-13_13.2.0-23ubuntu4_armhf.deb ... 278s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 278s Selecting previously unselected package cpp-arm-linux-gnueabihf. 278s Preparing to unpack .../15-cpp-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 278s Unpacking cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 278s Selecting previously unselected package cpp. 279s Preparing to unpack .../16-cpp_4%3a13.2.0-7ubuntu1_armhf.deb ... 279s Unpacking cpp (4:13.2.0-7ubuntu1) ... 279s Selecting previously unselected package libcc1-0:armhf. 279s Preparing to unpack .../17-libcc1-0_14-20240412-0ubuntu1_armhf.deb ... 279s Unpacking libcc1-0:armhf (14-20240412-0ubuntu1) ... 279s Selecting previously unselected package libgomp1:armhf. 279s Preparing to unpack .../18-libgomp1_14-20240412-0ubuntu1_armhf.deb ... 279s Unpacking libgomp1:armhf (14-20240412-0ubuntu1) ... 279s Selecting previously unselected package libatomic1:armhf. 279s Preparing to unpack .../19-libatomic1_14-20240412-0ubuntu1_armhf.deb ... 279s Unpacking libatomic1:armhf (14-20240412-0ubuntu1) ... 279s Selecting previously unselected package libasan8:armhf. 279s Preparing to unpack .../20-libasan8_14-20240412-0ubuntu1_armhf.deb ... 279s Unpacking libasan8:armhf (14-20240412-0ubuntu1) ... 280s Selecting previously unselected package libubsan1:armhf. 280s Preparing to unpack .../21-libubsan1_14-20240412-0ubuntu1_armhf.deb ... 280s Unpacking libubsan1:armhf (14-20240412-0ubuntu1) ... 280s Selecting previously unselected package libgcc-13-dev:armhf. 280s Preparing to unpack .../22-libgcc-13-dev_13.2.0-23ubuntu4_armhf.deb ... 280s Unpacking libgcc-13-dev:armhf (13.2.0-23ubuntu4) ... 280s Selecting previously unselected package gcc-13-arm-linux-gnueabihf. 280s Preparing to unpack .../23-gcc-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 280s Unpacking gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 281s Selecting previously unselected package gcc-13. 281s Preparing to unpack .../24-gcc-13_13.2.0-23ubuntu4_armhf.deb ... 281s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 281s Selecting previously unselected package gcc-arm-linux-gnueabihf. 281s Preparing to unpack .../25-gcc-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 281s Unpacking gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 281s Selecting previously unselected package gcc. 281s Preparing to unpack .../26-gcc_4%3a13.2.0-7ubuntu1_armhf.deb ... 281s Unpacking gcc (4:13.2.0-7ubuntu1) ... 281s Selecting previously unselected package libstdc++-13-dev:armhf. 281s Preparing to unpack .../27-libstdc++-13-dev_13.2.0-23ubuntu4_armhf.deb ... 281s Unpacking libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ... 281s Selecting previously unselected package g++-13-arm-linux-gnueabihf. 281s Preparing to unpack .../28-g++-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 281s Unpacking g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 281s Selecting previously unselected package g++-13. 281s Preparing to unpack .../29-g++-13_13.2.0-23ubuntu4_armhf.deb ... 281s Unpacking g++-13 (13.2.0-23ubuntu4) ... 281s Selecting previously unselected package g++-arm-linux-gnueabihf. 282s Preparing to unpack .../30-g++-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 282s Unpacking g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 282s Selecting previously unselected package g++. 282s Preparing to unpack .../31-g++_4%3a13.2.0-7ubuntu1_armhf.deb ... 282s Unpacking g++ (4:13.2.0-7ubuntu1) ... 282s Selecting previously unselected package build-essential. 282s Preparing to unpack .../32-build-essential_12.10ubuntu1_armhf.deb ... 282s Unpacking build-essential (12.10ubuntu1) ... 282s Selecting previously unselected package libdebhelper-perl. 282s Preparing to unpack .../33-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 282s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 282s Selecting previously unselected package libtool. 282s Preparing to unpack .../34-libtool_2.4.7-7build1_all.deb ... 282s Unpacking libtool (2.4.7-7build1) ... 282s Selecting previously unselected package dh-autoreconf. 282s Preparing to unpack .../35-dh-autoreconf_20_all.deb ... 282s Unpacking dh-autoreconf (20) ... 282s Selecting previously unselected package libarchive-zip-perl. 282s Preparing to unpack .../36-libarchive-zip-perl_1.68-1_all.deb ... 282s Unpacking libarchive-zip-perl (1.68-1) ... 282s Selecting previously unselected package libsub-override-perl. 282s Preparing to unpack .../37-libsub-override-perl_0.10-1_all.deb ... 282s Unpacking libsub-override-perl (0.10-1) ... 282s Selecting previously unselected package libfile-stripnondeterminism-perl. 282s Preparing to unpack .../38-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 282s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 282s Selecting previously unselected package dh-strip-nondeterminism. 283s Preparing to unpack .../39-dh-strip-nondeterminism_1.13.1-1_all.deb ... 283s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 283s Selecting previously unselected package libdw1t64:armhf. 283s Preparing to unpack .../40-libdw1t64_0.190-1.1build4_armhf.deb ... 283s Unpacking libdw1t64:armhf (0.190-1.1build4) ... 283s Selecting previously unselected package debugedit. 283s Preparing to unpack .../41-debugedit_1%3a5.0-5build2_armhf.deb ... 283s Unpacking debugedit (1:5.0-5build2) ... 283s Selecting previously unselected package dwz. 284s Preparing to unpack .../42-dwz_0.15-1build6_armhf.deb ... 284s Unpacking dwz (0.15-1build6) ... 284s Selecting previously unselected package gettext. 284s Preparing to unpack .../43-gettext_0.21-14ubuntu2_armhf.deb ... 284s Unpacking gettext (0.21-14ubuntu2) ... 284s Selecting previously unselected package intltool-debian. 284s Preparing to unpack .../44-intltool-debian_0.35.0+20060710.6_all.deb ... 284s Unpacking intltool-debian (0.35.0+20060710.6) ... 284s Selecting previously unselected package po-debconf. 284s Preparing to unpack .../45-po-debconf_1.0.21+nmu1_all.deb ... 284s Unpacking po-debconf (1.0.21+nmu1) ... 284s Selecting previously unselected package debhelper. 284s Preparing to unpack .../46-debhelper_13.14.1ubuntu5_all.deb ... 284s Unpacking debhelper (13.14.1ubuntu5) ... 284s Selecting previously unselected package dh-apport. 284s Preparing to unpack .../47-dh-apport_2.28.1-0ubuntu3_all.deb ... 284s Unpacking dh-apport (2.28.1-0ubuntu3) ... 284s Selecting previously unselected package golang-1.22-src. 284s Preparing to unpack .../48-golang-1.22-src_1.22.2-2_all.deb ... 284s Unpacking golang-1.22-src (1.22.2-2) ... 289s Selecting previously unselected package golang-1.22-go. 290s Preparing to unpack .../49-golang-1.22-go_1.22.2-2_armhf.deb ... 290s Unpacking golang-1.22-go (1.22.2-2) ... 291s Selecting previously unselected package golang-src. 291s Preparing to unpack .../50-golang-src_2%3a1.22~2build1_all.deb ... 291s Unpacking golang-src (2:1.22~2build1) ... 291s Selecting previously unselected package golang-go:armhf. 292s Preparing to unpack .../51-golang-go_2%3a1.22~2build1_armhf.deb ... 292s Unpacking golang-go:armhf (2:1.22~2build1) ... 292s Selecting previously unselected package dh-golang. 292s Preparing to unpack .../52-dh-golang_1.62_all.deb ... 292s Unpacking dh-golang (1.62) ... 292s Selecting previously unselected package autopkgtest-satdep. 292s Preparing to unpack .../53-1-autopkgtest-satdep.deb ... 292s Unpacking autopkgtest-satdep (0) ... 292s Setting up libarchive-zip-perl (1.68-1) ... 292s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 292s Setting up linux-libc-dev:armhf (6.8.0-31.31) ... 292s Setting up m4 (1.4.19-4build1) ... 292s Setting up libgomp1:armhf (14-20240412-0ubuntu1) ... 292s Setting up dh-apport (2.28.1-0ubuntu3) ... 292s Setting up libdw1t64:armhf (0.190-1.1build4) ... 292s Setting up autotools-dev (20220109.1) ... 292s Setting up rpcsvc-proto (1.4.2-0ubuntu7) ... 292s Setting up gcc-13-base:armhf (13.2.0-23ubuntu4) ... 292s Setting up golang-1.22-src (1.22.2-2) ... 292s Setting up libmpc3:armhf (1.3.1-1build1) ... 292s Setting up libatomic1:armhf (14-20240412-0ubuntu1) ... 292s Setting up autopoint (0.21-14ubuntu2) ... 292s Setting up autoconf (2.71-3) ... 292s Setting up libubsan1:armhf (14-20240412-0ubuntu1) ... 292s Setting up dwz (0.15-1build6) ... 292s Setting up libcrypt-dev:armhf (1:4.4.36-4build1) ... 292s Setting up libasan8:armhf (14-20240412-0ubuntu1) ... 292s Setting up debugedit (1:5.0-5build2) ... 292s Setting up libsub-override-perl (0.10-1) ... 292s Setting up libisl23:armhf (0.26-3build1) ... 292s Setting up libc-dev-bin (2.39-0ubuntu8.1) ... 292s Setting up golang-src (2:1.22~2build1) ... 292s Setting up libcc1-0:armhf (14-20240412-0ubuntu1) ... 292s Setting up automake (1:1.16.5-1.3ubuntu1) ... 292s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 292s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 292s Setting up gettext (0.21-14ubuntu2) ... 292s Setting up cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 292s Setting up golang-1.22-go (1.22.2-2) ... 292s Setting up intltool-debian (0.35.0+20060710.6) ... 292s Setting up dh-strip-nondeterminism (1.13.1-1) ... 292s Setting up libgcc-13-dev:armhf (13.2.0-23ubuntu4) ... 292s Setting up libc6-dev:armhf (2.39-0ubuntu8.1) ... 292s Setting up cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 292s Setting up libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ... 292s Setting up cpp-13 (13.2.0-23ubuntu4) ... 292s Setting up golang-go:armhf (2:1.22~2build1) ... 292s Setting up po-debconf (1.0.21+nmu1) ... 292s Setting up gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 292s Setting up gcc-13 (13.2.0-23ubuntu4) ... 292s Setting up cpp (4:13.2.0-7ubuntu1) ... 292s Setting up gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 292s Setting up g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 292s Setting up g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 292s Setting up g++-13 (13.2.0-23ubuntu4) ... 292s Setting up libtool (2.4.7-7build1) ... 292s Setting up gcc (4:13.2.0-7ubuntu1) ... 292s Setting up dh-autoreconf (20) ... 292s Setting up g++ (4:13.2.0-7ubuntu1) ... 292s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 292s Setting up build-essential (12.10ubuntu1) ... 292s Setting up debhelper (13.14.1ubuntu5) ... 292s Setting up dh-golang (1.62) ... 292s Setting up autopkgtest-satdep (0) ... 292s Processing triggers for man-db (2.12.0-4build2) ... 293s Processing triggers for install-info (7.1-3build2) ... 294s Processing triggers for libc-bin (2.39-0ubuntu8.1) ... 313s (Reading database ... 76040 files and directories currently installed.) 313s Removing autopkgtest-satdep (0) ... 322s autopkgtest [22:52:24]: test command1: ./debian/tests/test 322s autopkgtest [22:52:24]: test command1: [----------------------- 430s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 430s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 430s === RUN TestRunSignal 430s === RUN TestRunSignal/Send_SIGINT_exits 430s INFO Starting WSL Pro Service version Dev 430s === RUN TestRunSignal/Send_SIGTERM_exits 430s INFO Starting WSL Pro Service version Dev 430s --- PASS: TestRunSignal (0.20s) 430s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 430s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 430s === RUN TestRun 430s === PAUSE TestRun 430s === CONT TestRun 430s === RUN TestRun/Run_and_exit_successfully 430s === PAUSE TestRun/Run_and_exit_successfully 430s === RUN TestRun/Run_and_return_error 430s === PAUSE TestRun/Run_and_return_error 430s === RUN TestRun/Run_and_return_usage_error 430s === PAUSE TestRun/Run_and_return_usage_error 430s === RUN TestRun/Run_and_usage_error_only_does_not_fail 430s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 430s === CONT TestRun/Run_and_exit_successfully 430s === CONT TestRun/Run_and_usage_error_only_does_not_fail 430s === CONT TestRun/Run_and_return_usage_error 430s === CONT TestRun/Run_and_return_error 430s INFO Starting WSL Pro Service version Dev 430s INFO Starting WSL Pro Service version Dev 430s INFO Starting WSL Pro Service version Dev 430s INFO Starting WSL Pro Service version Dev 430s ERROR context.Background Error requested 430s ERROR context.Background Error requested 430s --- PASS: TestRun (0.00s) 430s --- PASS: TestRun/Run_and_return_usage_error (0.11s) 430s --- PASS: TestRun/Run_and_return_error (0.11s) 430s --- PASS: TestRun/Run_and_exit_successfully (0.11s) 430s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.11s) 430s PASS 430s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.484s 431s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 567s === RUN TestHelp 567s --- PASS: TestHelp (1.20s) 567s === RUN TestCompletion 567s --- PASS: TestCompletion (0.35s) 567s === RUN TestVersion 567s --- PASS: TestVersion (0.02s) 567s === RUN TestNoUsageError 567s --- PASS: TestNoUsageError (2.22s) 567s === RUN TestUsageError 567s === PAUSE TestUsageError 567s === RUN TestCanQuitWhenExecute 567s === PAUSE TestCanQuitWhenExecute 567s === RUN TestCanQuitTwice 567s === PAUSE TestCanQuitTwice 567s === RUN TestAppCanQuitWithoutExecute 567s === PAUSE TestAppCanQuitWithoutExecute 567s === RUN TestAppRunFailsOnComponentsCreationAndQuit 567s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 567s === RUN TestAppGetRootCmd 567s === PAUSE TestAppGetRootCmd 567s === RUN TestWithProMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithProMock (0.00s) 567s === RUN TestWithWslPathMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithWslPathMock (0.00s) 567s === RUN TestWithWslInfoMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithWslInfoMock (0.00s) 567s === RUN TestWithCmdExeMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithCmdExeMock (0.00s) 567s === CONT TestUsageError 567s === CONT TestAppGetRootCmd 567s === CONT TestAppRunFailsOnComponentsCreationAndQuit 567s === CONT TestAppCanQuitWithoutExecute 567s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 567s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 567s === CONT TestCanQuitTwice 567s === CONT TestCanQuitWhenExecute 567s time="2024-05-28T22:54:20Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 567s time="2024-05-28T22:54:20Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:75 New() Building new daemon" 567s time="2024-05-28T22:54:20Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45645" 567s time="2024-05-28T22:54:20Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 567s time="2024-05-28T22:54:20Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:75 New() Building new daemon" 567s --- PASS: TestUsageError (2.50s) 567s --- PASS: TestAppGetRootCmd (2.56s) 567s time="2024-05-28T22:56:12Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 567s time="2024-05-28T22:56:13Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 567s time="2024-05-28T22:56:13Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:13Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:16Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 567s time="2024-05-28T22:56:17Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:17Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:21Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:41261" 567s time="2024-05-28T22:56:21Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 567s time="2024-05-28T22:56:21Z" level=warning msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() 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:41261: connect: connection refused\"" 567s time="2024-05-28T22:56:21Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 567s time="2024-05-28T22:56:21Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s time="2024-05-28T22:56:21Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:21Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:21Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s --- PASS: TestCanQuitWhenExecute (122.70s) 567s time="2024-05-28T22:56:22Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:36367" 567s time="2024-05-28T22:56:22Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 567s time="2024-05-28T22:56:22Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 567s time="2024-05-28T22:56:22Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 567s time="2024-05-28T22:56:23Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:23Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:23Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (124.90s) 567s time="2024-05-28T22:56:29Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 567s time="2024-05-28T22:56:29Z" level=warning msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: serve error: could not receive ProAttachCmd: context canceled" 567s time="2024-05-28T22:56:29Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 567s time="2024-05-28T22:56:29Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s time="2024-05-28T22:56:29Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:29Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:29Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s time="2024-05-28T22:56:29Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.7bZ5VP/build.6lg/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 567s time="2024-05-28T22:56:29Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.7bZ5VP/build.6lg/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 567s time="2024-05-28T22:56:29Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.7bZ5VP/build.6lg/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 567s time="2024-05-28T22:56:29Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 567s time="2024-05-28T22:56:29Z" level=info msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 567s time="2024-05-28T22:56:29Z" level=debug msg="/tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 567s --- PASS: TestCanQuitTwice (130.41s) 567s PASS 567s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 136.856s 567s === RUN TestApplyProToken 567s === PAUSE TestApplyProToken 567s === RUN TestApplyLandscapeConfig 567s === PAUSE TestApplyLandscapeConfig 567s === RUN TestWithProMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithProMock (0.00s) 567s === RUN TestWithLandscapeConfigMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithLandscapeConfigMock (0.00s) 567s === RUN TestWithWslPathMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithWslPathMock (0.00s) 567s === RUN TestWithWslInfoMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithWslInfoMock (0.00s) 567s === RUN TestWithCmdExeMock 567s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 567s --- SKIP: TestWithCmdExeMock (0.00s) 567s === CONT TestApplyProToken 567s === RUN TestApplyProToken/Success_attaching 567s === PAUSE TestApplyProToken/Success_attaching 567s === RUN TestApplyProToken/Success_detaching 567s === PAUSE TestApplyProToken/Success_detaching 567s === RUN TestApplyProToken/Error_calling_pro_detach 567s === PAUSE TestApplyProToken/Error_calling_pro_detach 567s === RUN TestApplyProToken/Error_calling_pro_attach 567s === PAUSE TestApplyProToken/Error_calling_pro_attach 567s === CONT TestApplyProToken/Success_attaching 567s === CONT TestApplyLandscapeConfig 567s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 567s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 567s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 567s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 567s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 567s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 567s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 567s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 567s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 567s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 567s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 567s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 567s === CONT TestApplyProToken/Error_calling_pro_detach 567s === CONT TestApplyProToken/Error_calling_pro_attach 567s === CONT TestApplyProToken/Success_detaching 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyLandscapeConfig: received config: registering" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyLandscapeConfig: received config: registering" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 567s time="2024-05-28T22:54:15Z" level=info msg="ApplyProToken: Received empty token: detaching" 567s --- PASS: TestApplyLandscapeConfig (0.00s) 567s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (88.06s) 567s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (88.78s) 567s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (88.10s) 567s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (103.05s) 567s --- PASS: TestApplyProToken (0.00s) 567s --- PASS: TestApplyProToken/Success_detaching (88.33s) 567s --- PASS: TestApplyProToken/Error_calling_pro_detach (104.13s) 567s --- PASS: TestApplyProToken/Error_calling_pro_attach (118.82s) 567s --- PASS: TestApplyProToken/Success_attaching (122.22s) 567s PASS 567s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 124.554s 785s === RUN TestNew 785s === PAUSE TestNew 785s === RUN TestServe 785s === PAUSE TestServe 785s === RUN TestServeAndQuit 785s === PAUSE TestServeAndQuit 785s === RUN TestReconnection 785s === PAUSE TestReconnection 785s === RUN TestWithProMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithProMock (0.00s) 785s === RUN TestWithWslPathMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslPathMock (0.00s) 785s === RUN TestWithWslInfoMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslInfoMock (0.00s) 785s === RUN TestWithCmdExeMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithCmdExeMock (0.00s) 785s === CONT TestNew 785s === RUN TestNew/Error_when_WslPath_returns_error 785s === PAUSE TestNew/Error_when_WslPath_returns_error 785s === RUN TestNew/Success 785s === PAUSE TestNew/Success 785s === CONT TestNew/Error_when_WslPath_returns_error 785s === CONT TestServeAndQuit 785s === RUN TestServeAndQuit/Success_with_graceful_quit 785s === PAUSE TestServeAndQuit/Success_with_graceful_quit 785s === RUN TestServeAndQuit/Success_with_forceful_quit 785s === PAUSE TestServeAndQuit/Success_with_forceful_quit 785s === RUN TestServeAndQuit/Success_with_double_quit 785s === PAUSE TestServeAndQuit/Success_with_double_quit 785s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 785s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 785s === CONT TestServeAndQuit/Success_with_graceful_quit 785s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 785s time="2024-05-28T22:54:14Z" level=debug msg="Building new daemon" 785s === CONT TestServeAndQuit/Success_with_double_quit 785s === CONT TestNew/Success 785s time="2024-05-28T22:54:14Z" level=debug msg="Building new daemon" 785s === CONT TestServeAndQuit/Success_with_forceful_quit 785s === CONT TestServe 785s === RUN TestServe/No_connection_because_the_port_file_is_empty 785s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 785s === RUN TestServe/No_connection_because_the_port_file_has_port_0 785s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 785s === RUN TestServe/No_connection_because_there_is_no_server 785s === PAUSE TestServe/No_connection_because_there_is_no_server 785s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 785s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 785s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 785s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 785s === RUN TestServe/Success 785s === PAUSE TestServe/Success 785s === RUN TestServe/Success_with_systemd_notifier_returning_true 785s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 785s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 785s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 785s === RUN TestServe/No_connection_because_there_are_no_certificates 785s === PAUSE TestServe/No_connection_because_there_are_no_certificates 785s === RUN TestServe/Error_because_the_context_is_pre-cancelled 785s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 785s === RUN TestServe/Error_because_the_notifier_returns_an_error 785s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 785s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 785s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 785s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 785s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 785s === CONT TestServe/No_connection_because_the_port_file_is_empty 785s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39543" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46167" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34471" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45097" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43847" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:54:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40857" 785s time="2024-05-28T22:54:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:11Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:56:11Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:11Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 785s time="2024-05-28T22:56:12Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:12Z" 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" 785s time="2024-05-28T22:56:12Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:12Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:56:12Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:12Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:56:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38837" 785s time="2024-05-28T22:56:12Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:13Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:13Z" 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" 785s time="2024-05-28T22:56:13Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T22:56:13Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:13Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:13Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T22:56:13Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:13Z" 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" 785s time="2024-05-28T22:56:13Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s --- PASS: TestNew (0.00s) 785s --- PASS: TestNew/Error_when_WslPath_returns_error (117.10s) 785s --- PASS: TestNew/Success (118.85s) 785s === CONT TestServe/Error_because_the_notifier_returns_an_error 785s time="2024-05-28T22:56:13Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45665" 785s time="2024-05-28T22:56:13Z" level=debug msg="Building new daemon" 785s === CONT TestServe/Error_because_the_context_is_pre-cancelled 785s time="2024-05-28T22:56:13Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41279" 785s time="2024-05-28T22:56:13Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:14Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:14Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:14Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:14Z" 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" 785s time="2024-05-28T22:56:14Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T22:56:14Z" level=debug msg="All connections have now ended." 785s === CONT TestServe/No_connection_because_there_are_no_certificates 785s time="2024-05-28T22:56:14Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:56:14Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:14Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:56:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33873" 785s time="2024-05-28T22:56:14Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:14Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:14Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:14Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:14Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:56:14Z" level=debug msg="Building new daemon" 785s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 785s time="2024-05-28T22:56:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33641" 785s time="2024-05-28T22:56:15Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:19Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43847" 785s time="2024-05-28T22:56:19Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T22:56:19Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T22:56:19Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T22:56:19Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T22:56:21Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34471" 785s time="2024-05-28T22:56:21Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T22:56:21Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T22:56:21Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40857" 785s time="2024-05-28T22:56:21Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T22:56:21Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T22:56:21Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T22:56:21Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T22:56:21Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T22:56:21Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T22:56:25Z" level=debug msg="Server: sent preface messages to all streams" 785s time="2024-05-28T22:56:25Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 785s time="2024-05-28T22:56:25Z" level=info msg="MockWindowsAgent: Connected ready" 785s time="2024-05-28T22:56:25Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 785s time="2024-05-28T22:56:25Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:25Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:25Z" level=warning msg="Daemon: disconnected from Windows host" 785s time="2024-05-28T22:56:25Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:25Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s time="2024-05-28T22:56:25Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:56:25Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T22:56:25Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:25Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:25Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:25Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:25Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:25Z" level=debug msg="All connections have now ended." 785s === CONT TestServe/Success_with_systemd_notifier_returning_true 785s time="2024-05-28T22:56:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37615" 785s time="2024-05-28T22:56:25Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:25Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 785s time="2024-05-28T22:56:25Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:25Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:25Z" level=debug msg="All connections have now ended." 785s === CONT TestServe/Success 785s time="2024-05-28T22:56:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39751" 785s time="2024-05-28T22:56:25Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:25Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:26Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:26Z" 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_exist3586555494/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist3586555494/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 785s time="2024-05-28T22:56:26Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:27Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:27Z" 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_exist3586555494/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist3586555494/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 785s time="2024-05-28T22:56:27Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T22:56:27Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:27Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:27Z" level=debug msg="All connections have now ended." 785s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 785s time="2024-05-28T22:56:27Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39897" 785s time="2024-05-28T22:56:27Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:28Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:56:28Z" 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" 785s time="2024-05-28T22:56:28Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:28Z" level=debug msg="Server: sent preface messages to all streams" 785s time="2024-05-28T22:56:28Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 785s time="2024-05-28T22:56:28Z" level=info msg="MockWindowsAgent: Connected ready" 785s time="2024-05-28T22:56:28Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 785s time="2024-05-28T22:56:28Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:28Z" level=info msg="Stopping active requests." 785s time="2024-05-28T22:56:28Z" level=warning msg="Daemon: disconnected from Windows host" 785s time="2024-05-28T22:56:28Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:28Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s time="2024-05-28T22:56:28Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:56:28Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T22:56:28Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:28Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:28Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 785s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 785s time="2024-05-28T22:56:28Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41793" 785s time="2024-05-28T22:56:28Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:29Z" level=debug msg="Server: sent preface messages to all streams" 785s time="2024-05-28T22:56:29Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 785s time="2024-05-28T22:56:29Z" level=info msg="MockWindowsAgent: Connected ready" 785s time="2024-05-28T22:56:29Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 785s time="2024-05-28T22:56:29Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:29Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:29Z" level=debug msg="All connections have now ended." 785s === CONT TestServe/No_connection_because_there_is_no_server 785s time="2024-05-28T22:56:29Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:29Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:29Z" level=warning msg="Daemon: disconnected from Windows host" 785s time="2024-05-28T22:56:29Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:29Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s time="2024-05-28T22:56:29Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:56:29Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T22:56:29Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:29Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:29Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:56:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46099" 785s time="2024-05-28T22:56:29Z" level=debug msg="Building new daemon" 785s --- PASS: TestServeAndQuit (0.00s) 785s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (120.63s) 785s --- PASS: TestServeAndQuit/Success_with_double_quit (130.54s) 785s --- PASS: TestServeAndQuit/Success_with_forceful_quit (134.12s) 785s --- PASS: TestServeAndQuit/Success_with_graceful_quit (134.60s) 785s === CONT TestServe/No_connection_because_the_port_file_has_port_0 785s time="2024-05-28T22:56:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42661" 785s time="2024-05-28T22:56:29Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:29Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:29Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:29Z" level=debug msg="All connections have now ended." 785s === CONT TestReconnection 785s === RUN TestReconnection/Success_connecting_after_failing_to_connect 785s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 785s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 785s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 785s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 785s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 785s === CONT TestReconnection/Success_connecting_after_failing_to_connect 785s time="2024-05-28T22:56:29Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:56:36Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33873" 785s time="2024-05-28T22:56:36Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates2406272499/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 785s time="2024-05-28T22:56:36Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:56:36Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:56:36Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:56:36Z" level=debug msg="All connections have now ended." 785s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 785s time="2024-05-28T22:56:36Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:57:25Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:57:25Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:25Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:57:25Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:30Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:42Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:44Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:44Z" 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" 785s time="2024-05-28T22:57:44Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:57:46Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:57:46Z" level=info msg="Waiting for active requests to close." 785s time="2024-05-28T22:57:46Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:46Z" 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" 785s time="2024-05-28T22:57:46Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T22:57:46Z" level=debug msg="All connections have now ended." 785s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 785s time="2024-05-28T22:57:49Z" level=debug msg="Building new daemon" 785s time="2024-05-28T22:57:50Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:53Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:57:53Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:57:54Z" 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_connect3592570122/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3592570122/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 785s time="2024-05-28T22:57:54Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T22:57:54Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s === NAME TestServe/Success_with_systemd_notifier_returning_true 785s daemon_test.go:178: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:178 785s Error: Condition never satisfied 785s Test: TestServe/Success_with_systemd_notifier_returning_true 785s Messages: Systemd never switched states to 'Connected' 785s time="2024-05-28T22:57:55Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:55Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:57:55Z" 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_connect3592570122/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3592570122/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 785s time="2024-05-28T22:57:55Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T22:57:55Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s === NAME TestServe/Error_because_WindowsHostAddress_returns_an_error 785s daemon_test.go:196: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:196 785s Error: Serve should have returned an error, but is still serving 785s Test: TestServe/Error_because_WindowsHostAddress_returns_an_error 785s time="2024-05-28T22:57:56Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40639" 785s time="2024-05-28T22:57:57Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:57:57Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s === NAME TestServe/Success 785s daemon_test.go:178: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:178 785s Error: Condition never satisfied 785s Test: TestServe/Success 785s Messages: Systemd never switched states to 'Connected' 785s time="2024-05-28T22:58:07Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s === NAME TestServe/No_connection_because_there_is_no_server 785s daemon_test.go:200: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:200 785s Error: Condition never satisfied 785s Test: TestServe/No_connection_because_there_is_no_server 785s Messages: Systemd never switched states to 'Not connected' 785s time="2024-05-28T22:58:13Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43759" 785s time="2024-05-28T22:58:13Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:58:13Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:58:13Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s === NAME TestReconnection/Success_connecting_after_failing_to_connect 785s daemon_test.go:392: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:392 785s Error: Condition never satisfied 785s Test: TestReconnection/Success_connecting_after_failing_to_connect 785s Messages: Daemon never connected to agent's service 785s time="2024-05-28T22:58:16Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:58:16Z" level=info msg="Stopping active requests." 785s === NAME TestServe/No_connection_because_cannot_read_root_CA_certificate_file 785s daemon_test.go:200: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:200 785s Error: Condition never satisfied 785s Test: TestServe/No_connection_because_cannot_read_root_CA_certificate_file 785s Messages: Systemd never switched states to 'Not connected' 785s --- FAIL: TestServe (0.06s) 785s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (118.96s) 785s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (119.60s) 785s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (12.25s) 785s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (15.90s) 785s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (15.35s) 785s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (14.40s) 785s --- PASS: TestServe/No_connection_because_there_are_no_certificates (22.47s) 785s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (80.61s) 785s --- FAIL: TestServe/Success_with_systemd_notifier_returning_true (89.85s) 785s --- FAIL: TestServe/Error_because_WindowsHostAddress_returns_an_error (88.14s) 785s --- FAIL: TestServe/Success (94.39s) 785s --- FAIL: TestServe/No_connection_because_there_is_no_server (103.80s) 785s --- FAIL: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (112.12s) 785s time="2024-05-28T22:58:41Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:58:41Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T22:58:48Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43759" 785s time="2024-05-28T22:58:48Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T22:58:48Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T22:58:49Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T22:58:49Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T22:58:50Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:32845" 785s time="2024-05-28T22:58:50Z" level=debug msg="Ready state sent to systemd" 785s time="2024-05-28T22:58:50Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T22:58:50Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T22:58:56Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:32845" 785s time="2024-05-28T22:58:56Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T22:58:56Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T22:58:56Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T22:58:56Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T22:58:57Z" level=info msg="MockWindowsAgent: Connected ready" 785s time="2024-05-28T22:58:57Z" level=debug msg="Server: sent preface messages to all streams" 785s time="2024-05-28T22:58:57Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 785s time="2024-05-28T22:58:57Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 785s === NAME TestReconnection/Success_connecting_after_previous_connection_dropped 785s daemon_test.go:375: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/daemon/daemon_test.go:375 785s Error: Condition never satisfied 785s Test: TestReconnection/Success_connecting_after_previous_connection_dropped 785s Messages: Daemon never connected to agent's service 785s time="2024-05-28T22:59:07Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T22:59:07Z" level=info msg="Stopping active requests." 785s time="2024-05-28T22:59:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:59:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:59:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:59:13Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T22:59:13Z" level=debug msg="All connections have now ended." 785s time="2024-05-28T23:00:02Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:02Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:02Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:02Z" level=warning msg="Daemon: disconnected from Windows host" 785s time="2024-05-28T23:00:02Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T23:00:02Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T23:00:02Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped2211158332/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped2211158332/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 785s time="2024-05-28T23:00:02Z" level=info msg="Reconnecting to Windows host in 1 seconds" 785s time="2024-05-28T23:00:02Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s time="2024-05-28T23:00:02Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35761" 785s time="2024-05-28T23:00:03Z" level=info msg="Daemon: connecting to Windows Agent" 785s time="2024-05-28T23:00:03Z" level=debug msg="Updated systemd status to \"Connecting\"" 785s time="2024-05-28T23:00:05Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35761" 785s time="2024-05-28T23:00:05Z" level=info msg="Daemon: completed connection to Windows Agent" 785s time="2024-05-28T23:00:05Z" level=debug msg="Updated systemd status to \"Connected\"" 785s time="2024-05-28T23:00:05Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 785s time="2024-05-28T23:00:05Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 785s time="2024-05-28T23:00:07Z" level=debug msg="Server: sent preface messages to all streams" 785s time="2024-05-28T23:00:07Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 785s time="2024-05-28T23:00:07Z" level=info msg="MockWindowsAgent: Connected ready" 785s time="2024-05-28T23:00:07Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 785s time="2024-05-28T23:00:07Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:07Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:07Z" level=info msg="Stopping daemon requested." 785s time="2024-05-28T23:00:07Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T23:00:07Z" level=info msg="Stopping active requests." 785s time="2024-05-28T23:00:07Z" level=warning msg="Daemon: disconnected from Windows host" 785s time="2024-05-28T23:00:07Z" level=info msg="Reconnecting to Windows host in 2 seconds" 785s time="2024-05-28T23:00:07Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 785s time="2024-05-28T23:00:07Z" level=debug msg="Updated systemd status to \"Stopped\"" 785s time="2024-05-28T23:00:07Z" level=debug msg="All connections have now ended." 785s --- FAIL: TestReconnection (0.00s) 785s --- FAIL: TestReconnection/Success_connecting_after_failing_to_connect (131.84s) 785s --- FAIL: TestReconnection/Success_connecting_after_previous_connection_dropped (83.66s) 785s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (210.57s) 785s FAIL 785s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 354.797s 785s === RUN TestConnect 785s === PAUSE TestConnect 785s === RUN TestSendAndRecv 785s --- PASS: TestSendAndRecv (0.59s) 785s === RUN TestServe 785s === PAUSE TestServe 785s === RUN TestStop 785s === PAUSE TestStop 785s === RUN TestWithProMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithProMock (0.00s) 785s === RUN TestWithWslPathMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslPathMock (0.00s) 785s === RUN TestWithWslInfoMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslInfoMock (0.00s) 785s === RUN TestWithCmdExeMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithCmdExeMock (0.00s) 785s === CONT TestConnect 785s === RUN TestConnect/Success 785s === PAUSE TestConnect/Success 785s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 785s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 785s === CONT TestConnect/Success 785s === CONT TestServe 785s === CONT TestStop 785s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 785s time="2024-05-28T22:54:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44951" 785s time="2024-05-28T22:54:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35145" 785s === NAME TestServe 785s server_test.go:41: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/streams/server_test.go:41 785s Error: Condition never satisfied 785s Test: TestServe 785s Messages: Setup: Agent service never became ready 785s === NAME TestStop 785s server_test.go:116: 785s Error Trace: /tmp/autopkgtest.7bZ5VP/build.6lg/src/internal/streams/server_test.go:116 785s Error: Condition never satisfied 785s Test: TestStop 785s Messages: Setup: Agent service never became ready 785s --- FAIL: TestServe (24.13s) 785s time="2024-05-28T22:54:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:54:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:54:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s --- PASS: TestConnect (0.00s) 785s --- PASS: TestConnect/Success (0.34s) 785s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (24.69s) 785s time="2024-05-28T22:54:39Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:54:39Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s time="2024-05-28T22:54:39Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 785s --- FAIL: TestStop (24.71s) 785s FAIL 785s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 26.264s 785s === RUN TestInfo 785s === PAUSE TestInfo 785s === RUN TestWslDistroName 785s === PAUSE TestWslDistroName 785s === RUN TestUserProfileDir 785s === PAUSE TestUserProfileDir 785s === RUN TestProStatus 785s === PAUSE TestProStatus 785s === RUN TestProAttach 785s === PAUSE TestProAttach 785s === RUN TestProDetach 785s === PAUSE TestProDetach 785s === RUN TestLandscapeEnable 785s === PAUSE TestLandscapeEnable 785s === RUN TestWindowsHostAddress 785s === PAUSE TestWindowsHostAddress 785s === RUN TestLandscapeDisable 785s === PAUSE TestLandscapeDisable 785s === RUN TestRealBackend 785s === PAUSE TestRealBackend 785s === RUN TestWithProMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithProMock (0.00s) 785s === RUN TestWithLandscapeConfigMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithLandscapeConfigMock (0.00s) 785s === RUN TestWithWslPathMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslPathMock (0.00s) 785s === RUN TestWithWslInfoMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithWslInfoMock (0.00s) 785s === RUN TestWithCmdExeMock 785s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 785s --- SKIP: TestWithCmdExeMock (0.00s) 785s === CONT TestInfo 785s === RUN TestInfo/Error_when_WslDistroName_fails 785s === PAUSE TestInfo/Error_when_WslDistroName_fails 785s === RUN TestInfo/Error_when_pro_status_command_fails 785s === PAUSE TestInfo/Error_when_pro_status_command_fails 785s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 785s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 785s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 785s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 785s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 785s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 785s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 785s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 785s === RUN TestInfo/Success 785s === PAUSE TestInfo/Success 785s === CONT TestInfo/Error_when_WslDistroName_fails 785s === CONT TestRealBackend 785s --- PASS: TestRealBackend (0.00s) 785s === CONT TestLandscapeDisable 785s === RUN TestLandscapeDisable/Success 785s === PAUSE TestLandscapeDisable/Success 785s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 785s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 785s === CONT TestLandscapeDisable/Success 785s === CONT TestWindowsHostAddress 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 785s === RUN TestWindowsHostAddress/Success_without_NAT 785s === PAUSE TestWindowsHostAddress/Success_without_NAT 785s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 785s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 785s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 785s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 785s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 785s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 785s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 785s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 785s === CONT TestLandscapeEnable 785s === RUN TestLandscapeEnable/Success_overriding_computer_title 785s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 785s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 785s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 785s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 785s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 785s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 785s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 785s === RUN TestLandscapeEnable/Success 785s === PAUSE TestLandscapeEnable/Success 785s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 785s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 785s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 785s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 785s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 785s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 785s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 785s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 785s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 785s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 785s === CONT TestLandscapeEnable/Success_overriding_computer_title 785s === CONT TestProDetach 785s === RUN TestProDetach/success_on_unattached_distro 785s === PAUSE TestProDetach/success_on_unattached_distro 785s === RUN TestProDetach/success_on_attached_distro 785s === PAUSE TestProDetach/success_on_attached_distro 785s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 785s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 785s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 785s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 785s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 785s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 785s === CONT TestProDetach/success_on_unattached_distro 785s === CONT TestProAttach 785s === RUN TestProAttach/success 785s === PAUSE TestProAttach/success 785s === RUN TestProAttach/error_on_'pro_attach'_error 785s === PAUSE TestProAttach/error_on_'pro_attach'_error 785s === CONT TestProAttach/success 785s === CONT TestProStatus 785s === RUN TestProStatus/error_on_'pro_attach'_error 785s === PAUSE TestProStatus/error_on_'pro_attach'_error 785s === RUN TestProStatus/success_on_unattached_distro 785s === PAUSE TestProStatus/success_on_unattached_distro 785s === RUN TestProStatus/success_on_attached_distro 785s === PAUSE TestProStatus/success_on_attached_distro 785s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 785s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 785s === CONT TestProStatus/error_on_'pro_attach'_error 785s === CONT TestUserProfileDir 785s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 785s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 785s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 785s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 785s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 785s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 785s === RUN TestUserProfileDir/Error_on_wslpath_error 785s === PAUSE TestUserProfileDir/Error_on_wslpath_error 785s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 785s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 785s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 785s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 785s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 785s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 785s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 785s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 785s === RUN TestUserProfileDir/Error_on_cmd.exe_error 785s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 785s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 785s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 785s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 785s time="2024-05-28T22:54:17Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 785s === CONT TestWslDistroName 785s === RUN TestWslDistroName/Success_using_wslpath 785s === PAUSE TestWslDistroName/Success_using_wslpath 785s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 785s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 785s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 785s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 785s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 785s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 785s === CONT TestInfo/Success 785s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 785s === NAME TestLandscapeEnable/Success_overriding_computer_title 785s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 785s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 785s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 785s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 785s === CONT TestInfo/Error_when_pro_status_command_fails 785s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 785s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 785s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 785s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 785s === CONT TestWindowsHostAddress/Success_without_NAT 785s --- PASS: TestLandscapeDisable (0.00s) 785s --- PASS: TestLandscapeDisable/Success (90.79s) 785s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (12.77s) 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 785s --- PASS: TestInfo (0.00s) 785s --- PASS: TestInfo/Error_when_WslDistroName_fails (101.02s) 785s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (10.34s) 785s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (23.59s) 785s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (13.42s) 785s --- PASS: TestInfo/Error_when_pro_status_command_fails (11.90s) 785s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (17.21s) 785s --- PASS: TestInfo/Success (31.36s) 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 785s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 785s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 785s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 785s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 785s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 785s time="2024-05-28T22:56:19Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 785s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 785s time="2024-05-28T22:56:20Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 785s === CONT TestLandscapeEnable/Success 785s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 785s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 785s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 785s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 785s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 785s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 785s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 785s --- PASS: TestWindowsHostAddress (0.00s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (87.89s) 785s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (7.43s) 785s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (7.95s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (8.43s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (8.98s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (5.65s) 785s --- PASS: TestWindowsHostAddress/Success_without_NAT (6.50s) 785s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (8.87s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (6.24s) 785s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (6.03s) 785s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 785s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 785s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 785s === CONT TestProDetach/success_on_attached_distro 785s === CONT TestProAttach/error_on_'pro_attach'_error 785s === NAME TestLandscapeEnable/Success 785s system_test.go:456: testdata/TestLandscapeEnable/golden/success 785s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 785s === CONT TestProStatus/success_on_attached_distro 785s === NAME TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 785s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 785s === CONT TestProStatus/success_on_unattached_distro 785s --- PASS: TestLandscapeEnable (0.00s) 785s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (101.01s) 785s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 785s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 785s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.34s) 785s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (5.36s) 785s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (5.51s) 785s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (4.73s) 785s --- PASS: TestLandscapeEnable/Success (6.16s) 785s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (8.02s) 785s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (10.00s) 785s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 785s === CONT TestUserProfileDir/Error_on_cmd.exe_error 785s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 785s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 785s --- PASS: TestProAttach (0.00s) 785s --- PASS: TestProAttach/success (103.82s) 785s --- PASS: TestProAttach/error_on_'pro_attach'_error (8.31s) 785s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 785s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 785s --- PASS: TestProDetach (0.00s) 785s --- PASS: TestProDetach/success_on_unattached_distro (104.66s) 785s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (6.95s) 785s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (7.23s) 785s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (7.52s) 785s --- PASS: TestProDetach/success_on_attached_distro (9.47s) 785s === CONT TestUserProfileDir/Error_on_wslpath_error 785s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 785s system_test.go:205: Removing default proc/mounts 785s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 785s system_test.go:205: Removing default proc/mounts 785s === CONT TestWslDistroName/Success_using_wslpath 785s --- PASS: TestProStatus (0.00s) 785s --- PASS: TestProStatus/error_on_'pro_attach'_error (104.35s) 785s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (8.30s) 785s --- PASS: TestProStatus/success_on_unattached_distro (18.28s) 785s --- PASS: TestProStatus/success_on_attached_distro (23.23s) 785s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 785s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 785s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 785s --- PASS: TestWslDistroName (0.00s) 785s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.03s) 785s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (49.67s) 785s --- PASS: TestWslDistroName/Success_using_wslpath (55.83s) 785s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (37.67s) 785s --- PASS: TestUserProfileDir (0.00s) 785s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (114.53s) 785s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 785s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 785s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 785s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (47.45s) 785s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (72.71s) 785s --- PASS: TestUserProfileDir/Error_on_wslpath_error (86.86s) 785s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (90.74s) 785s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (89.94s) 785s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (101.67s) 785s PASS 785s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 243.320s 785s FAIL 786s autopkgtest [23:00:08]: test command1: -----------------------] 791s autopkgtest [23:00:13]: test command1: - - - - - - - - - - results - - - - - - - - - - 791s command1 FAIL non-zero exit status 1 795s autopkgtest [23:00:17]: @@@@@@@@@@@@@@@@@@@@ summary 795s command1 FAIL non-zero exit status 1