0s autopkgtest [22:38:45]: starting date and time: 2024-07-18 22:38:45+0000 0s autopkgtest [22:38:45]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [22:38:45]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.10hioo4k/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --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.2~24.04' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos01-ppc64el-12.secgroup --name adt-noble-ppc64el-wsl-pro-service-20240718-223845-juju-7f2275-prod-proposed-migration-environment-3-cdc7261f-54e2-4070-acaf-36d576c35c15 --image adt/ubuntu-noble-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 84s autopkgtest [22:40:09]: testbed dpkg architecture: ppc64el 84s autopkgtest [22:40:09]: testbed apt version: 2.7.14build2 84s autopkgtest [22:40:09]: @@@@@@@@@@@@@@@@@@@@ test bed setup 85s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [265 kB] 85s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [9944 B] 85s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [33.0 kB] 85s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [5700 B] 85s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [50.9 kB] 85s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [2484 B] 85s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el Packages [1176 B] 85s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 85s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [43.5 kB] 85s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [1364 B] 85s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 87s Fetched 413 kB in 1s (628 kB/s) 87s Reading package lists... 89s Reading package lists... 90s Building dependency tree... 90s Reading state information... 90s Calculating upgrade... 90s The following packages will be upgraded: 90s ubuntu-pro-client ubuntu-pro-client-l10n xkb-data 90s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 90s Need to get 648 kB of archives. 90s After this operation, 25.6 kB of additional disk space will be used. 90s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el ubuntu-pro-client-l10n ppc64el 33.2~24.04 [19.4 kB] 90s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el ubuntu-pro-client ppc64el 33.2~24.04 [232 kB] 90s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el xkb-data all 2.41-2ubuntu1.1 [397 kB] 91s Fetched 648 kB in 1s (1173 kB/s) 91s (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 ... 102923 files and directories currently installed.) 91s Preparing to unpack .../ubuntu-pro-client-l10n_33.2~24.04_ppc64el.deb ... 91s Unpacking ubuntu-pro-client-l10n (33.2~24.04) over (32.3.1~24.04) ... 91s Preparing to unpack .../ubuntu-pro-client_33.2~24.04_ppc64el.deb ... 91s Unpacking ubuntu-pro-client (33.2~24.04) over (32.3.1~24.04) ... 91s Preparing to unpack .../xkb-data_2.41-2ubuntu1.1_all.deb ... 91s Unpacking xkb-data (2.41-2ubuntu1.1) over (2.41-2ubuntu1) ... 91s Setting up xkb-data (2.41-2ubuntu1.1) ... 91s Setting up ubuntu-pro-client (33.2~24.04) ... 91s Installing new version of config file /etc/apparmor.d/ubuntu_pro_apt_news ... 93s Setting up ubuntu-pro-client-l10n (33.2~24.04) ... 93s Processing triggers for man-db (2.12.0-4build2) ... 94s Reading package lists... 94s Building dependency tree... 94s Reading state information... 94s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 94s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 94s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 94s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 95s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 96s Reading package lists... 96s Reading package lists... 96s Building dependency tree... 96s Reading state information... 96s Calculating upgrade... 96s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 96s Reading package lists... 97s Building dependency tree... 97s Reading state information... 97s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 97s autopkgtest [22:40:22]: rebooting testbed after setup commands that affected boot 101s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 134s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 146s autopkgtest [22:41:11]: testbed running kernel: Linux 6.8.0-38-generic #38-Ubuntu SMP Fri Jun 7 15:27:19 UTC 2024 148s autopkgtest [22:41:13]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 150s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 150s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 150s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 150s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 150s gpgv: Can't check signature: No public key 151s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 151s autopkgtest [22:41:16]: testing package wsl-pro-service version 0.1.4 151s autopkgtest [22:41:16]: build not needed 172s autopkgtest [22:41:37]: test command1: preparing testbed 173s Reading package lists... 174s Building dependency tree... 174s Reading state information... 174s Starting pkgProblemResolver with broken count: 0 174s Starting 2 pkgProblemResolver with broken count: 0 174s Done 174s The following additional packages will be installed: 174s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 174s cpp-13-powerpc64le-linux-gnu cpp-powerpc64le-linux-gnu debhelper debugedit 174s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 174s g++-13-powerpc64le-linux-gnu g++-powerpc64le-linux-gnu gcc gcc-13 174s gcc-13-base gcc-13-powerpc64le-linux-gnu gcc-powerpc64le-linux-gnu gettext 174s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 174s libarchive-zip-perl libasan8 libatomic1 libcc1-0 libdebhelper-perl 174s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 174s liblsan0 libmpc3 libquadmath0 libstdc++-13-dev libsub-override-perl libtool 174s libtsan2 libubsan1 m4 po-debconf 174s Suggested packages: 174s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 174s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 174s gcc-doc gdb-powerpc64le-linux-gnu gettext-doc libasprintf-dev 174s libgettextpo-dev bzr | brz git mercurial subversion libstdc++-13-doc 174s libtool-doc gfortran | fortran95-compiler gcj-jdk m4-doc libmail-box-perl 174s Recommended packages: 174s pkg-config libarchive-cpio-perl libltdl-dev libmail-sendmail-perl 174s The following NEW packages will be installed: 174s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 174s cpp cpp-13 cpp-13-powerpc64le-linux-gnu cpp-powerpc64le-linux-gnu debhelper 174s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 174s g++-13 g++-13-powerpc64le-linux-gnu g++-powerpc64le-linux-gnu gcc gcc-13 174s gcc-13-base gcc-13-powerpc64le-linux-gnu gcc-powerpc64le-linux-gnu gettext 174s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 174s libarchive-zip-perl libasan8 libatomic1 libcc1-0 libdebhelper-perl 174s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 174s liblsan0 libmpc3 libquadmath0 libstdc++-13-dev libsub-override-perl libtool 174s libtsan2 libubsan1 m4 po-debconf 174s 0 upgraded, 52 newly installed, 0 to remove and 0 not upgraded. 174s Need to get 105 MB/105 MB of archives. 174s After this operation, 461 MB of additional disk space will be used. 174s Get:1 /tmp/autopkgtest.5GXtHd/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [760 B] 174s Get:2 http://ftpmaster.internal/ubuntu noble/main ppc64el m4 ppc64el 1.4.19-4build1 [278 kB] 175s Get:3 http://ftpmaster.internal/ubuntu noble/main ppc64el autoconf all 2.71-3 [339 kB] 175s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el autotools-dev all 20220109.1 [44.9 kB] 175s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el automake all 1:1.16.5-1.3ubuntu1 [558 kB] 175s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el autopoint all 0.21-14ubuntu2 [422 kB] 175s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13-base ppc64el 13.2.0-23ubuntu4 [49.0 kB] 175s Get:8 http://ftpmaster.internal/ubuntu noble/main ppc64el libisl23 ppc64el 0.26-3build1 [886 kB] 175s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el libmpc3 ppc64el 1.3.1-1build1 [62.1 kB] 175s Get:10 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13-powerpc64le-linux-gnu ppc64el 13.2.0-23ubuntu4 [10.7 MB] 177s Get:11 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13 ppc64el 13.2.0-23ubuntu4 [1038 B] 177s Get:12 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [5330 B] 177s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp ppc64el 4:13.2.0-7ubuntu1 [22.5 kB] 177s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el libcc1-0 ppc64el 14-20240412-0ubuntu1 [48.1 kB] 177s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el libgomp1 ppc64el 14-20240412-0ubuntu1 [161 kB] 177s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el libitm1 ppc64el 14-20240412-0ubuntu1 [32.4 kB] 177s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el libatomic1 ppc64el 14-20240412-0ubuntu1 [10.7 kB] 177s Get:18 http://ftpmaster.internal/ubuntu noble/main ppc64el libasan8 ppc64el 14-20240412-0ubuntu1 [2971 kB] 177s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el liblsan0 ppc64el 14-20240412-0ubuntu1 [1327 kB] 177s Get:20 http://ftpmaster.internal/ubuntu noble/main ppc64el libtsan2 ppc64el 14-20240412-0ubuntu1 [2709 kB] 178s Get:21 http://ftpmaster.internal/ubuntu noble/main ppc64el libubsan1 ppc64el 14-20240412-0ubuntu1 [1196 kB] 178s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el libquadmath0 ppc64el 14-20240412-0ubuntu1 [158 kB] 178s Get:23 http://ftpmaster.internal/ubuntu noble/main ppc64el libgcc-13-dev ppc64el 13.2.0-23ubuntu4 [1580 kB] 178s Get:24 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13-powerpc64le-linux-gnu ppc64el 13.2.0-23ubuntu4 [20.6 MB] 181s Get:25 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13 ppc64el 13.2.0-23ubuntu4 [482 kB] 181s Get:26 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [1224 B] 181s Get:27 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc ppc64el 4:13.2.0-7ubuntu1 [5022 B] 181s Get:28 http://ftpmaster.internal/ubuntu noble/main ppc64el libstdc++-13-dev ppc64el 13.2.0-23ubuntu4 [2512 kB] 182s Get:29 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13-powerpc64le-linux-gnu ppc64el 13.2.0-23ubuntu4 [12.2 MB] 184s Get:30 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13 ppc64el 13.2.0-23ubuntu4 [14.5 kB] 184s Get:31 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [968 B] 184s Get:32 http://ftpmaster.internal/ubuntu noble/main ppc64el g++ ppc64el 4:13.2.0-7ubuntu1 [1086 B] 184s Get:33 http://ftpmaster.internal/ubuntu noble/main ppc64el build-essential ppc64el 12.10ubuntu1 [4936 B] 184s Get:34 http://ftpmaster.internal/ubuntu noble/main ppc64el libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 184s Get:35 http://ftpmaster.internal/ubuntu noble/main ppc64el libtool all 2.4.7-7build1 [166 kB] 184s Get:36 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-autoreconf all 20 [16.1 kB] 184s Get:37 http://ftpmaster.internal/ubuntu noble/main ppc64el libarchive-zip-perl all 1.68-1 [90.2 kB] 184s Get:38 http://ftpmaster.internal/ubuntu noble/main ppc64el libsub-override-perl all 0.10-1 [10.0 kB] 184s Get:39 http://ftpmaster.internal/ubuntu noble/main ppc64el libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 184s Get:40 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-strip-nondeterminism all 1.13.1-1 [5362 B] 184s Get:41 http://ftpmaster.internal/ubuntu noble/main ppc64el debugedit ppc64el 1:5.0-5build2 [51.4 kB] 184s Get:42 http://ftpmaster.internal/ubuntu noble/main ppc64el dwz ppc64el 0.15-1build6 [142 kB] 184s Get:43 http://ftpmaster.internal/ubuntu noble/main ppc64el gettext ppc64el 0.21-14ubuntu2 [985 kB] 184s Get:44 http://ftpmaster.internal/ubuntu noble/main ppc64el intltool-debian all 0.35.0+20060710.6 [23.2 kB] 184s Get:45 http://ftpmaster.internal/ubuntu noble/main ppc64el po-debconf all 1.0.21+nmu1 [233 kB] 184s Get:46 http://ftpmaster.internal/ubuntu noble/main ppc64el debhelper all 13.14.1ubuntu5 [869 kB] 184s Get:47 http://ftpmaster.internal/ubuntu noble-updates/universe ppc64el dh-apport all 2.28.1-0ubuntu3 [17.2 kB] 184s Get:48 http://ftpmaster.internal/ubuntu noble-updates/main ppc64el golang-1.22-src all 1.22.2-2ubuntu0.1 [19.7 MB] 187s Get:49 http://ftpmaster.internal/ubuntu noble-updates/main ppc64el golang-1.22-go ppc64el 1.22.2-2ubuntu0.1 [23.5 MB] 190s Get:50 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-src all 2:1.22~2build1 [5078 B] 190s Get:51 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-go ppc64el 2:1.22~2build1 [44.0 kB] 190s Get:52 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-golang all 1.62 [25.2 kB] 191s Fetched 105 MB in 16s (6546 kB/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 ... 102924 files and directories currently installed.) 191s Preparing to unpack .../00-m4_1.4.19-4build1_ppc64el.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 gcc-13-base:ppc64el. 191s Preparing to unpack .../05-gcc-13-base_13.2.0-23ubuntu4_ppc64el.deb ... 191s Unpacking gcc-13-base:ppc64el (13.2.0-23ubuntu4) ... 191s Selecting previously unselected package libisl23:ppc64el. 191s Preparing to unpack .../06-libisl23_0.26-3build1_ppc64el.deb ... 191s Unpacking libisl23:ppc64el (0.26-3build1) ... 191s Selecting previously unselected package libmpc3:ppc64el. 191s Preparing to unpack .../07-libmpc3_1.3.1-1build1_ppc64el.deb ... 191s Unpacking libmpc3:ppc64el (1.3.1-1build1) ... 191s Selecting previously unselected package cpp-13-powerpc64le-linux-gnu. 191s Preparing to unpack .../08-cpp-13-powerpc64le-linux-gnu_13.2.0-23ubuntu4_ppc64el.deb ... 191s Unpacking cpp-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 191s Selecting previously unselected package cpp-13. 191s Preparing to unpack .../09-cpp-13_13.2.0-23ubuntu4_ppc64el.deb ... 191s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 191s Selecting previously unselected package cpp-powerpc64le-linux-gnu. 191s Preparing to unpack .../10-cpp-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 191s Unpacking cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 191s Selecting previously unselected package cpp. 191s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 191s Unpacking cpp (4:13.2.0-7ubuntu1) ... 191s Selecting previously unselected package libcc1-0:ppc64el. 191s Preparing to unpack .../12-libcc1-0_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libcc1-0:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package libgomp1:ppc64el. 191s Preparing to unpack .../13-libgomp1_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libgomp1:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package libitm1:ppc64el. 191s Preparing to unpack .../14-libitm1_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libitm1:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package libatomic1:ppc64el. 191s Preparing to unpack .../15-libatomic1_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libatomic1:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package libasan8:ppc64el. 191s Preparing to unpack .../16-libasan8_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libasan8:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package liblsan0:ppc64el. 191s Preparing to unpack .../17-liblsan0_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking liblsan0:ppc64el (14-20240412-0ubuntu1) ... 191s Selecting previously unselected package libtsan2:ppc64el. 191s Preparing to unpack .../18-libtsan2_14-20240412-0ubuntu1_ppc64el.deb ... 191s Unpacking libtsan2:ppc64el (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libubsan1:ppc64el. 192s Preparing to unpack .../19-libubsan1_14-20240412-0ubuntu1_ppc64el.deb ... 192s Unpacking libubsan1:ppc64el (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libquadmath0:ppc64el. 192s Preparing to unpack .../20-libquadmath0_14-20240412-0ubuntu1_ppc64el.deb ... 192s Unpacking libquadmath0:ppc64el (14-20240412-0ubuntu1) ... 192s Selecting previously unselected package libgcc-13-dev:ppc64el. 192s Preparing to unpack .../21-libgcc-13-dev_13.2.0-23ubuntu4_ppc64el.deb ... 192s Unpacking libgcc-13-dev:ppc64el (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package gcc-13-powerpc64le-linux-gnu. 192s Preparing to unpack .../22-gcc-13-powerpc64le-linux-gnu_13.2.0-23ubuntu4_ppc64el.deb ... 192s Unpacking gcc-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package gcc-13. 192s Preparing to unpack .../23-gcc-13_13.2.0-23ubuntu4_ppc64el.deb ... 192s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 192s Selecting previously unselected package gcc-powerpc64le-linux-gnu. 192s Preparing to unpack .../24-gcc-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 192s Unpacking gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 192s Selecting previously unselected package gcc. 192s Preparing to unpack .../25-gcc_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 192s Unpacking gcc (4:13.2.0-7ubuntu1) ... 192s Selecting previously unselected package libstdc++-13-dev:ppc64el. 192s Preparing to unpack .../26-libstdc++-13-dev_13.2.0-23ubuntu4_ppc64el.deb ... 192s Unpacking libstdc++-13-dev:ppc64el (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-13-powerpc64le-linux-gnu. 193s Preparing to unpack .../27-g++-13-powerpc64le-linux-gnu_13.2.0-23ubuntu4_ppc64el.deb ... 193s Unpacking g++-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-13. 193s Preparing to unpack .../28-g++-13_13.2.0-23ubuntu4_ppc64el.deb ... 193s Unpacking g++-13 (13.2.0-23ubuntu4) ... 193s Selecting previously unselected package g++-powerpc64le-linux-gnu. 193s Preparing to unpack .../29-g++-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 193s Unpacking g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package g++. 193s Preparing to unpack .../30-g++_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 193s Unpacking g++ (4:13.2.0-7ubuntu1) ... 193s Selecting previously unselected package build-essential. 193s Preparing to unpack .../31-build-essential_12.10ubuntu1_ppc64el.deb ... 193s Unpacking build-essential (12.10ubuntu1) ... 193s Selecting previously unselected package libdebhelper-perl. 193s Preparing to unpack .../32-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 193s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 193s Selecting previously unselected package libtool. 193s Preparing to unpack .../33-libtool_2.4.7-7build1_all.deb ... 193s Unpacking libtool (2.4.7-7build1) ... 193s Selecting previously unselected package dh-autoreconf. 193s Preparing to unpack .../34-dh-autoreconf_20_all.deb ... 193s Unpacking dh-autoreconf (20) ... 193s Selecting previously unselected package libarchive-zip-perl. 193s Preparing to unpack .../35-libarchive-zip-perl_1.68-1_all.deb ... 193s Unpacking libarchive-zip-perl (1.68-1) ... 193s Selecting previously unselected package libsub-override-perl. 193s Preparing to unpack .../36-libsub-override-perl_0.10-1_all.deb ... 193s Unpacking libsub-override-perl (0.10-1) ... 193s Selecting previously unselected package libfile-stripnondeterminism-perl. 193s Preparing to unpack .../37-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 193s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 193s Selecting previously unselected package dh-strip-nondeterminism. 193s Preparing to unpack .../38-dh-strip-nondeterminism_1.13.1-1_all.deb ... 193s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 193s Selecting previously unselected package debugedit. 193s Preparing to unpack .../39-debugedit_1%3a5.0-5build2_ppc64el.deb ... 193s Unpacking debugedit (1:5.0-5build2) ... 193s Selecting previously unselected package dwz. 193s Preparing to unpack .../40-dwz_0.15-1build6_ppc64el.deb ... 193s Unpacking dwz (0.15-1build6) ... 193s Selecting previously unselected package gettext. 193s Preparing to unpack .../41-gettext_0.21-14ubuntu2_ppc64el.deb ... 193s Unpacking gettext (0.21-14ubuntu2) ... 193s Selecting previously unselected package intltool-debian. 193s Preparing to unpack .../42-intltool-debian_0.35.0+20060710.6_all.deb ... 193s Unpacking intltool-debian (0.35.0+20060710.6) ... 193s Selecting previously unselected package po-debconf. 193s Preparing to unpack .../43-po-debconf_1.0.21+nmu1_all.deb ... 193s Unpacking po-debconf (1.0.21+nmu1) ... 193s Selecting previously unselected package debhelper. 193s Preparing to unpack .../44-debhelper_13.14.1ubuntu5_all.deb ... 193s Unpacking debhelper (13.14.1ubuntu5) ... 193s Selecting previously unselected package dh-apport. 193s Preparing to unpack .../45-dh-apport_2.28.1-0ubuntu3_all.deb ... 193s Unpacking dh-apport (2.28.1-0ubuntu3) ... 193s Selecting previously unselected package golang-1.22-src. 193s Preparing to unpack .../46-golang-1.22-src_1.22.2-2ubuntu0.1_all.deb ... 193s Unpacking golang-1.22-src (1.22.2-2ubuntu0.1) ... 196s Selecting previously unselected package golang-1.22-go. 196s Preparing to unpack .../47-golang-1.22-go_1.22.2-2ubuntu0.1_ppc64el.deb ... 196s Unpacking golang-1.22-go (1.22.2-2ubuntu0.1) ... 197s Selecting previously unselected package golang-src. 197s Preparing to unpack .../48-golang-src_2%3a1.22~2build1_all.deb ... 197s Unpacking golang-src (2:1.22~2build1) ... 197s Selecting previously unselected package golang-go:ppc64el. 197s Preparing to unpack .../49-golang-go_2%3a1.22~2build1_ppc64el.deb ... 197s Unpacking golang-go:ppc64el (2:1.22~2build1) ... 197s Selecting previously unselected package dh-golang. 197s Preparing to unpack .../50-dh-golang_1.62_all.deb ... 197s Unpacking dh-golang (1.62) ... 197s Selecting previously unselected package autopkgtest-satdep. 197s Preparing to unpack .../51-1-autopkgtest-satdep.deb ... 197s Unpacking autopkgtest-satdep (0) ... 197s Setting up libarchive-zip-perl (1.68-1) ... 197s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 197s Setting up m4 (1.4.19-4build1) ... 197s Setting up libgomp1:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up dh-apport (2.28.1-0ubuntu3) ... 197s Setting up autotools-dev (20220109.1) ... 197s Setting up gcc-13-base:ppc64el (13.2.0-23ubuntu4) ... 197s Setting up golang-1.22-src (1.22.2-2ubuntu0.1) ... 197s Setting up libquadmath0:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up libmpc3:ppc64el (1.3.1-1build1) ... 197s Setting up libatomic1:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up autopoint (0.21-14ubuntu2) ... 197s Setting up autoconf (2.71-3) ... 197s Setting up libubsan1:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up dwz (0.15-1build6) ... 197s Setting up libasan8:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up debugedit (1:5.0-5build2) ... 197s Setting up libsub-override-perl (0.10-1) ... 197s Setting up libtsan2:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up libisl23:ppc64el (0.26-3build1) ... 197s Setting up cpp-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 197s Setting up golang-src (2:1.22~2build1) ... 197s Setting up libcc1-0:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up liblsan0:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up libitm1:ppc64el (14-20240412-0ubuntu1) ... 197s Setting up cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 197s Setting up automake (1:1.16.5-1.3ubuntu1) ... 197s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 197s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 197s Setting up gettext (0.21-14ubuntu2) ... 197s Setting up cpp-13 (13.2.0-23ubuntu4) ... 197s Setting up golang-1.22-go (1.22.2-2ubuntu0.1) ... 197s Setting up intltool-debian (0.35.0+20060710.6) ... 197s Setting up dh-strip-nondeterminism (1.13.1-1) ... 197s Setting up libgcc-13-dev:ppc64el (13.2.0-23ubuntu4) ... 197s Setting up cpp (4:13.2.0-7ubuntu1) ... 197s Setting up libstdc++-13-dev:ppc64el (13.2.0-23ubuntu4) ... 197s Setting up golang-go:ppc64el (2:1.22~2build1) ... 197s Setting up po-debconf (1.0.21+nmu1) ... 197s Setting up gcc-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 197s Setting up gcc-13 (13.2.0-23ubuntu4) ... 197s Setting up libtool (2.4.7-7build1) ... 197s Setting up g++-13-powerpc64le-linux-gnu (13.2.0-23ubuntu4) ... 197s Setting up dh-autoreconf (20) ... 197s Setting up gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 197s Setting up g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 197s Setting up g++-13 (13.2.0-23ubuntu4) ... 197s Setting up debhelper (13.14.1ubuntu5) ... 197s Setting up gcc (4:13.2.0-7ubuntu1) ... 197s Setting up g++ (4:13.2.0-7ubuntu1) ... 197s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 197s Setting up build-essential (12.10ubuntu1) ... 197s Setting up dh-golang (1.62) ... 197s Setting up autopkgtest-satdep (0) ... 197s Processing triggers for man-db (2.12.0-4build2) ... 198s Processing triggers for install-info (7.1-3build2) ... 198s Processing triggers for libc-bin (2.39-0ubuntu8.2) ... 200s (Reading database ... 119517 files and directories currently installed.) 200s Removing autopkgtest-satdep (0) ... 200s autopkgtest [22:42:05]: test command1: ./debian/tests/test 200s autopkgtest [22:42:05]: test command1: [----------------------- 265s === RUN TestRunSignal 265s === RUN TestRunSignal/Send_SIGINT_exits 265s INFO Starting WSL Pro Service version Dev 265s === RUN TestRunSignal/Send_SIGTERM_exits 265s INFO Starting WSL Pro Service version Dev 265s --- PASS: TestRunSignal (0.20s) 265s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 265s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 265s === RUN TestRun 265s === PAUSE TestRun 265s === CONT TestRun 265s === RUN TestRun/Run_and_exit_successfully 265s === PAUSE TestRun/Run_and_exit_successfully 265s === RUN TestRun/Run_and_return_error 265s === PAUSE TestRun/Run_and_return_error 265s === RUN TestRun/Run_and_return_usage_error 265s === PAUSE TestRun/Run_and_return_usage_error 265s === RUN TestRun/Run_and_usage_error_only_does_not_fail 265s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 265s === CONT TestRun/Run_and_exit_successfully 265s INFO Starting WSL Pro Service version Dev 265s === CONT TestRun/Run_and_usage_error_only_does_not_fail 265s INFO Starting WSL Pro Service version Dev 265s === CONT TestRun/Run_and_return_usage_error 265s INFO Starting WSL Pro Service version Dev 266s ERROR context.Background Error requested 266s === CONT TestRun/Run_and_return_error 266s INFO Starting WSL Pro Service version Dev 266s ERROR context.Background Error requested 266s --- PASS: TestRun (0.00s) 266s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 266s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 266s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 266s --- PASS: TestRun/Run_and_return_error (0.10s) 266s PASS 266s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.608s 267s === RUN TestHelp 267s --- PASS: TestHelp (0.00s) 267s === RUN TestCompletion 267s --- PASS: TestCompletion (0.00s) 267s === RUN TestVersion 267s --- PASS: TestVersion (0.00s) 267s === RUN TestNoUsageError 267s --- PASS: TestNoUsageError (0.00s) 267s === RUN TestUsageError 267s === PAUSE TestUsageError 267s === RUN TestCanQuitWhenExecute 267s === PAUSE TestCanQuitWhenExecute 267s === RUN TestCanQuitTwice 267s === PAUSE TestCanQuitTwice 267s === RUN TestAppCanQuitWithoutExecute 267s === PAUSE TestAppCanQuitWithoutExecute 267s === RUN TestAppRunFailsOnComponentsCreationAndQuit 267s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 267s === RUN TestAppGetRootCmd 267s === PAUSE TestAppGetRootCmd 267s === RUN TestWithProMock 267s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 267s --- SKIP: TestWithProMock (0.00s) 267s === RUN TestWithWslPathMock 267s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 267s --- SKIP: TestWithWslPathMock (0.00s) 267s === RUN TestWithWslInfoMock 267s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 267s --- SKIP: TestWithWslInfoMock (0.00s) 267s === RUN TestWithCmdExeMock 267s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 267s --- SKIP: TestWithCmdExeMock (0.00s) 267s === CONT TestUsageError 267s --- PASS: TestUsageError (0.00s) 267s === CONT TestAppGetRootCmd 267s --- PASS: TestAppGetRootCmd (0.00s) 267s === CONT TestAppRunFailsOnComponentsCreationAndQuit 271s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (3.66s) 271s === CONT TestAppCanQuitWithoutExecute 271s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 271s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 271s === CONT TestCanQuitTwice 271s time="2024-07-18T22:43:16Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 271s time="2024-07-18T22:43:16Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:75 New() Building new daemon" 273s time="2024-07-18T22:43:18Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 273s time="2024-07-18T22:43:18Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 273s time="2024-07-18T22:43:18Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 274s time="2024-07-18T22:43:19Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:42625" 274s time="2024-07-18T22:43:19Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 274s time="2024-07-18T22:43:19Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 274s time="2024-07-18T22:43:19Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/testutils/mock_agent.go:326 (*mockWSLInstanceService).LandscapeConfigCommands() MockWindowsAgent: LandscapeConfigCommands ready" 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/testutils/mock_agent.go:275 (*mockWSLInstanceService).Connected() MockWindowsAgent: Connected ready" 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/testutils/mock_agent.go:300 (*mockWSLInstanceService).ProAttachmentCommands() MockWindowsAgent: ProAttachmentCommands ready" 275s time="2024-07-18T22:43:20Z" level=warning msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:186 (*Daemon).Serve.func1() Daemon: disconnected from Windows host" 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 275s time="2024-07-18T22:43:20Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.5GXtHd/build.2Lm/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 275s time="2024-07-18T22:43:20Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.5GXtHd/build.2Lm/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 275s time="2024-07-18T22:43:20Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.5GXtHd/build.2Lm/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 275s --- PASS: TestCanQuitTwice (4.43s) 275s === CONT TestCanQuitWhenExecute 275s time="2024-07-18T22:43:20Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39961" 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 275s time="2024-07-18T22:43:20Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:75 New() Building new daemon" 277s time="2024-07-18T22:43:22Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 278s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 278s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 279s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:39961" 279s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 279s time="2024-07-18T22:43:23Z" level=warning msg="/tmp/autopkgtest.5GXtHd/build.2Lm/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:39961: connect: connection refused\"" 279s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 279s time="2024-07-18T22:43:23Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 279s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 279s time="2024-07-18T22:43:23Z" level=info msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 279s time="2024-07-18T22:43:23Z" level=debug msg="/tmp/autopkgtest.5GXtHd/build.2Lm/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 279s --- PASS: TestCanQuitWhenExecute (3.40s) 279s PASS 279s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 11.508s 279s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 279s === RUN TestApplyProToken 279s === PAUSE TestApplyProToken 279s === RUN TestApplyLandscapeConfig 279s === PAUSE TestApplyLandscapeConfig 279s === RUN TestWithProMock 279s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 279s --- SKIP: TestWithProMock (0.00s) 279s === RUN TestWithLandscapeConfigMock 279s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 279s --- SKIP: TestWithLandscapeConfigMock (0.00s) 279s === RUN TestWithWslPathMock 279s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 279s --- SKIP: TestWithWslPathMock (0.00s) 279s === RUN TestWithWslInfoMock 279s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 279s --- SKIP: TestWithWslInfoMock (0.00s) 279s === RUN TestWithCmdExeMock 279s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 279s --- SKIP: TestWithCmdExeMock (0.00s) 279s === CONT TestApplyProToken 279s === RUN TestApplyProToken/Success_attaching 279s === PAUSE TestApplyProToken/Success_attaching 279s === RUN TestApplyProToken/Success_detaching 279s === PAUSE TestApplyProToken/Success_detaching 279s === RUN TestApplyProToken/Error_calling_pro_detach 279s === PAUSE TestApplyProToken/Error_calling_pro_detach 279s === RUN TestApplyProToken/Error_calling_pro_attach 279s === PAUSE TestApplyProToken/Error_calling_pro_attach 279s === CONT TestApplyProToken/Success_attaching 279s time="2024-07-18T22:43:24Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 281s === CONT TestApplyLandscapeConfig 281s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 281s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 281s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 281s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 281s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 281s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 281s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 281s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 281s === CONT TestApplyProToken/Error_calling_pro_attach 281s time="2024-07-18T22:43:26Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 283s === CONT TestApplyProToken/Error_calling_pro_detach 283s time="2024-07-18T22:43:28Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 284s === CONT TestApplyProToken/Success_detaching 284s time="2024-07-18T22:43:29Z" level=info msg="ApplyProToken: Received empty token: detaching" 285s --- PASS: TestApplyProToken (0.00s) 285s --- PASS: TestApplyProToken/Success_attaching (1.87s) 285s --- PASS: TestApplyProToken/Error_calling_pro_attach (1.87s) 285s --- PASS: TestApplyProToken/Error_calling_pro_detach (0.92s) 285s --- PASS: TestApplyProToken/Success_detaching (0.92s) 285s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 285s time="2024-07-18T22:43:30Z" level=info msg="ApplyLandscapeConfig: received config: registering" 286s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 286s time="2024-07-18T22:43:31Z" level=info msg="ApplyLandscapeConfig: received config: registering" 287s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 287s time="2024-07-18T22:43:32Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 288s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 288s time="2024-07-18T22:43:33Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 288s --- PASS: TestApplyLandscapeConfig (0.00s) 288s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (0.94s) 288s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (0.94s) 288s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (0.93s) 288s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (0.93s) 288s PASS 288s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 9.325s 288s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 289s === RUN TestNew 289s === PAUSE TestNew 289s === RUN TestServe 289s === PAUSE TestServe 289s === RUN TestServeAndQuit 289s === PAUSE TestServeAndQuit 289s === RUN TestReconnection 289s === PAUSE TestReconnection 289s === RUN TestWithProMock 289s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 289s --- SKIP: TestWithProMock (0.00s) 289s === RUN TestWithWslPathMock 289s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 289s --- SKIP: TestWithWslPathMock (0.00s) 289s === RUN TestWithWslInfoMock 289s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 289s --- SKIP: TestWithWslInfoMock (0.00s) 289s === RUN TestWithCmdExeMock 289s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 289s --- SKIP: TestWithCmdExeMock (0.00s) 289s === CONT TestNew 289s === RUN TestNew/Success 289s === PAUSE TestNew/Success 289s === RUN TestNew/Error_when_WslPath_returns_error 289s === PAUSE TestNew/Error_when_WslPath_returns_error 289s === CONT TestNew/Success 289s time="2024-07-18T22:43:34Z" level=debug msg="Building new daemon" 292s === CONT TestReconnection 292s === RUN TestReconnection/Success_connecting_after_failing_to_connect 292s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 292s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 292s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 292s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 292s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 292s === CONT TestServeAndQuit 292s === RUN TestServeAndQuit/Success_with_graceful_quit 292s === PAUSE TestServeAndQuit/Success_with_graceful_quit 292s === RUN TestServeAndQuit/Success_with_forceful_quit 292s === PAUSE TestServeAndQuit/Success_with_forceful_quit 292s === RUN TestServeAndQuit/Success_with_double_quit 292s === PAUSE TestServeAndQuit/Success_with_double_quit 292s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 292s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 292s === CONT TestServe 292s === RUN TestServe/Error_because_the_context_is_pre-cancelled 292s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 292s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 292s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 292s === RUN TestServe/Success 292s === PAUSE TestServe/Success 292s === RUN TestServe/Success_with_systemd_notifier_returning_true 292s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 292s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 292s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 292s === RUN TestServe/No_connection_because_there_is_no_server 292s === PAUSE TestServe/No_connection_because_there_is_no_server 292s === RUN TestServe/No_connection_because_there_are_no_certificates 292s === PAUSE TestServe/No_connection_because_there_are_no_certificates 292s === RUN TestServe/Error_because_the_notifier_returns_an_error 292s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 292s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 292s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 292s === RUN TestServe/No_connection_because_the_port_file_is_empty 292s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 292s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 292s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 292s === RUN TestServe/No_connection_because_the_port_file_has_port_0 292s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 292s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 292s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 292s === CONT TestNew/Error_when_WslPath_returns_error 292s time="2024-07-18T22:43:37Z" level=debug msg="Building new daemon" 294s --- PASS: TestNew (0.00s) 294s --- PASS: TestNew/Success (2.17s) 294s --- PASS: TestNew/Error_when_WslPath_returns_error (2.00s) 294s === CONT TestReconnection/Success_connecting_after_failing_to_connect 294s time="2024-07-18T22:43:39Z" level=debug msg="Building new daemon" 296s time="2024-07-18T22:43:41Z" level=debug msg="Ready state sent to systemd" 296s time="2024-07-18T22:43:41Z" level=info msg="Daemon: connecting to Windows Agent" 296s time="2024-07-18T22:43:41Z" level=debug msg="Updated systemd status to \"Connecting\"" 296s time="2024-07-18T22:43:41Z" 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_connect3597864039/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3597864039/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 296s time="2024-07-18T22:43:41Z" level=info msg="Reconnecting to Windows host in 1 seconds" 296s time="2024-07-18T22:43:41Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 296s time="2024-07-18T22:43:41Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39433" 297s time="2024-07-18T22:43:42Z" level=info msg="Daemon: connecting to Windows Agent" 297s time="2024-07-18T22:43:42Z" level=debug msg="Updated systemd status to \"Connecting\"" 298s time="2024-07-18T22:43:43Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:39433" 298s time="2024-07-18T22:43:43Z" level=info msg="Daemon: completed connection to Windows Agent" 298s time="2024-07-18T22:43:43Z" level=debug msg="Updated systemd status to \"Connected\"" 298s time="2024-07-18T22:43:43Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 298s time="2024-07-18T22:43:43Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 299s time="2024-07-18T22:43:44Z" level=debug msg="Server: sent preface messages to all streams" 299s time="2024-07-18T22:43:44Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 299s time="2024-07-18T22:43:44Z" level=info msg="MockWindowsAgent: Connected ready" 299s time="2024-07-18T22:43:44Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 299s time="2024-07-18T22:43:44Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 299s time="2024-07-18T22:43:44Z" level=info msg="Stopping daemon requested." 299s time="2024-07-18T22:43:44Z" level=info msg="Stopping active requests." 299s time="2024-07-18T22:43:44Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 299s time="2024-07-18T22:43:44Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 299s time="2024-07-18T22:43:44Z" level=warning msg="Daemon: disconnected from Windows host" 299s time="2024-07-18T22:43:44Z" level=info msg="Reconnecting to Windows host in 2 seconds" 299s time="2024-07-18T22:43:44Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 299s time="2024-07-18T22:43:44Z" level=debug msg="Updated systemd status to \"Stopped\"" 299s time="2024-07-18T22:43:44Z" level=debug msg="All connections have now ended." 299s === CONT TestServeAndQuit/Success_with_graceful_quit 299s time="2024-07-18T22:43:44Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45781" 299s time="2024-07-18T22:43:44Z" level=debug msg="Building new daemon" 301s time="2024-07-18T22:43:46Z" level=debug msg="Ready state sent to systemd" 301s time="2024-07-18T22:43:46Z" level=info msg="Daemon: connecting to Windows Agent" 301s time="2024-07-18T22:43:46Z" level=debug msg="Updated systemd status to \"Connecting\"" 302s time="2024-07-18T22:43:47Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45781" 302s time="2024-07-18T22:43:47Z" level=info msg="Daemon: completed connection to Windows Agent" 302s time="2024-07-18T22:43:47Z" level=debug msg="Updated systemd status to \"Connected\"" 302s time="2024-07-18T22:43:47Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 302s time="2024-07-18T22:43:47Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 303s time="2024-07-18T22:43:48Z" level=debug msg="Server: sent preface messages to all streams" 303s time="2024-07-18T22:43:48Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 303s time="2024-07-18T22:43:48Z" level=info msg="MockWindowsAgent: Connected ready" 303s time="2024-07-18T22:43:48Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 303s time="2024-07-18T22:43:48Z" level=info msg="Stopping daemon requested." 303s time="2024-07-18T22:43:48Z" level=info msg="Waiting for active requests to close." 303s time="2024-07-18T22:43:48Z" level=warning msg="Daemon: disconnected from Windows host" 303s time="2024-07-18T22:43:48Z" level=info msg="Reconnecting to Windows host in 1 seconds" 303s time="2024-07-18T22:43:48Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 303s time="2024-07-18T22:43:48Z" level=debug msg="Updated systemd status to \"Stopped\"" 303s time="2024-07-18T22:43:48Z" level=debug msg="All connections have now ended." 303s time="2024-07-18T22:43:48Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 303s time="2024-07-18T22:43:48Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 303s time="2024-07-18T22:43:48Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 303s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 303s time="2024-07-18T22:43:48Z" level=debug msg="Building new daemon" 305s time="2024-07-18T22:43:50Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33747" 305s time="2024-07-18T22:43:50Z" level=debug msg="Ready state sent to systemd" 305s time="2024-07-18T22:43:50Z" level=info msg="Daemon: connecting to Windows Agent" 305s time="2024-07-18T22:43:50Z" level=debug msg="Updated systemd status to \"Connecting\"" 306s time="2024-07-18T22:43:51Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33747" 306s time="2024-07-18T22:43:51Z" level=info msg="Daemon: completed connection to Windows Agent" 306s time="2024-07-18T22:43:51Z" level=debug msg="Updated systemd status to \"Connected\"" 306s time="2024-07-18T22:43:51Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 306s time="2024-07-18T22:43:51Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 307s time="2024-07-18T22:43:52Z" level=debug msg="Server: sent preface messages to all streams" 307s time="2024-07-18T22:43:52Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 307s time="2024-07-18T22:43:52Z" level=info msg="MockWindowsAgent: Connected ready" 307s time="2024-07-18T22:43:52Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 372s time="2024-07-18T22:44:57Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 372s time="2024-07-18T22:44:57Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37517" 372s time="2024-07-18T22:44:57Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 372s time="2024-07-18T22:44:57Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 372s time="2024-07-18T22:44:57Z" level=warning msg="Daemon: disconnected from Windows host" 372s time="2024-07-18T22:44:57Z" level=info msg="Daemon: connecting to Windows Agent" 372s time="2024-07-18T22:44:57Z" level=debug msg="Updated systemd status to \"Connecting\"" 373s time="2024-07-18T22:44:58Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:37517" 373s time="2024-07-18T22:44:58Z" level=info msg="Daemon: completed connection to Windows Agent" 373s time="2024-07-18T22:44:58Z" level=debug msg="Updated systemd status to \"Connected\"" 373s time="2024-07-18T22:44:58Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 373s time="2024-07-18T22:44:58Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 374s time="2024-07-18T22:44:59Z" level=debug msg="Server: sent preface messages to all streams" 374s time="2024-07-18T22:44:59Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 374s time="2024-07-18T22:44:59Z" level=info msg="MockWindowsAgent: Connected ready" 374s time="2024-07-18T22:44:59Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 374s time="2024-07-18T22:44:59Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 374s time="2024-07-18T22:44:59Z" level=info msg="Stopping daemon requested." 374s time="2024-07-18T22:44:59Z" level=info msg="Stopping active requests." 374s time="2024-07-18T22:44:59Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 374s time="2024-07-18T22:44:59Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 374s time="2024-07-18T22:44:59Z" level=warning msg="Daemon: disconnected from Windows host" 374s time="2024-07-18T22:44:59Z" level=info msg="Reconnecting to Windows host in 1 seconds" 374s time="2024-07-18T22:44:59Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 374s time="2024-07-18T22:44:59Z" level=debug msg="Updated systemd status to \"Stopped\"" 374s time="2024-07-18T22:44:59Z" level=debug msg="All connections have now ended." 374s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 374s time="2024-07-18T22:44:59Z" level=debug msg="Building new daemon" 376s time="2024-07-18T22:45:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35723" 376s time="2024-07-18T22:45:01Z" level=debug msg="Ready state sent to systemd" 376s time="2024-07-18T22:45:01Z" level=info msg="Daemon: connecting to Windows Agent" 376s time="2024-07-18T22:45:01Z" level=debug msg="Updated systemd status to \"Connecting\"" 377s time="2024-07-18T22:45:02Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35723" 377s time="2024-07-18T22:45:02Z" level=info msg="Daemon: completed connection to Windows Agent" 377s time="2024-07-18T22:45:02Z" level=debug msg="Updated systemd status to \"Connected\"" 377s time="2024-07-18T22:45:02Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 377s time="2024-07-18T22:45:02Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 378s time="2024-07-18T22:45:03Z" level=debug msg="Server: sent preface messages to all streams" 378s time="2024-07-18T22:45:03Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 378s time="2024-07-18T22:45:03Z" level=info msg="MockWindowsAgent: Connected ready" 378s time="2024-07-18T22:45:03Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 378s time="2024-07-18T22:45:03Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 378s time="2024-07-18T22:45:03Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40031" 378s time="2024-07-18T22:45:03Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 378s time="2024-07-18T22:45:03Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 378s time="2024-07-18T22:45:03Z" level=warning msg="Daemon: disconnected from Windows host" 378s time="2024-07-18T22:45:03Z" level=info msg="Reconnecting to Windows host in 1 seconds" 378s time="2024-07-18T22:45:03Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 379s time="2024-07-18T22:45:04Z" level=info msg="Daemon: connecting to Windows Agent" 379s time="2024-07-18T22:45:04Z" level=debug msg="Updated systemd status to \"Connecting\"" 380s time="2024-07-18T22:45:05Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40031" 380s time="2024-07-18T22:45:05Z" level=info msg="Daemon: completed connection to Windows Agent" 380s time="2024-07-18T22:45:05Z" level=debug msg="Updated systemd status to \"Connected\"" 380s time="2024-07-18T22:45:05Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 380s time="2024-07-18T22:45:05Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 381s time="2024-07-18T22:45:06Z" level=debug msg="Server: sent preface messages to all streams" 381s time="2024-07-18T22:45:06Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 381s time="2024-07-18T22:45:06Z" level=info msg="MockWindowsAgent: Connected ready" 381s time="2024-07-18T22:45:06Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 381s time="2024-07-18T22:45:06Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 381s time="2024-07-18T22:45:06Z" level=info msg="Stopping daemon requested." 381s time="2024-07-18T22:45:06Z" level=info msg="Stopping active requests." 381s time="2024-07-18T22:45:06Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 381s time="2024-07-18T22:45:06Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 381s time="2024-07-18T22:45:06Z" level=warning msg="Daemon: disconnected from Windows host" 381s time="2024-07-18T22:45:06Z" level=info msg="Reconnecting to Windows host in 2 seconds" 381s time="2024-07-18T22:45:06Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 381s time="2024-07-18T22:45:06Z" level=debug msg="Updated systemd status to \"Stopped\"" 381s time="2024-07-18T22:45:06Z" level=debug msg="All connections have now ended." 381s --- PASS: TestReconnection (0.00s) 381s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (5.18s) 381s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (71.22s) 381s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (7.11s) 381s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 381s time="2024-07-18T22:45:06Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40685" 381s time="2024-07-18T22:45:06Z" level=debug msg="Building new daemon" 383s time="2024-07-18T22:45:08Z" level=info msg="Stopping daemon requested." 383s time="2024-07-18T22:45:08Z" level=info msg="Waiting for active requests to close." 383s time="2024-07-18T22:45:08Z" level=info msg="Stopping daemon requested." 383s time="2024-07-18T22:45:08Z" level=info msg="Waiting for active requests to close." 383s time="2024-07-18T22:45:08Z" level=debug msg="Updated systemd status to \"Stopped\"" 383s === CONT TestServeAndQuit/Success_with_double_quit 383s time="2024-07-18T22:45:08Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35891" 383s time="2024-07-18T22:45:08Z" level=debug msg="Building new daemon" 385s time="2024-07-18T22:45:10Z" level=debug msg="Ready state sent to systemd" 385s time="2024-07-18T22:45:10Z" level=info msg="Daemon: connecting to Windows Agent" 385s time="2024-07-18T22:45:10Z" level=debug msg="Updated systemd status to \"Connecting\"" 386s time="2024-07-18T22:45:11Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35891" 386s time="2024-07-18T22:45:11Z" level=info msg="Daemon: completed connection to Windows Agent" 386s time="2024-07-18T22:45:11Z" level=debug msg="Updated systemd status to \"Connected\"" 386s time="2024-07-18T22:45:11Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 386s time="2024-07-18T22:45:11Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 387s time="2024-07-18T22:45:12Z" level=debug msg="Server: sent preface messages to all streams" 387s time="2024-07-18T22:45:12Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 387s time="2024-07-18T22:45:12Z" level=info msg="MockWindowsAgent: Connected ready" 387s time="2024-07-18T22:45:12Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 387s time="2024-07-18T22:45:12Z" level=info msg="Stopping daemon requested." 387s time="2024-07-18T22:45:12Z" level=info msg="Waiting for active requests to close." 387s time="2024-07-18T22:45:12Z" level=warning msg="Daemon: disconnected from Windows host" 387s time="2024-07-18T22:45:12Z" level=info msg="Reconnecting to Windows host in 1 seconds" 387s time="2024-07-18T22:45:12Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 387s time="2024-07-18T22:45:12Z" level=debug msg="Updated systemd status to \"Stopped\"" 387s time="2024-07-18T22:45:12Z" level=debug msg="All connections have now ended." 387s time="2024-07-18T22:45:12Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 387s time="2024-07-18T22:45:12Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 387s time="2024-07-18T22:45:12Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 388s time="2024-07-18T22:45:12Z" level=info msg="Stopping daemon requested." 388s time="2024-07-18T22:45:12Z" level=info msg="Waiting for active requests to close." 388s time="2024-07-18T22:45:12Z" level=debug msg="All connections have now ended." 388s === CONT TestServeAndQuit/Success_with_forceful_quit 388s time="2024-07-18T22:45:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34165" 388s time="2024-07-18T22:45:12Z" level=debug msg="Building new daemon" 389s time="2024-07-18T22:45:14Z" level=debug msg="Ready state sent to systemd" 389s time="2024-07-18T22:45:14Z" level=info msg="Daemon: connecting to Windows Agent" 389s time="2024-07-18T22:45:14Z" level=debug msg="Updated systemd status to \"Connecting\"" 391s time="2024-07-18T22:45:15Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34165" 391s time="2024-07-18T22:45:15Z" level=info msg="Daemon: completed connection to Windows Agent" 391s time="2024-07-18T22:45:15Z" level=debug msg="Updated systemd status to \"Connected\"" 391s time="2024-07-18T22:45:15Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 391s time="2024-07-18T22:45:15Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 392s time="2024-07-18T22:45:16Z" level=debug msg="Server: sent preface messages to all streams" 392s time="2024-07-18T22:45:16Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 392s time="2024-07-18T22:45:16Z" level=info msg="MockWindowsAgent: Connected ready" 392s time="2024-07-18T22:45:16Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 392s time="2024-07-18T22:45:17Z" level=info msg="Stopping daemon requested." 392s time="2024-07-18T22:45:17Z" level=info msg="Stopping active requests." 392s time="2024-07-18T22:45:17Z" level=warning msg="Daemon: disconnected from Windows host" 392s time="2024-07-18T22:45:17Z" level=info msg="Reconnecting to Windows host in 1 seconds" 392s time="2024-07-18T22:45:17Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 392s time="2024-07-18T22:45:17Z" level=debug msg="Updated systemd status to \"Stopped\"" 392s time="2024-07-18T22:45:17Z" level=debug msg="All connections have now ended." 392s time="2024-07-18T22:45:17Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 392s time="2024-07-18T22:45:17Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 392s time="2024-07-18T22:45:17Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 392s --- PASS: TestServeAndQuit (0.00s) 392s --- PASS: TestServeAndQuit/Success_with_graceful_quit (4.26s) 392s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (1.99s) 392s --- PASS: TestServeAndQuit/Success_with_double_quit (4.23s) 392s --- PASS: TestServeAndQuit/Success_with_forceful_quit (4.18s) 392s === CONT TestServe/Error_because_the_context_is_pre-cancelled 392s time="2024-07-18T22:45:17Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42263" 392s time="2024-07-18T22:45:17Z" level=debug msg="Building new daemon" 394s time="2024-07-18T22:45:19Z" level=info msg="Stopping daemon requested." 394s time="2024-07-18T22:45:19Z" level=info msg="Waiting for active requests to close." 394s time="2024-07-18T22:45:19Z" level=debug msg="All connections have now ended." 394s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 394s time="2024-07-18T22:45:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34099" 394s time="2024-07-18T22:45:19Z" level=debug msg="Building new daemon" 396s time="2024-07-18T22:45:21Z" level=info msg="Daemon: connecting to Windows Agent" 397s time="2024-07-18T22:45:22Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34099" 397s time="2024-07-18T22:45:22Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file1042114479/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 397s time="2024-07-18T22:45:22Z" level=info msg="Reconnecting to Windows host in 1 seconds" 397s time="2024-07-18T22:45:22Z" level=info msg="Stopping daemon requested." 397s time="2024-07-18T22:45:22Z" level=info msg="Waiting for active requests to close." 397s time="2024-07-18T22:45:22Z" level=debug msg="All connections have now ended." 397s === CONT TestServe/No_connection_because_the_port_file_has_port_0 397s time="2024-07-18T22:45:22Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37913" 397s time="2024-07-18T22:45:22Z" level=debug msg="Building new daemon" 399s time="2024-07-18T22:45:24Z" level=info msg="Daemon: connecting to Windows Agent" 399s time="2024-07-18T22:45:24Z" 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" 399s time="2024-07-18T22:45:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 400s time="2024-07-18T22:45:25Z" level=info msg="Daemon: connecting to Windows Agent" 400s time="2024-07-18T22:45:25Z" 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" 400s time="2024-07-18T22:45:25Z" level=info msg="Reconnecting to Windows host in 2 seconds" 400s time="2024-07-18T22:45:25Z" level=info msg="Stopping daemon requested." 400s time="2024-07-18T22:45:25Z" level=info msg="Waiting for active requests to close." 400s time="2024-07-18T22:45:25Z" level=debug msg="All connections have now ended." 400s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 400s time="2024-07-18T22:45:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35489" 400s time="2024-07-18T22:45:25Z" level=debug msg="Building new daemon" 402s time="2024-07-18T22:45:27Z" level=info msg="Daemon: connecting to Windows Agent" 402s time="2024-07-18T22:45:27Z" 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" 402s time="2024-07-18T22:45:27Z" level=info msg="Reconnecting to Windows host in 1 seconds" 403s time="2024-07-18T22:45:28Z" level=info msg="Daemon: connecting to Windows Agent" 403s time="2024-07-18T22:45:28Z" 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" 403s time="2024-07-18T22:45:28Z" level=info msg="Reconnecting to Windows host in 2 seconds" 403s time="2024-07-18T22:45:28Z" level=info msg="Stopping daemon requested." 403s time="2024-07-18T22:45:28Z" level=info msg="Waiting for active requests to close." 403s time="2024-07-18T22:45:28Z" level=debug msg="All connections have now ended." 403s === CONT TestServe/No_connection_because_the_port_file_is_empty 403s time="2024-07-18T22:45:28Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42245" 403s time="2024-07-18T22:45:28Z" level=debug msg="Building new daemon" 405s time="2024-07-18T22:45:30Z" level=info msg="Daemon: connecting to Windows Agent" 405s time="2024-07-18T22:45:30Z" 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" 405s time="2024-07-18T22:45:30Z" level=info msg="Reconnecting to Windows host in 1 seconds" 406s time="2024-07-18T22:45:31Z" level=info msg="Daemon: connecting to Windows Agent" 406s time="2024-07-18T22:45:31Z" 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" 406s time="2024-07-18T22:45:31Z" level=info msg="Reconnecting to Windows host in 2 seconds" 406s time="2024-07-18T22:45:31Z" level=info msg="Stopping daemon requested." 406s time="2024-07-18T22:45:31Z" level=info msg="Waiting for active requests to close." 406s time="2024-07-18T22:45:31Z" level=debug msg="All connections have now ended." 406s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 406s time="2024-07-18T22:45:31Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40891" 406s time="2024-07-18T22:45:31Z" level=debug msg="Building new daemon" 408s time="2024-07-18T22:45:33Z" level=info msg="Daemon: connecting to Windows Agent" 408s time="2024-07-18T22:45:33Z" 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_exist1040709962/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist1040709962/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 408s time="2024-07-18T22:45:33Z" level=info msg="Reconnecting to Windows host in 1 seconds" 409s time="2024-07-18T22:45:34Z" level=info msg="Daemon: connecting to Windows Agent" 409s time="2024-07-18T22:45:34Z" 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_exist1040709962/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist1040709962/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 409s time="2024-07-18T22:45:34Z" level=info msg="Reconnecting to Windows host in 2 seconds" 409s time="2024-07-18T22:45:34Z" level=info msg="Stopping daemon requested." 409s time="2024-07-18T22:45:34Z" level=info msg="Waiting for active requests to close." 409s time="2024-07-18T22:45:34Z" level=debug msg="All connections have now ended." 409s === CONT TestServe/Error_because_the_notifier_returns_an_error 409s time="2024-07-18T22:45:34Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40347" 409s time="2024-07-18T22:45:34Z" level=debug msg="Building new daemon" 411s time="2024-07-18T22:45:36Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 411s time="2024-07-18T22:45:36Z" level=info msg="Stopping daemon requested." 411s time="2024-07-18T22:45:36Z" level=info msg="Waiting for active requests to close." 411s time="2024-07-18T22:45:36Z" level=debug msg="All connections have now ended." 411s === CONT TestServe/No_connection_because_there_are_no_certificates 411s time="2024-07-18T22:45:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35459" 411s time="2024-07-18T22:45:36Z" level=debug msg="Building new daemon" 413s time="2024-07-18T22:45:38Z" level=info msg="Daemon: connecting to Windows Agent" 414s time="2024-07-18T22:45:39Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35459" 414s time="2024-07-18T22:45:39Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates194859200/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 414s time="2024-07-18T22:45:39Z" level=info msg="Reconnecting to Windows host in 1 seconds" 414s time="2024-07-18T22:45:39Z" level=info msg="Stopping daemon requested." 414s time="2024-07-18T22:45:39Z" level=info msg="Waiting for active requests to close." 414s time="2024-07-18T22:45:39Z" level=debug msg="All connections have now ended." 414s === CONT TestServe/No_connection_because_there_is_no_server 414s time="2024-07-18T22:45:39Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36349" 414s time="2024-07-18T22:45:39Z" level=debug msg="Building new daemon" 416s time="2024-07-18T22:45:41Z" level=info msg="Daemon: connecting to Windows Agent" 417s time="2024-07-18T22:45:42Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:36349" 417s time="2024-07-18T22:45:42Z" level=info msg="Daemon: completed connection to Windows Agent" 417s time="2024-07-18T22:45:42Z" 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:36349: connect: connection refused\"" 417s time="2024-07-18T22:45:42Z" level=info msg="Reconnecting to Windows host in 1 seconds" 418s time="2024-07-18T22:45:43Z" level=info msg="Stopping daemon requested." 418s time="2024-07-18T22:45:43Z" level=info msg="Waiting for active requests to close." 418s time="2024-07-18T22:45:43Z" level=debug msg="All connections have now ended." 418s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 418s time="2024-07-18T22:45:43Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34503" 418s time="2024-07-18T22:45:43Z" level=debug msg="Building new daemon" 420s time="2024-07-18T22:45:45Z" level=info msg="Daemon: connecting to Windows Agent" 420s time="2024-07-18T22:45:45Z" 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" 420s time="2024-07-18T22:45:45Z" level=info msg="Reconnecting to Windows host in 1 seconds" 421s time="2024-07-18T22:45:46Z" level=info msg="Stopping daemon requested." 421s time="2024-07-18T22:45:46Z" level=info msg="Waiting for active requests to close." 421s time="2024-07-18T22:45:46Z" level=debug msg="All connections have now ended." 421s === CONT TestServe/Success_with_systemd_notifier_returning_true 421s time="2024-07-18T22:45:46Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40629" 421s time="2024-07-18T22:45:46Z" level=debug msg="Building new daemon" 423s time="2024-07-18T22:45:48Z" level=debug msg="Ready state sent to systemd" 423s time="2024-07-18T22:45:48Z" level=info msg="Daemon: connecting to Windows Agent" 423s time="2024-07-18T22:45:48Z" level=debug msg="Updated systemd status to \"Connecting\"" 424s time="2024-07-18T22:45:49Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40629" 424s time="2024-07-18T22:45:49Z" level=info msg="Daemon: completed connection to Windows Agent" 424s time="2024-07-18T22:45:49Z" level=debug msg="Updated systemd status to \"Connected\"" 424s time="2024-07-18T22:45:49Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 424s time="2024-07-18T22:45:49Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 425s time="2024-07-18T22:45:50Z" level=debug msg="Server: sent preface messages to all streams" 425s time="2024-07-18T22:45:50Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 425s time="2024-07-18T22:45:50Z" level=info msg="MockWindowsAgent: Connected ready" 425s time="2024-07-18T22:45:50Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 427s time="2024-07-18T22:45:52Z" level=info msg="Stopping daemon requested." 427s time="2024-07-18T22:45:52Z" level=info msg="Waiting for active requests to close." 427s time="2024-07-18T22:45:52Z" level=warning msg="Daemon: disconnected from Windows host" 427s time="2024-07-18T22:45:52Z" level=info msg="Reconnecting to Windows host in 1 seconds" 427s time="2024-07-18T22:45:52Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 427s time="2024-07-18T22:45:52Z" level=debug msg="Updated systemd status to \"Stopped\"" 427s time="2024-07-18T22:45:52Z" level=debug msg="All connections have now ended." 427s time="2024-07-18T22:45:52Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 427s time="2024-07-18T22:45:52Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 427s time="2024-07-18T22:45:52Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 427s === CONT TestServe/Success 427s time="2024-07-18T22:45:52Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42923" 427s time="2024-07-18T22:45:52Z" level=debug msg="Building new daemon" 429s time="2024-07-18T22:45:54Z" level=info msg="Daemon: connecting to Windows Agent" 430s time="2024-07-18T22:45:55Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:42923" 430s time="2024-07-18T22:45:55Z" level=info msg="Daemon: completed connection to Windows Agent" 430s time="2024-07-18T22:45:55Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 430s time="2024-07-18T22:45:55Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 431s time="2024-07-18T22:45:56Z" level=debug msg="Server: sent preface messages to all streams" 431s time="2024-07-18T22:45:56Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 431s time="2024-07-18T22:45:56Z" level=info msg="MockWindowsAgent: Connected ready" 431s time="2024-07-18T22:45:56Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 433s time="2024-07-18T22:45:58Z" level=info msg="Stopping daemon requested." 433s time="2024-07-18T22:45:58Z" level=info msg="Waiting for active requests to close." 433s time="2024-07-18T22:45:58Z" level=warning msg="Daemon: disconnected from Windows host" 433s time="2024-07-18T22:45:58Z" level=info msg="Reconnecting to Windows host in 1 seconds" 433s time="2024-07-18T22:45:58Z" level=debug msg="All connections have now ended." 433s time="2024-07-18T22:45:58Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 433s time="2024-07-18T22:45:58Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 433s time="2024-07-18T22:45:58Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 433s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 433s time="2024-07-18T22:45:58Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33281" 433s time="2024-07-18T22:45:58Z" level=debug msg="Building new daemon" 435s time="2024-07-18T22:46:00Z" level=info msg="Daemon: connecting to Windows Agent" 436s time="2024-07-18T22:46:01Z" level=info msg="Stopping daemon requested." 436s time="2024-07-18T22:46:01Z" level=info msg="Waiting for active requests to close." 436s time="2024-07-18T22:46:01Z" level=debug msg="All connections have now ended." 436s --- PASS: TestServe (0.00s) 436s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (1.98s) 436s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (2.96s) 436s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (2.99s) 436s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (3.00s) 436s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (3.01s) 436s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (3.00s) 436s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (1.99s) 436s --- PASS: TestServe/No_connection_because_there_are_no_certificates (3.00s) 436s --- PASS: TestServe/No_connection_because_there_is_no_server (3.99s) 436s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (3.00s) 436s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (5.98s) 436s --- PASS: TestServe/Success (5.98s) 436s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (2.98s) 436s PASS 436s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 146.204s 436s === RUN TestConnect 436s === PAUSE TestConnect 436s === RUN TestSendAndRecv 437s --- PASS: TestSendAndRecv (0.40s) 437s === RUN TestServe 437s === PAUSE TestServe 437s === RUN TestStop 437s === PAUSE TestStop 437s === RUN TestWithProMock 437s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 437s --- SKIP: TestWithProMock (0.00s) 437s === RUN TestWithWslPathMock 437s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 437s --- SKIP: TestWithWslPathMock (0.00s) 437s === RUN TestWithWslInfoMock 437s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 437s --- SKIP: TestWithWslInfoMock (0.00s) 437s === RUN TestWithCmdExeMock 437s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 437s --- SKIP: TestWithCmdExeMock (0.00s) 437s === CONT TestConnect 437s === RUN TestConnect/Success 437s === PAUSE TestConnect/Success 437s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 437s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 437s === CONT TestConnect/Success 437s === CONT TestStop 437s time="2024-07-18T22:46:02Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45917" 438s time="2024-07-18T22:46:03Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 438s time="2024-07-18T22:46:03Z" level=info msg="MockWindowsAgent: Connected ready" 438s time="2024-07-18T22:46:03Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 448s time="2024-07-18T22:46:13Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 448s --- PASS: TestStop (11.11s) 448s === CONT TestServe 448s time="2024-07-18T22:46:13Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 448s time="2024-07-18T22:46:13Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 448s time="2024-07-18T22:46:13Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42897" 449s time="2024-07-18T22:46:14Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 449s time="2024-07-18T22:46:14Z" level=info msg="MockWindowsAgent: Connected ready" 449s time="2024-07-18T22:46:14Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 453s time="2024-07-18T22:46:18Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 453s --- PASS: TestServe (4.94s) 453s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 453s time="2024-07-18T22:46:18Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 453s time="2024-07-18T22:46:18Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 473s --- PASS: TestConnect (0.00s) 473s --- PASS: TestConnect/Success (0.30s) 473s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.00s) 473s PASS 473s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 36.762s 474s === RUN TestInfo 474s === PAUSE TestInfo 474s === RUN TestWslDistroName 474s === PAUSE TestWslDistroName 474s === RUN TestUserProfileDir 474s === PAUSE TestUserProfileDir 474s === RUN TestProStatus 474s === PAUSE TestProStatus 474s === RUN TestProAttach 474s === PAUSE TestProAttach 474s === RUN TestProDetach 474s === PAUSE TestProDetach 474s === RUN TestLandscapeEnable 474s === PAUSE TestLandscapeEnable 474s === RUN TestWindowsHostAddress 474s === PAUSE TestWindowsHostAddress 474s === RUN TestLandscapeDisable 474s === PAUSE TestLandscapeDisable 474s === RUN TestRealBackend 474s === PAUSE TestRealBackend 474s === RUN TestWithProMock 474s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 474s --- SKIP: TestWithProMock (0.00s) 474s === RUN TestWithLandscapeConfigMock 474s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 474s --- SKIP: TestWithLandscapeConfigMock (0.00s) 474s === RUN TestWithWslPathMock 474s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 474s --- SKIP: TestWithWslPathMock (0.00s) 474s === RUN TestWithWslInfoMock 474s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 474s --- SKIP: TestWithWslInfoMock (0.00s) 474s === RUN TestWithCmdExeMock 474s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 474s --- SKIP: TestWithCmdExeMock (0.00s) 474s === CONT TestInfo 474s === RUN TestInfo/Success 474s === PAUSE TestInfo/Success 474s === RUN TestInfo/Error_when_WslDistroName_fails 474s === PAUSE TestInfo/Error_when_WslDistroName_fails 474s === RUN TestInfo/Error_when_pro_status_command_fails 474s === PAUSE TestInfo/Error_when_pro_status_command_fails 474s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 474s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 474s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 474s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 474s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 474s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 474s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 474s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 474s === CONT TestInfo/Success 475s === CONT TestRealBackend 475s --- PASS: TestRealBackend (0.00s) 475s === CONT TestLandscapeDisable 475s === RUN TestLandscapeDisable/Success 475s === PAUSE TestLandscapeDisable/Success 475s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 475s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 475s === CONT TestWindowsHostAddress 475s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 475s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 475s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 475s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 475s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 475s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 475s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 475s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 475s === RUN TestWindowsHostAddress/Success_without_NAT 475s === PAUSE TestWindowsHostAddress/Success_without_NAT 476s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 476s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 476s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 476s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 476s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 476s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 476s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 476s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 476s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 476s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 476s === CONT TestLandscapeEnable 476s === RUN TestLandscapeEnable/Success 476s === PAUSE TestLandscapeEnable/Success 476s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 476s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 476s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 476s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 476s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 476s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 476s === RUN TestLandscapeEnable/Success_overriding_computer_title 476s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 476s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 476s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 476s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 476s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 476s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 476s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 476s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 476s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 476s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 476s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 476s === CONT TestProDetach 476s === RUN TestProDetach/success_on_unattached_distro 476s === PAUSE TestProDetach/success_on_unattached_distro 476s === RUN TestProDetach/success_on_attached_distro 476s === PAUSE TestProDetach/success_on_attached_distro 476s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 476s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 476s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 476s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 476s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 476s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 476s === CONT TestProAttach 476s === RUN TestProAttach/success 476s === PAUSE TestProAttach/success 476s === RUN TestProAttach/error_on_'pro_attach'_error 476s === PAUSE TestProAttach/error_on_'pro_attach'_error 476s === CONT TestProStatus 476s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 476s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 476s === RUN TestProStatus/error_on_'pro_attach'_error 476s === PAUSE TestProStatus/error_on_'pro_attach'_error 476s === RUN TestProStatus/success_on_unattached_distro 476s === PAUSE TestProStatus/success_on_unattached_distro 476s === RUN TestProStatus/success_on_attached_distro 476s === PAUSE TestProStatus/success_on_attached_distro 476s === CONT TestUserProfileDir 476s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 476s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 476s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 476s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 476s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 476s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 476s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 476s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 476s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 476s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 476s === RUN TestUserProfileDir/Error_on_cmd.exe_error 476s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 476s === RUN TestUserProfileDir/Error_on_wslpath_error 476s === PAUSE TestUserProfileDir/Error_on_wslpath_error 476s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 476s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 476s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 476s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 476s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 476s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 476s === CONT TestWslDistroName 476s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 476s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 476s === RUN TestWslDistroName/Success_using_wslpath 476s === PAUSE TestWslDistroName/Success_using_wslpath 476s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 476s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 476s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 476s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 476s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 476s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 477s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 478s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 479s === CONT TestInfo/Error_when_pro_status_command_fails 480s === CONT TestInfo/Error_when_WslDistroName_fails 481s --- PASS: TestInfo (0.00s) 481s --- PASS: TestInfo/Success (1.07s) 481s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (0.95s) 481s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (0.94s) 481s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (0.95s) 481s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (0.95s) 481s --- PASS: TestInfo/Error_when_pro_status_command_fails (0.95s) 481s --- PASS: TestInfo/Error_when_WslDistroName_fails (0.95s) 481s === CONT TestLandscapeDisable/Success 482s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 483s --- PASS: TestLandscapeDisable (0.00s) 483s --- PASS: TestLandscapeDisable/Success (0.96s) 483s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (0.96s) 483s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 484s === CONT TestLandscapeEnable/Success 485s system_test.go:456: testdata/TestLandscapeEnable/golden/success 485s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 486s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 487s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 488s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 489s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 490s === CONT TestWindowsHostAddress/Success_without_NAT 491s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 492s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 493s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 494s --- PASS: TestWindowsHostAddress (0.00s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (0.97s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (0.95s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (0.97s) 494s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (0.96s) 494s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (0.94s) 494s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (0.96s) 494s --- PASS: TestWindowsHostAddress/Success_without_NAT (0.97s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (0.97s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (0.96s) 494s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (0.95s) 494s === CONT TestProDetach/success_on_unattached_distro 495s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 495s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 495s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 495s time="2024-07-18T22:47:00Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 495s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 495s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 495s time="2024-07-18T22:47:00Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 496s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 496s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 498s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 498s === CONT TestLandscapeEnable/Success_overriding_computer_title 498s time="2024-07-18T22:47:03Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 499s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 499s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 500s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 501s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 501s --- PASS: TestLandscapeEnable (0.00s) 501s --- PASS: TestLandscapeEnable/Success (0.96s) 501s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 501s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 501s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (0.94s) 501s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (0.96s) 501s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (1.93s) 501s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (0.96s) 501s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (0.97s) 501s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (0.95s) 501s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 501s === CONT TestProAttach/success 502s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 503s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 504s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 505s === CONT TestProDetach/success_on_attached_distro 506s --- PASS: TestProDetach (0.00s) 506s --- PASS: TestProDetach/success_on_unattached_distro (0.94s) 506s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (0.96s) 506s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (0.95s) 506s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (0.96s) 506s --- PASS: TestProDetach/success_on_attached_distro (0.96s) 506s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 507s === CONT TestProAttach/error_on_'pro_attach'_error 508s --- PASS: TestProAttach (0.00s) 508s --- PASS: TestProAttach/success (0.95s) 508s --- PASS: TestProAttach/error_on_'pro_attach'_error (0.96s) 508s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 510s === CONT TestProStatus/success_on_attached_distro 511s === CONT TestProStatus/success_on_unattached_distro 512s === CONT TestProStatus/error_on_'pro_attach'_error 513s --- PASS: TestProStatus (0.00s) 513s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (0.95s) 513s --- PASS: TestProStatus/success_on_attached_distro (0.96s) 513s --- PASS: TestProStatus/success_on_unattached_distro (0.95s) 513s --- PASS: TestProStatus/error_on_'pro_attach'_error (0.96s) 513s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 513s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 513s system_test.go:205: Removing default proc/mounts 513s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 515s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 517s === CONT TestUserProfileDir/Error_on_wslpath_error 519s === CONT TestUserProfileDir/Error_on_cmd.exe_error 520s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 520s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 522s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 524s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 524s system_test.go:205: Removing default proc/mounts 524s --- PASS: TestUserProfileDir (0.00s) 524s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (1.92s) 524s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 524s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (1.95s) 524s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (2.09s) 524s --- PASS: TestUserProfileDir/Error_on_wslpath_error (2.12s) 524s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (0.97s) 524s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 524s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (1.92s) 524s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (1.89s) 524s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 524s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 525s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 526s === CONT TestWslDistroName/Success_using_wslpath 527s --- PASS: TestWslDistroName (0.00s) 527s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 527s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (0.94s) 527s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (0.97s) 527s --- PASS: TestWslDistroName/Success_using_wslpath (0.93s) 527s PASS 527s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 52.183s 527s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 527s autopkgtest [22:47:32]: test command1: -----------------------] 528s autopkgtest [22:47:33]: test command1: - - - - - - - - - - results - - - - - - - - - - 528s command1 PASS 528s autopkgtest [22:47:33]: @@@@@@@@@@@@@@@@@@@@ summary 528s command1 PASS 540s nova [W] Using flock in scalingstack-bos01-ppc64el 540s Creating nova instance adt-noble-ppc64el-wsl-pro-service-20240718-223845-juju-7f2275-prod-proposed-migration-environment-3-cdc7261f-54e2-4070-acaf-36d576c35c15 from image adt/ubuntu-noble-ppc64el-server-20240718.img (UUID 8681a7b2-bccb-46f5-9ee3-ad3852f54345)...