0s autopkgtest [14:35:51]: starting date and time: 2024-07-15 14:35:51+0000 0s autopkgtest [14:35:51]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [14:35:51]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.eqsksz59/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/33.1~24.04' -- lxd -r lxd-armhf-10.145.243.9 lxd-armhf-10.145.243.9:autopkgtest/ubuntu/noble/armhf 30s autopkgtest [14:36:21]: testbed dpkg architecture: armhf 32s autopkgtest [14:36:23]: testbed apt version: 2.7.14build2 32s autopkgtest [14:36:23]: @@@@@@@@@@@@@@@@@@@@ test bed setup 40s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [265 kB] 40s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [14.0 kB] 40s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [41.9 kB] 40s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [6912 B] 40s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main armhf Packages [56.6 kB] 40s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main armhf c-n-f Metadata [2212 B] 40s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf Packages [1176 B] 40s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted armhf c-n-f Metadata [116 B] 40s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf Packages [53.0 kB] 40s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe armhf c-n-f Metadata [2152 B] 40s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse armhf c-n-f Metadata [116 B] 42s Fetched 443 kB in 1s (579 kB/s) 42s Reading package lists... 61s tee: /proc/self/fd/2: Permission denied 79s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 79s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 79s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 79s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 80s Reading package lists... 80s Reading package lists... 80s Building dependency tree... 80s Reading state information... 81s Calculating upgrade... 81s The following packages will be upgraded: 81s libnss-systemd libpam-systemd libsystemd-shared libsystemd0 libudev1 systemd 81s systemd-dev systemd-resolved systemd-sysv systemd-timesyncd 81s ubuntu-pro-client ubuntu-pro-client-l10n udev 81s 13 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 81s Need to get 8999 kB of archives. 81s After this operation, 21.5 kB of additional disk space will be used. 81s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main armhf libnss-systemd armhf 255.4-1ubuntu8.2 [148 kB] 82s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main armhf systemd-dev all 255.4-1ubuntu8.2 [104 kB] 82s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main armhf systemd-timesyncd armhf 255.4-1ubuntu8.2 [36.0 kB] 82s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main armhf systemd-resolved armhf 255.4-1ubuntu8.2 [289 kB] 82s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main armhf libsystemd-shared armhf 255.4-1ubuntu8.2 [2010 kB] 82s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main armhf libsystemd0 armhf 255.4-1ubuntu8.2 [411 kB] 82s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main armhf systemd-sysv armhf 255.4-1ubuntu8.2 [11.9 kB] 82s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main armhf libpam-systemd armhf 255.4-1ubuntu8.2 [216 kB] 82s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/main armhf systemd armhf 255.4-1ubuntu8.2 [3502 kB] 82s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/main armhf udev armhf 255.4-1ubuntu8.2 [1852 kB] 82s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/main armhf libudev1 armhf 255.4-1ubuntu8.2 [167 kB] 82s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/main armhf ubuntu-pro-client-l10n armhf 33.1~24.04 [19.3 kB] 82s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/main armhf ubuntu-pro-client armhf 33.1~24.04 [232 kB] 82s Fetched 8999 kB in 1s (10.6 MB/s) 82s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 57911 files and directories currently installed.) 82s Preparing to unpack .../0-libnss-systemd_255.4-1ubuntu8.2_armhf.deb ... 82s Unpacking libnss-systemd:armhf (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../1-systemd-dev_255.4-1ubuntu8.2_all.deb ... 83s Unpacking systemd-dev (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../2-systemd-timesyncd_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking systemd-timesyncd (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../3-systemd-resolved_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking systemd-resolved (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../4-libsystemd-shared_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking libsystemd-shared:armhf (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../5-libsystemd0_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking libsystemd0:armhf (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Setting up libsystemd0:armhf (255.4-1ubuntu8.2) ... 83s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 57911 files and directories currently installed.) 83s Preparing to unpack .../systemd-sysv_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking systemd-sysv (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../libpam-systemd_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking libpam-systemd:armhf (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../systemd_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking systemd (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../udev_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking udev (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Preparing to unpack .../libudev1_255.4-1ubuntu8.2_armhf.deb ... 83s Unpacking libudev1:armhf (255.4-1ubuntu8.2) over (255.4-1ubuntu8.1) ... 83s Setting up libudev1:armhf (255.4-1ubuntu8.2) ... 83s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 57912 files and directories currently installed.) 83s Preparing to unpack .../ubuntu-pro-client-l10n_33.1~24.04_armhf.deb ... 83s Unpacking ubuntu-pro-client-l10n (33.1~24.04) over (32.3.1~24.04) ... 83s Preparing to unpack .../ubuntu-pro-client_33.1~24.04_armhf.deb ... 84s Unpacking ubuntu-pro-client (33.1~24.04) over (32.3.1~24.04) ... 84s Setting up systemd-dev (255.4-1ubuntu8.2) ... 84s Setting up libsystemd-shared:armhf (255.4-1ubuntu8.2) ... 84s Setting up ubuntu-pro-client (33.1~24.04) ... 84s apparmor_parser: Unable to replace "ubuntu_pro_apt_news". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 84s 84s apparmor_parser: Unable to replace "apt_methods". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 84s 84s apparmor_parser: Unable to replace "ubuntu_pro_esm_cache". apparmor_parser: Access denied. You need policy admin privileges to manage profiles. 84s 85s Setting up ubuntu-pro-client-l10n (33.1~24.04) ... 85s Setting up systemd (255.4-1ubuntu8.2) ... 86s Setting up systemd-timesyncd (255.4-1ubuntu8.2) ... 87s Setting up udev (255.4-1ubuntu8.2) ... 87s Setting up systemd-resolved (255.4-1ubuntu8.2) ... 88s Setting up systemd-sysv (255.4-1ubuntu8.2) ... 88s Setting up libnss-systemd:armhf (255.4-1ubuntu8.2) ... 88s Setting up libpam-systemd:armhf (255.4-1ubuntu8.2) ... 88s Processing triggers for libc-bin (2.39-0ubuntu8.2) ... 88s Processing triggers for man-db (2.12.0-4build2) ... 90s Processing triggers for dbus (1.14.10-4ubuntu4) ... 90s Processing triggers for initramfs-tools (0.142ubuntu25.1) ... 90s Reading package lists... 90s Building dependency tree... 90s Reading state information... 91s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 93s autopkgtest [14:37:24]: rebooting testbed after setup commands that affected boot 133s autopkgtest [14:38:04]: testbed running kernel: Linux 6.5.0-41-generic #41~22.04.2-Ubuntu SMP PREEMPT_DYNAMIC Mon Jun 3 16:28:24 UTC 2 160s autopkgtest [14:38:31]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 171s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 171s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 171s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 171s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 171s gpgv: Can't check signature: No public key 171s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 171s autopkgtest [14:38:42]: testing package wsl-pro-service version 0.1.4 173s autopkgtest [14:38:44]: build not needed 176s autopkgtest [14:38:47]: test command1: preparing testbed 186s Reading package lists... 186s Building dependency tree... 186s Reading state information... 186s Starting pkgProblemResolver with broken count: 0 187s Starting 2 pkgProblemResolver with broken count: 0 187s Done 187s The following additional packages will be installed: 187s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 187s cpp-13-arm-linux-gnueabihf cpp-arm-linux-gnueabihf debhelper debugedit 187s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 187s g++-13-arm-linux-gnueabihf g++-arm-linux-gnueabihf gcc gcc-13 187s gcc-13-arm-linux-gnueabihf gcc-13-base gcc-arm-linux-gnueabihf gettext 187s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 187s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 187s libcrypt-dev libdebhelper-perl libdw1t64 libfile-stripnondeterminism-perl 187s libgcc-13-dev libgomp1 libisl23 libmpc3 libstdc++-13-dev 187s libsub-override-perl libtool libubsan1 linux-libc-dev m4 po-debconf 187s rpcsvc-proto 187s Suggested packages: 187s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 187s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 187s gcc-doc gdb-arm-linux-gnueabihf gettext-doc libasprintf-dev libgettextpo-dev 187s bzr | brz git mercurial subversion glibc-doc libstdc++-13-doc libtool-doc 187s gfortran | fortran95-compiler gcj-jdk m4-doc libmail-box-perl 187s Recommended packages: 187s pkg-config manpages manpages-dev libc-devtools libarchive-cpio-perl 187s libltdl-dev libmail-sendmail-perl 187s The following NEW packages will be installed: 187s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 187s cpp cpp-13 cpp-13-arm-linux-gnueabihf cpp-arm-linux-gnueabihf debhelper 187s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 187s g++-13 g++-13-arm-linux-gnueabihf g++-arm-linux-gnueabihf gcc gcc-13 187s gcc-13-arm-linux-gnueabihf gcc-13-base gcc-arm-linux-gnueabihf gettext 187s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 187s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 187s libcrypt-dev libdebhelper-perl libdw1t64 libfile-stripnondeterminism-perl 187s libgcc-13-dev libgomp1 libisl23 libmpc3 libstdc++-13-dev 187s libsub-override-perl libtool libubsan1 linux-libc-dev m4 po-debconf 187s rpcsvc-proto 187s 0 upgraded, 54 newly installed, 0 to remove and 0 not upgraded. 187s Need to get 95.3 MB/95.3 MB of archives. 187s After this operation, 377 MB of additional disk space will be used. 187s Get:1 /tmp/autopkgtest.O1nfeX/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [760 B] 188s Get:2 http://ftpmaster.internal/ubuntu noble/main armhf m4 armhf 1.4.19-4build1 [235 kB] 188s Get:3 http://ftpmaster.internal/ubuntu noble/main armhf autoconf all 2.71-3 [339 kB] 188s Get:4 http://ftpmaster.internal/ubuntu noble/main armhf autotools-dev all 20220109.1 [44.9 kB] 188s Get:5 http://ftpmaster.internal/ubuntu noble/main armhf automake all 1:1.16.5-1.3ubuntu1 [558 kB] 188s Get:6 http://ftpmaster.internal/ubuntu noble/main armhf autopoint all 0.21-14ubuntu2 [422 kB] 188s Get:7 http://ftpmaster.internal/ubuntu noble-updates/main armhf libc-dev-bin armhf 2.39-0ubuntu8.2 [19.1 kB] 188s Get:8 http://ftpmaster.internal/ubuntu noble-updates/main armhf linux-libc-dev armhf 6.8.0-38.38 [1604 kB] 188s Get:9 http://ftpmaster.internal/ubuntu noble/main armhf libcrypt-dev armhf 1:4.4.36-4build1 [120 kB] 188s Get:10 http://ftpmaster.internal/ubuntu noble/main armhf rpcsvc-proto armhf 1.4.2-0ubuntu7 [62.2 kB] 188s Get:11 http://ftpmaster.internal/ubuntu noble-updates/main armhf libc6-dev armhf 2.39-0ubuntu8.2 [1351 kB] 188s Get:12 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13-base armhf 13.2.0-23ubuntu4 [48.9 kB] 188s Get:13 http://ftpmaster.internal/ubuntu noble/main armhf libisl23 armhf 0.26-3build1 [544 kB] 188s Get:14 http://ftpmaster.internal/ubuntu noble/main armhf libmpc3 armhf 1.3.1-1build1 [46.7 kB] 188s Get:15 http://ftpmaster.internal/ubuntu noble/main armhf cpp-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [8759 kB] 188s Get:16 http://ftpmaster.internal/ubuntu noble/main armhf cpp-13 armhf 13.2.0-23ubuntu4 [1034 B] 188s Get:17 http://ftpmaster.internal/ubuntu noble/main armhf cpp-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [5320 B] 188s Get:18 http://ftpmaster.internal/ubuntu noble/main armhf cpp armhf 4:13.2.0-7ubuntu1 [22.4 kB] 188s Get:19 http://ftpmaster.internal/ubuntu noble/main armhf libcc1-0 armhf 14-20240412-0ubuntu1 [39.0 kB] 188s Get:20 http://ftpmaster.internal/ubuntu noble/main armhf libgomp1 armhf 14-20240412-0ubuntu1 [125 kB] 188s Get:21 http://ftpmaster.internal/ubuntu noble/main armhf libatomic1 armhf 14-20240412-0ubuntu1 [7816 B] 188s Get:22 http://ftpmaster.internal/ubuntu noble/main armhf libasan8 armhf 14-20240412-0ubuntu1 [2942 kB] 189s Get:23 http://ftpmaster.internal/ubuntu noble/main armhf libubsan1 armhf 14-20240412-0ubuntu1 [1154 kB] 189s Get:24 http://ftpmaster.internal/ubuntu noble/main armhf libgcc-13-dev armhf 13.2.0-23ubuntu4 [899 kB] 189s Get:25 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [16.9 MB] 189s Get:26 http://ftpmaster.internal/ubuntu noble/main armhf gcc-13 armhf 13.2.0-23ubuntu4 [453 kB] 189s Get:27 http://ftpmaster.internal/ubuntu noble/main armhf gcc-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [1220 B] 189s Get:28 http://ftpmaster.internal/ubuntu noble/main armhf gcc armhf 4:13.2.0-7ubuntu1 [5022 B] 189s Get:29 http://ftpmaster.internal/ubuntu noble/main armhf libstdc++-13-dev armhf 13.2.0-23ubuntu4 [2456 kB] 189s Get:30 http://ftpmaster.internal/ubuntu noble/main armhf g++-13-arm-linux-gnueabihf armhf 13.2.0-23ubuntu4 [9941 kB] 189s Get:31 http://ftpmaster.internal/ubuntu noble/main armhf g++-13 armhf 13.2.0-23ubuntu4 [14.5 kB] 189s Get:32 http://ftpmaster.internal/ubuntu noble/main armhf g++-arm-linux-gnueabihf armhf 4:13.2.0-7ubuntu1 [966 B] 189s Get:33 http://ftpmaster.internal/ubuntu noble/main armhf g++ armhf 4:13.2.0-7ubuntu1 [1090 B] 189s Get:34 http://ftpmaster.internal/ubuntu noble/main armhf build-essential armhf 12.10ubuntu1 [4928 B] 189s Get:35 http://ftpmaster.internal/ubuntu noble/main armhf libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 189s Get:36 http://ftpmaster.internal/ubuntu noble/main armhf libtool all 2.4.7-7build1 [166 kB] 189s Get:37 http://ftpmaster.internal/ubuntu noble/main armhf dh-autoreconf all 20 [16.1 kB] 189s Get:38 http://ftpmaster.internal/ubuntu noble/main armhf libarchive-zip-perl all 1.68-1 [90.2 kB] 189s Get:39 http://ftpmaster.internal/ubuntu noble/main armhf libsub-override-perl all 0.10-1 [10.0 kB] 189s Get:40 http://ftpmaster.internal/ubuntu noble/main armhf libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 189s Get:41 http://ftpmaster.internal/ubuntu noble/main armhf dh-strip-nondeterminism all 1.13.1-1 [5362 B] 189s Get:42 http://ftpmaster.internal/ubuntu noble/main armhf libdw1t64 armhf 0.190-1.1build4 [235 kB] 189s Get:43 http://ftpmaster.internal/ubuntu noble/main armhf debugedit armhf 1:5.0-5build2 [42.3 kB] 189s Get:44 http://ftpmaster.internal/ubuntu noble/main armhf dwz armhf 0.15-1build6 [116 kB] 189s Get:45 http://ftpmaster.internal/ubuntu noble/main armhf gettext armhf 0.21-14ubuntu2 [800 kB] 189s Get:46 http://ftpmaster.internal/ubuntu noble/main armhf intltool-debian all 0.35.0+20060710.6 [23.2 kB] 189s Get:47 http://ftpmaster.internal/ubuntu noble/main armhf po-debconf all 1.0.21+nmu1 [233 kB] 189s Get:48 http://ftpmaster.internal/ubuntu noble/main armhf debhelper all 13.14.1ubuntu5 [869 kB] 189s Get:49 http://ftpmaster.internal/ubuntu noble-updates/universe armhf dh-apport all 2.28.1-0ubuntu3 [17.2 kB] 189s Get:50 http://ftpmaster.internal/ubuntu noble-updates/main armhf golang-1.22-src all 1.22.2-2ubuntu0.1 [19.7 MB] 190s Get:51 http://ftpmaster.internal/ubuntu noble-updates/main armhf golang-1.22-go armhf 1.22.2-2ubuntu0.1 [23.7 MB] 191s Get:52 http://ftpmaster.internal/ubuntu noble/main armhf golang-src all 2:1.22~2build1 [5078 B] 191s Get:53 http://ftpmaster.internal/ubuntu noble/main armhf golang-go armhf 2:1.22~2build1 [43.9 kB] 191s Get:54 http://ftpmaster.internal/ubuntu noble/main armhf dh-golang all 1.62 [25.2 kB] 191s Fetched 95.3 MB in 3s (29.4 MB/s) 191s Selecting previously unselected package m4. 191s (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 ... 57913 files and directories currently installed.) 191s Preparing to unpack .../00-m4_1.4.19-4build1_armhf.deb ... 191s Unpacking m4 (1.4.19-4build1) ... 191s Selecting previously unselected package autoconf. 191s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 191s Unpacking autoconf (2.71-3) ... 191s Selecting previously unselected package autotools-dev. 191s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 191s Unpacking autotools-dev (20220109.1) ... 191s Selecting previously unselected package automake. 191s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 191s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 191s Selecting previously unselected package autopoint. 191s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 191s Unpacking autopoint (0.21-14ubuntu2) ... 191s Selecting previously unselected package libc-dev-bin. 191s Preparing to unpack .../05-libc-dev-bin_2.39-0ubuntu8.2_armhf.deb ... 191s Unpacking libc-dev-bin (2.39-0ubuntu8.2) ... 191s Selecting previously unselected package linux-libc-dev:armhf. 191s Preparing to unpack .../06-linux-libc-dev_6.8.0-38.38_armhf.deb ... 191s Unpacking linux-libc-dev:armhf (6.8.0-38.38) ... 191s Selecting previously unselected package libcrypt-dev:armhf. 191s Preparing to unpack .../07-libcrypt-dev_1%3a4.4.36-4build1_armhf.deb ... 191s Unpacking libcrypt-dev:armhf (1:4.4.36-4build1) ... 191s Selecting previously unselected package rpcsvc-proto. 191s Preparing to unpack .../08-rpcsvc-proto_1.4.2-0ubuntu7_armhf.deb ... 191s Unpacking rpcsvc-proto (1.4.2-0ubuntu7) ... 192s Selecting previously unselected package libc6-dev:armhf. 192s Preparing to unpack .../09-libc6-dev_2.39-0ubuntu8.2_armhf.deb ... 192s Unpacking libc6-dev:armhf (2.39-0ubuntu8.2) ... 192s Selecting previously unselected package gcc-13-base:armhf. 192s Preparing to unpack .../10-gcc-13-base_13.2.0-23ubuntu4_armhf.deb ... 192s Unpacking gcc-13-base:armhf (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package libisl23:armhf. 192s Preparing to unpack .../11-libisl23_0.26-3build1_armhf.deb ... 192s Unpacking libisl23:armhf (0.26-3build1) ... 192s Selecting previously unselected package libmpc3:armhf. 192s Preparing to unpack .../12-libmpc3_1.3.1-1build1_armhf.deb ... 192s Unpacking libmpc3:armhf (1.3.1-1build1) ... 192s Selecting previously unselected package cpp-13-arm-linux-gnueabihf. 192s Preparing to unpack .../13-cpp-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 192s Unpacking cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package cpp-13. 192s Preparing to unpack .../14-cpp-13_13.2.0-23ubuntu4_armhf.deb ... 192s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package cpp-arm-linux-gnueabihf. 192s Preparing to unpack .../15-cpp-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 192s Unpacking cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 192s Selecting previously unselected package cpp. 192s Preparing to unpack .../16-cpp_4%3a13.2.0-7ubuntu1_armhf.deb ... 192s Unpacking cpp (4:13.2.0-7ubuntu1) ... 192s Selecting previously unselected package libcc1-0:armhf. 192s Preparing to unpack .../17-libcc1-0_14-20240412-0ubuntu1_armhf.deb ... 192s Unpacking libcc1-0:armhf (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libgomp1:armhf. 192s Preparing to unpack .../18-libgomp1_14-20240412-0ubuntu1_armhf.deb ... 192s Unpacking libgomp1:armhf (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libatomic1:armhf. 192s Preparing to unpack .../19-libatomic1_14-20240412-0ubuntu1_armhf.deb ... 192s Unpacking libatomic1:armhf (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libasan8:armhf. 192s Preparing to unpack .../20-libasan8_14-20240412-0ubuntu1_armhf.deb ... 192s Unpacking libasan8:armhf (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libubsan1:armhf. 192s Preparing to unpack .../21-libubsan1_14-20240412-0ubuntu1_armhf.deb ... 192s Unpacking libubsan1:armhf (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libgcc-13-dev:armhf. 192s Preparing to unpack .../22-libgcc-13-dev_13.2.0-23ubuntu4_armhf.deb ... 192s Unpacking libgcc-13-dev:armhf (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package gcc-13-arm-linux-gnueabihf. 192s Preparing to unpack .../23-gcc-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 192s Unpacking gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package gcc-13. 193s Preparing to unpack .../24-gcc-13_13.2.0-23ubuntu4_armhf.deb ... 193s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package gcc-arm-linux-gnueabihf. 193s Preparing to unpack .../25-gcc-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 193s Unpacking gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package gcc. 193s Preparing to unpack .../26-gcc_4%3a13.2.0-7ubuntu1_armhf.deb ... 193s Unpacking gcc (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package libstdc++-13-dev:armhf. 193s Preparing to unpack .../27-libstdc++-13-dev_13.2.0-23ubuntu4_armhf.deb ... 193s Unpacking libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-13-arm-linux-gnueabihf. 193s Preparing to unpack .../28-g++-13-arm-linux-gnueabihf_13.2.0-23ubuntu4_armhf.deb ... 193s Unpacking g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-13. 193s Preparing to unpack .../29-g++-13_13.2.0-23ubuntu4_armhf.deb ... 193s Unpacking g++-13 (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-arm-linux-gnueabihf. 193s Preparing to unpack .../30-g++-arm-linux-gnueabihf_4%3a13.2.0-7ubuntu1_armhf.deb ... 193s Unpacking g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package g++. 193s Preparing to unpack .../31-g++_4%3a13.2.0-7ubuntu1_armhf.deb ... 193s Unpacking g++ (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package build-essential. 193s Preparing to unpack .../32-build-essential_12.10ubuntu1_armhf.deb ... 193s Unpacking build-essential (12.10ubuntu1) ... 193s Selecting previously unselected package libdebhelper-perl. 193s Preparing to unpack .../33-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 193s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 193s Selecting previously unselected package libtool. 193s Preparing to unpack .../34-libtool_2.4.7-7build1_all.deb ... 193s Unpacking libtool (2.4.7-7build1) ... 194s Selecting previously unselected package dh-autoreconf. 194s Preparing to unpack .../35-dh-autoreconf_20_all.deb ... 194s Unpacking dh-autoreconf (20) ... 194s Selecting previously unselected package libarchive-zip-perl. 194s Preparing to unpack .../36-libarchive-zip-perl_1.68-1_all.deb ... 194s Unpacking libarchive-zip-perl (1.68-1) ... 194s Selecting previously unselected package libsub-override-perl. 194s Preparing to unpack .../37-libsub-override-perl_0.10-1_all.deb ... 194s Unpacking libsub-override-perl (0.10-1) ... 194s Selecting previously unselected package libfile-stripnondeterminism-perl. 194s Preparing to unpack .../38-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 194s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 194s Selecting previously unselected package dh-strip-nondeterminism. 194s Preparing to unpack .../39-dh-strip-nondeterminism_1.13.1-1_all.deb ... 194s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 194s Selecting previously unselected package libdw1t64:armhf. 194s Preparing to unpack .../40-libdw1t64_0.190-1.1build4_armhf.deb ... 194s Unpacking libdw1t64:armhf (0.190-1.1build4) ... 194s Selecting previously unselected package debugedit. 194s Preparing to unpack .../41-debugedit_1%3a5.0-5build2_armhf.deb ... 194s Unpacking debugedit (1:5.0-5build2) ... 194s Selecting previously unselected package dwz. 194s Preparing to unpack .../42-dwz_0.15-1build6_armhf.deb ... 194s Unpacking dwz (0.15-1build6) ... 194s Selecting previously unselected package gettext. 194s Preparing to unpack .../43-gettext_0.21-14ubuntu2_armhf.deb ... 194s Unpacking gettext (0.21-14ubuntu2) ... 194s Selecting previously unselected package intltool-debian. 194s Preparing to unpack .../44-intltool-debian_0.35.0+20060710.6_all.deb ... 194s Unpacking intltool-debian (0.35.0+20060710.6) ... 194s Selecting previously unselected package po-debconf. 194s Preparing to unpack .../45-po-debconf_1.0.21+nmu1_all.deb ... 194s Unpacking po-debconf (1.0.21+nmu1) ... 194s Selecting previously unselected package debhelper. 194s Preparing to unpack .../46-debhelper_13.14.1ubuntu5_all.deb ... 194s Unpacking debhelper (13.14.1ubuntu5) ... 194s Selecting previously unselected package dh-apport. 194s Preparing to unpack .../47-dh-apport_2.28.1-0ubuntu3_all.deb ... 194s Unpacking dh-apport (2.28.1-0ubuntu3) ... 194s Selecting previously unselected package golang-1.22-src. 194s Preparing to unpack .../48-golang-1.22-src_1.22.2-2ubuntu0.1_all.deb ... 194s Unpacking golang-1.22-src (1.22.2-2ubuntu0.1) ... 198s Selecting previously unselected package golang-1.22-go. 198s Preparing to unpack .../49-golang-1.22-go_1.22.2-2ubuntu0.1_armhf.deb ... 198s Unpacking golang-1.22-go (1.22.2-2ubuntu0.1) ... 202s Selecting previously unselected package golang-src. 202s Preparing to unpack .../50-golang-src_2%3a1.22~2build1_all.deb ... 202s Unpacking golang-src (2:1.22~2build1) ... 202s Selecting previously unselected package golang-go:armhf. 202s Preparing to unpack .../51-golang-go_2%3a1.22~2build1_armhf.deb ... 202s Unpacking golang-go:armhf (2:1.22~2build1) ... 202s Selecting previously unselected package dh-golang. 203s Preparing to unpack .../52-dh-golang_1.62_all.deb ... 203s Unpacking dh-golang (1.62) ... 203s Selecting previously unselected package autopkgtest-satdep. 203s Preparing to unpack .../53-1-autopkgtest-satdep.deb ... 203s Unpacking autopkgtest-satdep (0) ... 203s Setting up libarchive-zip-perl (1.68-1) ... 203s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 203s Setting up linux-libc-dev:armhf (6.8.0-38.38) ... 203s Setting up m4 (1.4.19-4build1) ... 203s Setting up libgomp1:armhf (14-20240412-0ubuntu1) ... 203s Setting up dh-apport (2.28.1-0ubuntu3) ... 203s Setting up libdw1t64:armhf (0.190-1.1build4) ... 203s Setting up autotools-dev (20220109.1) ... 203s Setting up rpcsvc-proto (1.4.2-0ubuntu7) ... 203s Setting up gcc-13-base:armhf (13.2.0-23ubuntu4) ... 203s Setting up golang-1.22-src (1.22.2-2ubuntu0.1) ... 203s Setting up libmpc3:armhf (1.3.1-1build1) ... 203s Setting up libatomic1:armhf (14-20240412-0ubuntu1) ... 203s Setting up autopoint (0.21-14ubuntu2) ... 203s Setting up autoconf (2.71-3) ... 203s Setting up libubsan1:armhf (14-20240412-0ubuntu1) ... 203s Setting up dwz (0.15-1build6) ... 203s Setting up libcrypt-dev:armhf (1:4.4.36-4build1) ... 203s Setting up libasan8:armhf (14-20240412-0ubuntu1) ... 203s Setting up debugedit (1:5.0-5build2) ... 203s Setting up libsub-override-perl (0.10-1) ... 203s Setting up libisl23:armhf (0.26-3build1) ... 203s Setting up libc-dev-bin (2.39-0ubuntu8.2) ... 203s Setting up golang-src (2:1.22~2build1) ... 203s Setting up libcc1-0:armhf (14-20240412-0ubuntu1) ... 203s Setting up automake (1:1.16.5-1.3ubuntu1) ... 203s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 203s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 203s Setting up gettext (0.21-14ubuntu2) ... 203s Setting up cpp-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 203s Setting up golang-1.22-go (1.22.2-2ubuntu0.1) ... 203s Setting up intltool-debian (0.35.0+20060710.6) ... 203s Setting up dh-strip-nondeterminism (1.13.1-1) ... 203s Setting up libgcc-13-dev:armhf (13.2.0-23ubuntu4) ... 203s Setting up libc6-dev:armhf (2.39-0ubuntu8.2) ... 203s Setting up cpp-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 203s Setting up libstdc++-13-dev:armhf (13.2.0-23ubuntu4) ... 203s Setting up cpp-13 (13.2.0-23ubuntu4) ... 203s Setting up golang-go:armhf (2:1.22~2build1) ... 203s Setting up po-debconf (1.0.21+nmu1) ... 203s Setting up gcc-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 203s Setting up gcc-13 (13.2.0-23ubuntu4) ... 203s Setting up cpp (4:13.2.0-7ubuntu1) ... 203s Setting up gcc-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 203s Setting up g++-13-arm-linux-gnueabihf (13.2.0-23ubuntu4) ... 203s Setting up g++-arm-linux-gnueabihf (4:13.2.0-7ubuntu1) ... 203s Setting up g++-13 (13.2.0-23ubuntu4) ... 203s Setting up libtool (2.4.7-7build1) ... 203s Setting up gcc (4:13.2.0-7ubuntu1) ... 203s Setting up dh-autoreconf (20) ... 203s Setting up g++ (4:13.2.0-7ubuntu1) ... 203s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 203s Setting up build-essential (12.10ubuntu1) ... 203s Setting up debhelper (13.14.1ubuntu5) ... 203s Setting up dh-golang (1.62) ... 203s Setting up autopkgtest-satdep (0) ... 203s Processing triggers for man-db (2.12.0-4build2) ... 205s Processing triggers for install-info (7.1-3build2) ... 205s Processing triggers for libc-bin (2.39-0ubuntu8.2) ... 217s (Reading database ... 76053 files and directories currently installed.) 217s Removing autopkgtest-satdep (0) ... 226s autopkgtest [14:39:37]: test command1: ./debian/tests/test 226s autopkgtest [14:39:37]: test command1: [----------------------- 269s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 269s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 269s === RUN TestRunSignal 269s === RUN TestRunSignal/Send_SIGINT_exits 269s INFO Starting WSL Pro Service version Dev 269s === RUN TestRunSignal/Send_SIGTERM_exits 269s INFO Starting WSL Pro Service version Dev 269s --- PASS: TestRunSignal (0.20s) 269s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 269s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 269s === RUN TestRun 269s === PAUSE TestRun 269s === CONT TestRun 269s === RUN TestRun/Run_and_usage_error_only_does_not_fail 269s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 269s === RUN TestRun/Run_and_exit_successfully 269s === PAUSE TestRun/Run_and_exit_successfully 269s === RUN TestRun/Run_and_return_error 269s === PAUSE TestRun/Run_and_return_error 269s === RUN TestRun/Run_and_return_usage_error 269s === PAUSE TestRun/Run_and_return_usage_error 269s === CONT TestRun/Run_and_usage_error_only_does_not_fail 269s === CONT TestRun/Run_and_return_error 269s === CONT TestRun/Run_and_return_usage_error 269s === CONT TestRun/Run_and_exit_successfully 269s INFO Starting WSL Pro Service version Dev 269s INFO Starting WSL Pro Service version Dev 269s INFO Starting WSL Pro Service version Dev 269s INFO Starting WSL Pro Service version Dev 269s ERROR context.Background Error requested 269s ERROR context.Background Error requested 269s --- PASS: TestRun (0.00s) 269s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 269s --- PASS: TestRun/Run_and_return_error (0.10s) 269s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 269s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 269s PASS 269s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.439s 271s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 311s === RUN TestHelp 311s --- PASS: TestHelp (0.01s) 311s === RUN TestCompletion 311s --- PASS: TestCompletion (0.00s) 311s === RUN TestVersion 311s --- PASS: TestVersion (0.00s) 311s === RUN TestNoUsageError 311s --- PASS: TestNoUsageError (0.00s) 311s === RUN TestUsageError 311s === PAUSE TestUsageError 311s === RUN TestCanQuitWhenExecute 311s === PAUSE TestCanQuitWhenExecute 311s === RUN TestCanQuitTwice 311s === PAUSE TestCanQuitTwice 311s === RUN TestAppCanQuitWithoutExecute 311s === PAUSE TestAppCanQuitWithoutExecute 311s === RUN TestAppRunFailsOnComponentsCreationAndQuit 311s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 311s === RUN TestAppGetRootCmd 311s === PAUSE TestAppGetRootCmd 311s === RUN TestWithProMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithProMock (0.00s) 311s === RUN TestWithWslPathMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithWslPathMock (0.00s) 311s === RUN TestWithWslInfoMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithWslInfoMock (0.00s) 311s === RUN TestWithCmdExeMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithCmdExeMock (0.00s) 311s === CONT TestUsageError 311s --- PASS: TestUsageError (0.00s) 311s === CONT TestAppGetRootCmd 311s --- PASS: TestAppGetRootCmd (0.00s) 311s === CONT TestAppRunFailsOnComponentsCreationAndQuit 311s === CONT TestCanQuitTwice 311s === CONT TestCanQuitWhenExecute 311s === CONT TestAppCanQuitWithoutExecute 311s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 311s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 311s time="2024-07-15T14:40:20Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 311s time="2024-07-15T14:40:20Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:75 New() Building new daemon" 311s time="2024-07-15T14:40:20Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40513" 311s time="2024-07-15T14:40:20Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 311s time="2024-07-15T14:40:20Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:75 New() Building new daemon" 311s time="2024-07-15T14:40:47Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 311s time="2024-07-15T14:40:47Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 311s time="2024-07-15T14:40:47Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:40:47Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:40:51Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 311s time="2024-07-15T14:40:52Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:40:52Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:40:56Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:37185" 311s time="2024-07-15T14:40:56Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 311s time="2024-07-15T14:40:56Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 311s time="2024-07-15T14:40:56Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 311s time="2024-07-15T14:40:57Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:40:57Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:40:57Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (36.70s) 311s time="2024-07-15T14:41:00Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:45281" 311s time="2024-07-15T14:41:00Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 311s time="2024-07-15T14:41:00Z" level=warning msg="/tmp/autopkgtest.O1nfeX/build.mlo/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:45281: connect: connection refused\"" 311s time="2024-07-15T14:41:00Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 311s time="2024-07-15T14:41:00Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s time="2024-07-15T14:41:00Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:41:00Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:41:00Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s --- PASS: TestCanQuitWhenExecute (40.09s) 311s time="2024-07-15T14:41:02Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 311s time="2024-07-15T14:41:02Z" level=warning msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: serve error: could not receive ProAttachCmd: context canceled" 311s time="2024-07-15T14:41:02Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 311s time="2024-07-15T14:41:02Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s time="2024-07-15T14:41:02Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:41:02Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:41:02Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s time="2024-07-15T14:41:02Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.O1nfeX/build.mlo/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 311s time="2024-07-15T14:41:02Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.O1nfeX/build.mlo/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 311s time="2024-07-15T14:41:02Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.O1nfeX/build.mlo/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 311s time="2024-07-15T14:41:02Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 311s time="2024-07-15T14:41:02Z" level=info msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 311s time="2024-07-15T14:41:02Z" level=debug msg="/tmp/autopkgtest.O1nfeX/build.mlo/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 311s --- PASS: TestCanQuitTwice (41.75s) 311s PASS 311s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 42.088s 311s === RUN TestApplyProToken 311s === PAUSE TestApplyProToken 311s === RUN TestApplyLandscapeConfig 311s === PAUSE TestApplyLandscapeConfig 311s === RUN TestWithProMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithProMock (0.00s) 311s === RUN TestWithLandscapeConfigMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithLandscapeConfigMock (0.00s) 311s === RUN TestWithWslPathMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithWslPathMock (0.00s) 311s === RUN TestWithWslInfoMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithWslInfoMock (0.00s) 311s === RUN TestWithCmdExeMock 311s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 311s --- SKIP: TestWithCmdExeMock (0.00s) 311s === CONT TestApplyProToken 311s === RUN TestApplyProToken/Success_attaching 311s === PAUSE TestApplyProToken/Success_attaching 311s === RUN TestApplyProToken/Success_detaching 311s === PAUSE TestApplyProToken/Success_detaching 311s === RUN TestApplyProToken/Error_calling_pro_detach 311s === PAUSE TestApplyProToken/Error_calling_pro_detach 311s === RUN TestApplyProToken/Error_calling_pro_attach 311s === PAUSE TestApplyProToken/Error_calling_pro_attach 311s === CONT TestApplyProToken/Success_attaching 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 311s === CONT TestApplyProToken/Error_calling_pro_attach 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 311s === CONT TestApplyProToken/Error_calling_pro_detach 311s === CONT TestApplyLandscapeConfig 311s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 311s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 311s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 311s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 311s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 311s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 311s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 311s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 311s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 311s === CONT TestApplyProToken/Success_detaching 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyLandscapeConfig: received config: registering" 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyProToken: Received empty token: detaching" 311s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 311s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 311s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 311s time="2024-07-15T14:40:20Z" level=info msg="ApplyLandscapeConfig: received config: registering" 311s --- PASS: TestApplyLandscapeConfig (0.00s) 311s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (8.61s) 311s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (9.10s) 311s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (20.90s) 311s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (23.56s) 311s --- PASS: TestApplyProToken (0.00s) 311s --- PASS: TestApplyProToken/Error_calling_pro_detach (14.43s) 311s --- PASS: TestApplyProToken/Success_detaching (21.83s) 311s --- PASS: TestApplyProToken/Success_attaching (23.38s) 311s --- PASS: TestApplyProToken/Error_calling_pro_attach (33.75s) 311s PASS 311s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 33.998s 386s === RUN TestNew 386s === PAUSE TestNew 386s === RUN TestServe 386s === PAUSE TestServe 386s === RUN TestServeAndQuit 386s === PAUSE TestServeAndQuit 386s === RUN TestReconnection 386s === PAUSE TestReconnection 386s === RUN TestWithProMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithProMock (0.00s) 386s === RUN TestWithWslPathMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslPathMock (0.00s) 386s === RUN TestWithWslInfoMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslInfoMock (0.00s) 386s === RUN TestWithCmdExeMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithCmdExeMock (0.00s) 386s === CONT TestNew 386s === CONT TestServeAndQuit 386s === CONT TestServe 386s === RUN TestNew/Success 386s === PAUSE TestNew/Success 386s === RUN TestNew/Error_when_WslPath_returns_error 386s === PAUSE TestNew/Error_when_WslPath_returns_error 386s === CONT TestNew/Success 386s === CONT TestReconnection 386s === RUN TestReconnection/Success_connecting_after_failing_to_connect 386s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 386s === CONT TestNew/Error_when_WslPath_returns_error 386s === RUN TestServeAndQuit/Success_with_graceful_quit 386s === PAUSE TestServeAndQuit/Success_with_graceful_quit 386s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 386s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 386s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 386s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 386s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 386s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 386s === RUN TestServe/No_connection_because_the_port_file_has_port_0 386s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 386s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 386s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 386s === CONT TestReconnection/Success_connecting_after_failing_to_connect 386s === RUN TestServeAndQuit/Success_with_forceful_quit 386s === PAUSE TestServeAndQuit/Success_with_forceful_quit 386s === RUN TestServeAndQuit/Success_with_double_quit 386s === PAUSE TestServeAndQuit/Success_with_double_quit 386s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 386s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 386s === CONT TestServeAndQuit/Success_with_graceful_quit 386s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 386s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 386s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 386s === RUN TestServe/No_connection_because_there_is_no_server 386s === PAUSE TestServe/No_connection_because_there_is_no_server 386s === RUN TestServe/No_connection_because_there_are_no_certificates 386s === PAUSE TestServe/No_connection_because_there_are_no_certificates 386s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 386s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 386s === RUN TestServe/Success_with_systemd_notifier_returning_true 386s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 386s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 386s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 386s === RUN TestServe/Error_because_the_context_is_pre-cancelled 386s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 386s === RUN TestServe/No_connection_because_the_port_file_is_empty 386s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 386s === RUN TestServe/Error_because_the_notifier_returns_an_error 386s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 386s === RUN TestServe/Success 386s === PAUSE TestServe/Success 386s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 386s === CONT TestServeAndQuit/Success_with_double_quit 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43555" 386s time="2024-07-15T14:40:20Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44539" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:20Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34049" 386s time="2024-07-15T14:40:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:42Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:40:42Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:42Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s === CONT TestServeAndQuit/Success_with_forceful_quit 386s time="2024-07-15T14:40:47Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43895" 386s time="2024-07-15T14:40:47Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:48Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:40:48Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:48Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:40:48Z" 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_connect3605793852/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3605793852/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 386s time="2024-07-15T14:40:48Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:40:48Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:40:49Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:40:49Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:40:49Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:40:49Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:40:49Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:40:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44521" 386s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 386s time="2024-07-15T14:40:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38323" 386s time="2024-07-15T14:40:49Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:49Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:49Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:40:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46045" 386s time="2024-07-15T14:40:49Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:40:49Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:49Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:40:50Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:40:50Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:50Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:40:50Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34049" 386s time="2024-07-15T14:40:50Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:40:50Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:40:50Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:40:50Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:40:52Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38777" 386s time="2024-07-15T14:40:52Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:40:52Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:40:52Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s --- PASS: TestNew (0.00s) 386s --- PASS: TestNew/Error_when_WslPath_returns_error (26.97s) 386s --- PASS: TestNew/Success (32.65s) 386s === CONT TestServe/Success_with_systemd_notifier_returning_true 386s time="2024-07-15T14:40:53Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45065" 386s time="2024-07-15T14:40:53Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:40:56Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44521" 386s time="2024-07-15T14:40:56Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:40:56Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:40:56Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:40:56Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:40:57Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43555" 386s time="2024-07-15T14:40:57Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:40:57Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:40:57Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:40:57Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:40:59Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:40:59Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:40:59Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:40:59Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:40:59Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:40:59Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:40:59Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:40:59Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:40:59Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:40:59Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:40:59Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:59Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:40:59Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:40:59Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/Success 386s time="2024-07-15T14:40:59Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38777" 386s time="2024-07-15T14:40:59Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:40:59Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:40:59Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:40:59Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:40:59Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45035" 386s time="2024-07-15T14:40:59Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:00Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46045" 386s time="2024-07-15T14:41:00Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:00Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:41:00Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:41:00Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:41:00Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:41:00Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:00Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:41:03Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:03Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:03Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:03Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:03Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:03Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:03Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:03Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:03Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:03Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:03Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:03Z" level=info msg="Stopping active requests." 386s time="2024-07-15T14:41:03Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:41:03Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/Error_because_the_notifier_returns_an_error 386s time="2024-07-15T14:41:03Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44375" 386s time="2024-07-15T14:41:03Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:04Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:04Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:04Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:04Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:04Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:04Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:04Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:04Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:04Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:04Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:41:04Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:04Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:04Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:04Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s === CONT TestServe/No_connection_because_the_port_file_is_empty 386s time="2024-07-15T14:41:05Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41693" 386s time="2024-07-15T14:41:05Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:05Z" level=debug msg="Ready state sent to systemd" 386s time="2024-07-15T14:41:05Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:05Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:41:05Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:05Z" 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_exist317931114/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist317931114/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 386s time="2024-07-15T14:41:05Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:06Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:06Z" 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_exist317931114/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist317931114/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 386s time="2024-07-15T14:41:06Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:06Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:06Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:06Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/Error_because_the_context_is_pre-cancelled 386s time="2024-07-15T14:41:06Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37115" 386s time="2024-07-15T14:41:06Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:07Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:07Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:07Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:07Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:07Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:07Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:07Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:07Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:07Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:07Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:08Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33605" 386s time="2024-07-15T14:41:08Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43895" 386s time="2024-07-15T14:41:08Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:08Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:41:08Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:41:08Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:41:08Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:08Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:08Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:08Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:08Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:08Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:41:11Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45065" 386s time="2024-07-15T14:41:11Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:11Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:41:11Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:41:11Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:41:12Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:14Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33605" 386s time="2024-07-15T14:41:14Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:14Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:41:14Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:41:14Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:41:14Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:14Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:14Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:14Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:14Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:14Z" level=info msg="Stopping active requests." 386s time="2024-07-15T14:41:14Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:14Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:14Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:14Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:41:14Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:14Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:14Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:14Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s --- PASS: TestServeAndQuit (0.00s) 386s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (29.03s) 386s --- PASS: TestServeAndQuit/Success_with_double_quit (38.85s) 386s --- PASS: TestServeAndQuit/Success_with_graceful_quit (44.39s) 386s --- PASS: TestServeAndQuit/Success_with_forceful_quit (26.81s) 386s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 386s time="2024-07-15T14:41:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36123" 386s time="2024-07-15T14:41:14Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:15Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 386s time="2024-07-15T14:41:15Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:15Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:15Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/No_connection_because_there_is_no_server 386s time="2024-07-15T14:41:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38079" 386s time="2024-07-15T14:41:15Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:15Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:15Z" 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" 386s time="2024-07-15T14:41:15Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:15Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45035" 386s time="2024-07-15T14:41:15Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:15Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:41:15Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:41:16Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:16Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:16Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:16Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:16Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:16Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:16Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 386s time="2024-07-15T14:41:16Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40411" 386s time="2024-07-15T14:41:16Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:16Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:16Z" 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" 386s time="2024-07-15T14:41:16Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:17Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:17Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:17Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/No_connection_because_there_are_no_certificates 386s time="2024-07-15T14:41:17Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46595" 386s time="2024-07-15T14:41:17Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:18Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:18Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:18Z" level=info msg="Stopping active requests." 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:18Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:18Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:18Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:18Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:41:18Z" level=debug msg="All connections have now ended." 386s === CONT TestServe/No_connection_because_the_port_file_has_port_0 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45727" 386s time="2024-07-15T14:41:18Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:18Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:18Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:18Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:18Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:18Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:41:18Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:41:18Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:18Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43265" 386s time="2024-07-15T14:41:18Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:18Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:41:18Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:41:20Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:20Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:20Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:41:20Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:20Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:20Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:20Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:41:20Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 386s time="2024-07-15T14:41:20Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:32797" 386s time="2024-07-15T14:41:20Z" level=debug msg="Building new daemon" 386s time="2024-07-15T14:41:20Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:21Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:21Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:22Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:22Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:22Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:22Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:22Z" 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" 386s time="2024-07-15T14:41:22Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:22Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:22Z" 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" 386s time="2024-07-15T14:41:22Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:22Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:23Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40411" 386s time="2024-07-15T14:41:23Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file3927496940/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 386s time="2024-07-15T14:41:23Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:23Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38079" 386s time="2024-07-15T14:41:23Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:41:23Z" level=warning msg="Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:38079: connect: connection refused\"" 386s time="2024-07-15T14:41:23Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:23Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:23Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:23Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:23Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:23Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:23Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:23Z" 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" 386s time="2024-07-15T14:41:23Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:23Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:24Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:24Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:24Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:24Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:24Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:24Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:24Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:24Z" 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" 386s time="2024-07-15T14:41:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:24Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46595" 386s time="2024-07-15T14:41:24Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates3431720075/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 386s time="2024-07-15T14:41:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:41:24Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:24Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:24Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:41:25Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:41:25Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:41:25Z" level=info msg="Waiting for active requests to close." 386s time="2024-07-15T14:41:25Z" 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" 386s time="2024-07-15T14:41:25Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:41:25Z" level=debug msg="All connections have now ended." 386s --- PASS: TestServe (0.00s) 386s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (17.09s) 386s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (12.25s) 386s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (9.84s) 386s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (12.71s) 386s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (25.13s) 386s --- PASS: TestServe/Success (20.73s) 386s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (8.52s) 386s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (5.55s) 386s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (5.65s) 386s --- PASS: TestServe/No_connection_because_there_is_no_server (8.91s) 386s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (7.90s) 386s --- PASS: TestServe/No_connection_because_there_are_no_certificates (7.27s) 386s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (5.48s) 386s time="2024-07-15T14:42:13Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:42:13Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:42:13Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:42:13Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:42:13Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:42:13Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:42:13Z" 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_dropped3619667631/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3619667631/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 386s time="2024-07-15T14:42:13Z" level=info msg="Reconnecting to Windows host in 1 seconds" 386s time="2024-07-15T14:42:13Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:42:13Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42243" 386s time="2024-07-15T14:42:14Z" level=info msg="Daemon: connecting to Windows Agent" 386s time="2024-07-15T14:42:14Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-15T14:42:15Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:42243" 386s time="2024-07-15T14:42:15Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-15T14:42:15Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-15T14:42:15Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-15T14:42:15Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 386s time="2024-07-15T14:42:17Z" level=debug msg="Server: sent preface messages to all streams" 386s time="2024-07-15T14:42:17Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:42:17Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:42:17Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:42:17Z" level=info msg="Stopping daemon requested." 386s time="2024-07-15T14:42:17Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:42:17Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:42:17Z" level=info msg="Stopping active requests." 386s time="2024-07-15T14:42:17Z" level=warning msg="Daemon: disconnected from Windows host" 386s time="2024-07-15T14:42:17Z" level=info msg="Reconnecting to Windows host in 2 seconds" 386s time="2024-07-15T14:42:17Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 386s time="2024-07-15T14:42:17Z" level=debug msg="Updated systemd status to \"Stopped\"" 386s time="2024-07-15T14:42:17Z" level=debug msg="All connections have now ended." 386s time="2024-07-15T14:42:17Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s --- PASS: TestReconnection (0.00s) 386s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (42.64s) 386s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (57.70s) 386s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (116.61s) 386s PASS 386s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 116.839s 386s === RUN TestConnect 386s === PAUSE TestConnect 386s === RUN TestSendAndRecv 386s --- PASS: TestSendAndRecv (0.42s) 386s === RUN TestServe 386s === PAUSE TestServe 386s === RUN TestStop 386s === PAUSE TestStop 386s === RUN TestWithProMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithProMock (0.00s) 386s === RUN TestWithWslPathMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslPathMock (0.00s) 386s === RUN TestWithWslInfoMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslInfoMock (0.00s) 386s === RUN TestWithCmdExeMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithCmdExeMock (0.00s) 386s === CONT TestConnect 386s === RUN TestConnect/Success 386s === PAUSE TestConnect/Success 386s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 386s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 386s === CONT TestStop 386s === CONT TestServe 386s === CONT TestConnect/Success 386s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 386s time="2024-07-15T14:40:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42059" 386s time="2024-07-15T14:40:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37979" 386s time="2024-07-15T14:40:35Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:40:35Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:40:35Z" level=info msg="MockWindowsAgent: Connected ready" 386s --- PASS: TestConnect (0.00s) 386s --- PASS: TestConnect/Success (0.31s) 386s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.02s) 386s time="2024-07-15T14:40:41Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 386s time="2024-07-15T14:40:41Z" level=info msg="MockWindowsAgent: Connected ready" 386s time="2024-07-15T14:40:41Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 386s time="2024-07-15T14:40:51Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:51Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:51Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s --- PASS: TestStop (30.49s) 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 386s time="2024-07-15T14:40:59Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 386s --- PASS: TestServe (38.45s) 386s PASS 386s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 39.098s 386s === RUN TestInfo 386s === PAUSE TestInfo 386s === RUN TestWslDistroName 386s === PAUSE TestWslDistroName 386s === RUN TestUserProfileDir 386s === PAUSE TestUserProfileDir 386s === RUN TestProStatus 386s === PAUSE TestProStatus 386s === RUN TestProAttach 386s === PAUSE TestProAttach 386s === RUN TestProDetach 386s === PAUSE TestProDetach 386s === RUN TestLandscapeEnable 386s === PAUSE TestLandscapeEnable 386s === RUN TestWindowsHostAddress 386s === PAUSE TestWindowsHostAddress 386s === RUN TestLandscapeDisable 386s === PAUSE TestLandscapeDisable 386s === RUN TestRealBackend 386s === PAUSE TestRealBackend 386s === RUN TestWithProMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithProMock (0.00s) 386s === RUN TestWithLandscapeConfigMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithLandscapeConfigMock (0.00s) 386s === RUN TestWithWslPathMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslPathMock (0.00s) 386s === RUN TestWithWslInfoMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithWslInfoMock (0.00s) 386s === RUN TestWithCmdExeMock 386s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 386s --- SKIP: TestWithCmdExeMock (0.00s) 386s === CONT TestInfo 386s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 386s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 386s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 386s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 386s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 386s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 386s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 386s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 386s === RUN TestInfo/Success 386s === PAUSE TestInfo/Success 386s === RUN TestInfo/Error_when_WslDistroName_fails 386s === PAUSE TestInfo/Error_when_WslDistroName_fails 386s === RUN TestInfo/Error_when_pro_status_command_fails 386s === PAUSE TestInfo/Error_when_pro_status_command_fails 386s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 386s === CONT TestUserProfileDir 386s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 386s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 386s === CONT TestLandscapeEnable 386s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 386s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 386s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 386s === CONT TestProDetach 386s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 386s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 386s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 386s === CONT TestProAttach 386s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 386s === RUN TestProAttach/success 386s === CONT TestRealBackend 386s === PAUSE TestProAttach/success 386s === RUN TestProAttach/error_on_'pro_attach'_error 386s === PAUSE TestProAttach/error_on_'pro_attach'_error 386s === CONT TestProAttach/success 386s === CONT TestWslDistroName 386s === CONT TestProStatus 386s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 386s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 386s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 386s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 386s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 386s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 386s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 386s === RUN TestWslDistroName/Success_using_wslpath 386s === PAUSE TestWslDistroName/Success_using_wslpath 386s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 386s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 386s === RUN TestProStatus/success_on_unattached_distro 386s === PAUSE TestProStatus/success_on_unattached_distro 386s === RUN TestProStatus/success_on_attached_distro 386s === PAUSE TestProStatus/success_on_attached_distro 386s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 386s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 386s === CONT TestLandscapeDisable 386s === RUN TestProStatus/error_on_'pro_attach'_error 386s === PAUSE TestProStatus/error_on_'pro_attach'_error 386s === RUN TestLandscapeDisable/Success 386s === PAUSE TestLandscapeDisable/Success 386s === RUN TestLandscapeEnable/Success_overriding_computer_title 386s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 386s === RUN TestProDetach/success_on_unattached_distro 386s === CONT TestWindowsHostAddress 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 386s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 386s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 386s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 386s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 386s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 386s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 386s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 386s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 386s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 386s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 386s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 386s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 386s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 386s === RUN TestLandscapeEnable/Success 386s === PAUSE TestLandscapeEnable/Success 386s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 386s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 386s === CONT TestInfo/Success 386s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 386s === RUN TestUserProfileDir/Error_on_cmd.exe_error 386s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 386s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 386s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 386s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 386s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 386s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 386s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 386s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 386s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 386s === RUN TestUserProfileDir/Error_on_wslpath_error 386s === PAUSE TestUserProfileDir/Error_on_wslpath_error 386s === CONT TestInfo/Error_when_pro_status_command_fails 386s === PAUSE TestProDetach/success_on_unattached_distro 386s === CONT TestInfo/Error_when_WslDistroName_fails 386s === RUN TestProDetach/success_on_attached_distro 386s === PAUSE TestProDetach/success_on_attached_distro 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 386s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 386s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 386s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 386s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 386s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 386s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 386s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 386s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 386s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 386s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 386s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 386s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 386s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 386s === RUN TestWindowsHostAddress/Success_without_NAT 386s === PAUSE TestWindowsHostAddress/Success_without_NAT 386s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 386s --- PASS: TestRealBackend (0.08s) 386s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 386s === CONT TestProAttach/error_on_'pro_attach'_error 386s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 386s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 386s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 386s === CONT TestWslDistroName/Success_using_wslpath 386s === CONT TestProStatus/success_on_unattached_distro 386s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 386s === CONT TestProStatus/success_on_attached_distro 386s === CONT TestProStatus/error_on_'pro_attach'_error 386s --- PASS: TestInfo (0.00s) 386s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (9.19s) 386s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (13.08s) 386s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (16.54s) 386s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (16.64s) 386s --- PASS: TestInfo/Error_when_WslDistroName_fails (17.66s) 386s --- PASS: TestInfo/Success (17.70s) 386s --- PASS: TestInfo/Error_when_pro_status_command_fails (17.89s) 386s === CONT TestLandscapeDisable/Success 386s --- PASS: TestProAttach (0.00s) 386s --- PASS: TestProAttach/success (17.21s) 386s --- PASS: TestProAttach/error_on_'pro_attach'_error (12.12s) 386s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 386s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 386s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 386s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 386s time="2024-07-15T14:40:50Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 386s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 386s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 386s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 386s --- PASS: TestWslDistroName (0.02s) 386s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.38s) 386s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (9.12s) 386s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (8.97s) 386s --- PASS: TestWslDistroName/Success_using_wslpath (10.38s) 386s --- PASS: TestProStatus (0.02s) 386s --- PASS: TestProStatus/success_on_unattached_distro (8.86s) 386s --- PASS: TestProStatus/success_on_attached_distro (8.54s) 386s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (8.63s) 386s --- PASS: TestProStatus/error_on_'pro_attach'_error (9.75s) 386s === CONT TestLandscapeEnable/Success_overriding_computer_title 386s time="2024-07-15T14:40:51Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 386s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 386s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 386s system_test.go:205: Removing default proc/mounts 386s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 386s time="2024-07-15T14:40:52Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 386s === CONT TestLandscapeEnable/Success 386s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 386s === CONT TestUserProfileDir/Error_on_cmd.exe_error 386s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 386s system_test.go:205: Removing default proc/mounts 386s --- PASS: TestLandscapeDisable (0.00s) 386s --- PASS: TestLandscapeDisable/Success (7.63s) 386s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (7.07s) 386s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 386s === NAME TestLandscapeEnable/Success_overriding_computer_title 386s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 386s === CONT TestUserProfileDir/Error_on_wslpath_error 386s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 386s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 386s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 386s === NAME TestLandscapeEnable/Success 386s system_test.go:456: testdata/TestLandscapeEnable/golden/success 386s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 386s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 386s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 386s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 386s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 386s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 386s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 386s === NAME TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 386s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 386s --- PASS: TestLandscapeEnable (0.05s) 386s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.34s) 386s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.63s) 386s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (5.85s) 386s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (6.37s) 386s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 386s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (6.53s) 386s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (8.18s) 386s --- PASS: TestLandscapeEnable/Success (5.97s) 386s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (7.06s) 386s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (15.96s) 386s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 386s === CONT TestProDetach/success_on_attached_distro 386s === CONT TestProDetach/success_on_unattached_distro 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 386s === CONT TestWindowsHostAddress/Success_without_NAT 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 386s --- PASS: TestUserProfileDir (0.05s) 386s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.26s) 386s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 386s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (4.86s) 386s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.96s) 386s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (17.01s) 386s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (11.97s) 386s --- PASS: TestUserProfileDir/Error_on_wslpath_error (11.70s) 386s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (11.67s) 386s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (12.76s) 386s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (13.95s) 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 386s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 386s --- PASS: TestProDetach (0.05s) 386s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (7.79s) 386s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (4.93s) 386s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (5.81s) 386s --- PASS: TestProDetach/success_on_attached_distro (5.69s) 386s --- PASS: TestProDetach/success_on_unattached_distro (5.31s) 386s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 386s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 386s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 386s --- PASS: TestWindowsHostAddress (0.01s) 386s --- PASS: TestWindowsHostAddress/Success_without_NAT (4.44s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (5.42s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (4.17s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (4.43s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (4.20s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (3.97s) 386s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (3.24s) 386s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (3.47s) 386s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (3.38s) 386s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (3.79s) 386s PASS 386s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 56.193s 386s autopkgtest [14:42:17]: test command1: -----------------------] 391s autopkgtest [14:42:22]: test command1: - - - - - - - - - - results - - - - - - - - - - 391s command1 PASS 400s autopkgtest [14:42:31]: @@@@@@@@@@@@@@@@@@@@ summary 400s command1 PASS