0s autopkgtest [22:38:46]: starting date and time: 2024-07-18 22:38:46+0000 0s autopkgtest [22:38:46]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [22:38:46]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.grb1k7jc/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-s390x-19.secgroup --name adt-noble-s390x-wsl-pro-service-20240718-223846-juju-7f2275-prod-proposed-migration-environment-3-895c74c6-d878-4c1e-8bdf-e5d3da72ec8e --image adt/ubuntu-noble-s390x-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/ 93s autopkgtest [22:40:19]: testbed dpkg architecture: s390x 93s autopkgtest [22:40:19]: testbed apt version: 2.7.14build2 93s autopkgtest [22:40:19]: @@@@@@@@@@@@@@@@@@@@ test bed setup 94s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [265 kB] 95s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [33.0 kB] 95s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [9944 B] 95s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [5700 B] 95s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [51.2 kB] 95s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [2480 B] 95s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [1176 B] 95s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 95s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [38.1 kB] 95s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [1180 B] 95s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 96s Fetched 408 kB in 1s (633 kB/s) 96s Reading package lists... 98s Reading package lists... 99s Building dependency tree... 99s Reading state information... 99s Calculating upgrade... 99s The following packages will be upgraded: 99s ubuntu-pro-client ubuntu-pro-client-l10n xkb-data 99s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 99s Need to get 648 kB of archives. 99s After this operation, 25.6 kB of additional disk space will be used. 99s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x ubuntu-pro-client-l10n s390x 33.2~24.04 [19.3 kB] 99s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x ubuntu-pro-client s390x 33.2~24.04 [231 kB] 99s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main s390x xkb-data all 2.41-2ubuntu1.1 [397 kB] 100s Fetched 648 kB in 1s (1195 kB/s) 100s (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 ... 78194 files and directories currently installed.) 100s Preparing to unpack .../ubuntu-pro-client-l10n_33.2~24.04_s390x.deb ... 100s Unpacking ubuntu-pro-client-l10n (33.2~24.04) over (32.3.1~24.04) ... 100s Preparing to unpack .../ubuntu-pro-client_33.2~24.04_s390x.deb ... 100s Unpacking ubuntu-pro-client (33.2~24.04) over (32.3.1~24.04) ... 100s Preparing to unpack .../xkb-data_2.41-2ubuntu1.1_all.deb ... 100s Unpacking xkb-data (2.41-2ubuntu1.1) over (2.41-2ubuntu1) ... 100s Setting up xkb-data (2.41-2ubuntu1.1) ... 100s Setting up ubuntu-pro-client (33.2~24.04) ... 100s Installing new version of config file /etc/apparmor.d/ubuntu_pro_apt_news ... 102s Setting up ubuntu-pro-client-l10n (33.2~24.04) ... 102s Processing triggers for man-db (2.12.0-4build2) ... 102s Reading package lists... 102s Building dependency tree... 102s Reading state information... 103s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 103s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 103s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 103s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 103s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 104s Reading package lists... 104s Reading package lists... 104s Building dependency tree... 104s Reading state information... 104s Calculating upgrade... 105s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 105s Reading package lists... 105s Building dependency tree... 105s Reading state information... 105s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 105s autopkgtest [22:40:31]: rebooting testbed after setup commands that affected boot 109s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 130s autopkgtest [22:40:56]: testbed running kernel: Linux 6.8.0-38-generic #38-Ubuntu SMP Fri Jun 7 14:30:57 UTC 2024 133s autopkgtest [22:40:59]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 135s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 135s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 135s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 135s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 135s gpgv: Can't check signature: No public key 135s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 135s autopkgtest [22:41:01]: testing package wsl-pro-service version 0.1.4 135s autopkgtest [22:41:01]: build not needed 141s autopkgtest [22:41:07]: test command1: preparing testbed 142s Reading package lists... 142s Building dependency tree... 142s Reading state information... 143s Starting pkgProblemResolver with broken count: 0 143s Starting 2 pkgProblemResolver with broken count: 0 143s Done 143s The following additional packages will be installed: 143s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 143s cpp-13-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit dh-apport 143s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 143s g++-13-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-13 gcc-13-base 143s gcc-13-s390x-linux-gnu gcc-s390x-linux-gnu gettext golang-1.22-go 143s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 143s libasan8 libatomic1 libcc1-0 libdebhelper-perl 143s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 143s libmpc3 libstdc++-13-dev libsub-override-perl libtool libubsan1 m4 143s po-debconf 143s Suggested packages: 143s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 143s cpp-13-doc dh-make g++-multilib g++-13-multilib gcc-13-doc gcc-multilib 143s manpages-dev flex bison gdb gcc-doc gcc-13-multilib gdb-s390x-linux-gnu 143s gettext-doc libasprintf-dev libgettextpo-dev bzr | brz git mercurial 143s subversion libstdc++-13-doc libtool-doc gfortran | fortran95-compiler 143s gcj-jdk m4-doc libmail-box-perl 143s Recommended packages: 143s pkg-config libarchive-cpio-perl libltdl-dev libmail-sendmail-perl 143s The following NEW packages will be installed: 143s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 143s cpp cpp-13 cpp-13-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit 143s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 143s g++-13-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-13 gcc-13-base 143s gcc-13-s390x-linux-gnu gcc-s390x-linux-gnu gettext golang-1.22-go 143s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 143s libasan8 libatomic1 libcc1-0 libdebhelper-perl 143s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 143s libmpc3 libstdc++-13-dev libsub-override-perl libtool libubsan1 m4 143s po-debconf 143s 0 upgraded, 49 newly installed, 0 to remove and 0 not upgraded. 143s Need to get 98.4 MB/98.4 MB of archives. 143s After this operation, 410 MB of additional disk space will be used. 143s Get:1 /tmp/autopkgtest.Bd8iYp/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [760 B] 143s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x m4 s390x 1.4.19-4build1 [256 kB] 143s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x autoconf all 2.71-3 [339 kB] 144s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x autotools-dev all 20220109.1 [44.9 kB] 144s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x automake all 1:1.16.5-1.3ubuntu1 [558 kB] 144s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x autopoint all 0.21-14ubuntu2 [422 kB] 144s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13-base s390x 13.2.0-23ubuntu4 [48.9 kB] 144s Get:8 http://ftpmaster.internal/ubuntu noble/main s390x libisl23 s390x 0.26-3build1 [713 kB] 144s Get:9 http://ftpmaster.internal/ubuntu noble/main s390x libmpc3 s390x 1.3.1-1build1 [58.4 kB] 144s Get:10 http://ftpmaster.internal/ubuntu noble/main s390x cpp-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [9939 kB] 144s Get:11 http://ftpmaster.internal/ubuntu noble/main s390x cpp-13 s390x 13.2.0-23ubuntu4 [1030 B] 144s Get:12 http://ftpmaster.internal/ubuntu noble/main s390x cpp-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [5308 B] 144s Get:13 http://ftpmaster.internal/ubuntu noble/main s390x cpp s390x 4:13.2.0-7ubuntu1 [22.4 kB] 144s Get:14 http://ftpmaster.internal/ubuntu noble/main s390x libcc1-0 s390x 14-20240412-0ubuntu1 [49.9 kB] 144s Get:15 http://ftpmaster.internal/ubuntu noble/main s390x libgomp1 s390x 14-20240412-0ubuntu1 [151 kB] 144s Get:16 http://ftpmaster.internal/ubuntu noble/main s390x libitm1 s390x 14-20240412-0ubuntu1 [31.1 kB] 144s Get:17 http://ftpmaster.internal/ubuntu noble/main s390x libatomic1 s390x 14-20240412-0ubuntu1 [9398 B] 144s Get:18 http://ftpmaster.internal/ubuntu noble/main s390x libasan8 s390x 14-20240412-0ubuntu1 [3003 kB] 144s Get:19 http://ftpmaster.internal/ubuntu noble/main s390x libubsan1 s390x 14-20240412-0ubuntu1 [1188 kB] 144s Get:20 http://ftpmaster.internal/ubuntu noble/main s390x libgcc-13-dev s390x 13.2.0-23ubuntu4 [1004 kB] 144s Get:21 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [19.1 MB] 145s Get:22 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13 s390x 13.2.0-23ubuntu4 [472 kB] 145s Get:23 http://ftpmaster.internal/ubuntu noble/main s390x gcc-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [1208 B] 145s Get:24 http://ftpmaster.internal/ubuntu noble/main s390x gcc s390x 4:13.2.0-7ubuntu1 [5014 B] 145s Get:25 http://ftpmaster.internal/ubuntu noble/main s390x libstdc++-13-dev s390x 13.2.0-23ubuntu4 [2494 kB] 145s Get:26 http://ftpmaster.internal/ubuntu noble/main s390x g++-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [11.3 MB] 145s Get:27 http://ftpmaster.internal/ubuntu noble/main s390x g++-13 s390x 13.2.0-23ubuntu4 [14.5 kB] 145s Get:28 http://ftpmaster.internal/ubuntu noble/main s390x g++-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [956 B] 145s Get:29 http://ftpmaster.internal/ubuntu noble/main s390x g++ s390x 4:13.2.0-7ubuntu1 [1096 B] 145s Get:30 http://ftpmaster.internal/ubuntu noble/main s390x build-essential s390x 12.10ubuntu1 [4930 B] 145s Get:31 http://ftpmaster.internal/ubuntu noble/main s390x libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 145s Get:32 http://ftpmaster.internal/ubuntu noble/main s390x libtool all 2.4.7-7build1 [166 kB] 145s Get:33 http://ftpmaster.internal/ubuntu noble/main s390x dh-autoreconf all 20 [16.1 kB] 145s Get:34 http://ftpmaster.internal/ubuntu noble/main s390x libarchive-zip-perl all 1.68-1 [90.2 kB] 145s Get:35 http://ftpmaster.internal/ubuntu noble/main s390x libsub-override-perl all 0.10-1 [10.0 kB] 145s Get:36 http://ftpmaster.internal/ubuntu noble/main s390x libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 145s Get:37 http://ftpmaster.internal/ubuntu noble/main s390x dh-strip-nondeterminism all 1.13.1-1 [5362 B] 145s Get:38 http://ftpmaster.internal/ubuntu noble/main s390x debugedit s390x 1:5.0-5build2 [50.5 kB] 145s Get:39 http://ftpmaster.internal/ubuntu noble/main s390x dwz s390x 0.15-1build6 [122 kB] 145s Get:40 http://ftpmaster.internal/ubuntu noble/main s390x gettext s390x 0.21-14ubuntu2 [915 kB] 145s Get:41 http://ftpmaster.internal/ubuntu noble/main s390x intltool-debian all 0.35.0+20060710.6 [23.2 kB] 145s Get:42 http://ftpmaster.internal/ubuntu noble/main s390x po-debconf all 1.0.21+nmu1 [233 kB] 145s Get:43 http://ftpmaster.internal/ubuntu noble/main s390x debhelper all 13.14.1ubuntu5 [869 kB] 145s Get:44 http://ftpmaster.internal/ubuntu noble-updates/universe s390x dh-apport all 2.28.1-0ubuntu3 [17.2 kB] 145s Get:45 http://ftpmaster.internal/ubuntu noble-updates/main s390x golang-1.22-src all 1.22.2-2ubuntu0.1 [19.7 MB] 146s Get:46 http://ftpmaster.internal/ubuntu noble-updates/main s390x golang-1.22-go s390x 1.22.2-2ubuntu0.1 [24.7 MB] 147s Get:47 http://ftpmaster.internal/ubuntu noble/main s390x golang-src all 2:1.22~2build1 [5078 B] 147s Get:48 http://ftpmaster.internal/ubuntu noble/main s390x golang-go s390x 2:1.22~2build1 [44.0 kB] 147s Get:49 http://ftpmaster.internal/ubuntu noble/main s390x dh-golang all 1.62 [25.2 kB] 147s Fetched 98.4 MB in 4s (24.9 MB/s) 147s Selecting previously unselected package m4. 147s (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 ... 78195 files and directories currently installed.) 147s Preparing to unpack .../00-m4_1.4.19-4build1_s390x.deb ... 147s Unpacking m4 (1.4.19-4build1) ... 147s Selecting previously unselected package autoconf. 147s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 147s Unpacking autoconf (2.71-3) ... 147s Selecting previously unselected package autotools-dev. 147s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 147s Unpacking autotools-dev (20220109.1) ... 147s Selecting previously unselected package automake. 147s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 147s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 147s Selecting previously unselected package autopoint. 147s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 147s Unpacking autopoint (0.21-14ubuntu2) ... 147s Selecting previously unselected package gcc-13-base:s390x. 147s Preparing to unpack .../05-gcc-13-base_13.2.0-23ubuntu4_s390x.deb ... 147s Unpacking gcc-13-base:s390x (13.2.0-23ubuntu4) ... 147s Selecting previously unselected package libisl23:s390x. 147s Preparing to unpack .../06-libisl23_0.26-3build1_s390x.deb ... 147s Unpacking libisl23:s390x (0.26-3build1) ... 147s Selecting previously unselected package libmpc3:s390x. 147s Preparing to unpack .../07-libmpc3_1.3.1-1build1_s390x.deb ... 147s Unpacking libmpc3:s390x (1.3.1-1build1) ... 147s Selecting previously unselected package cpp-13-s390x-linux-gnu. 147s Preparing to unpack .../08-cpp-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 147s Unpacking cpp-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 148s Selecting previously unselected package cpp-13. 148s Preparing to unpack .../09-cpp-13_13.2.0-23ubuntu4_s390x.deb ... 148s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 148s Selecting previously unselected package cpp-s390x-linux-gnu. 148s Preparing to unpack .../10-cpp-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 148s Unpacking cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 148s Selecting previously unselected package cpp. 148s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_s390x.deb ... 148s Unpacking cpp (4:13.2.0-7ubuntu1) ... 148s Selecting previously unselected package libcc1-0:s390x. 148s Preparing to unpack .../12-libcc1-0_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libcc1-0:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libgomp1:s390x. 148s Preparing to unpack .../13-libgomp1_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libgomp1:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libitm1:s390x. 148s Preparing to unpack .../14-libitm1_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libitm1:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libatomic1:s390x. 148s Preparing to unpack .../15-libatomic1_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libatomic1:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libasan8:s390x. 148s Preparing to unpack .../16-libasan8_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libasan8:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libubsan1:s390x. 148s Preparing to unpack .../17-libubsan1_14-20240412-0ubuntu1_s390x.deb ... 148s Unpacking libubsan1:s390x (14-20240412-0ubuntu1) ... 148s Selecting previously unselected package libgcc-13-dev:s390x. 148s Preparing to unpack .../18-libgcc-13-dev_13.2.0-23ubuntu4_s390x.deb ... 148s Unpacking libgcc-13-dev:s390x (13.2.0-23ubuntu4) ... 148s Selecting previously unselected package gcc-13-s390x-linux-gnu. 148s Preparing to unpack .../19-gcc-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 148s Unpacking gcc-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 148s Selecting previously unselected package gcc-13. 148s Preparing to unpack .../20-gcc-13_13.2.0-23ubuntu4_s390x.deb ... 148s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 148s Selecting previously unselected package gcc-s390x-linux-gnu. 148s Preparing to unpack .../21-gcc-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 148s Unpacking gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 148s Selecting previously unselected package gcc. 148s Preparing to unpack .../22-gcc_4%3a13.2.0-7ubuntu1_s390x.deb ... 148s Unpacking gcc (4:13.2.0-7ubuntu1) ... 148s Selecting previously unselected package libstdc++-13-dev:s390x. 148s Preparing to unpack .../23-libstdc++-13-dev_13.2.0-23ubuntu4_s390x.deb ... 148s Unpacking libstdc++-13-dev:s390x (13.2.0-23ubuntu4) ... 149s Selecting previously unselected package g++-13-s390x-linux-gnu. 149s Preparing to unpack .../24-g++-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 149s Unpacking g++-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 149s Selecting previously unselected package g++-13. 149s Preparing to unpack .../25-g++-13_13.2.0-23ubuntu4_s390x.deb ... 149s Unpacking g++-13 (13.2.0-23ubuntu4) ... 149s Selecting previously unselected package g++-s390x-linux-gnu. 149s Preparing to unpack .../26-g++-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 149s Unpacking g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 149s Selecting previously unselected package g++. 149s Preparing to unpack .../27-g++_4%3a13.2.0-7ubuntu1_s390x.deb ... 149s Unpacking g++ (4:13.2.0-7ubuntu1) ... 149s Selecting previously unselected package build-essential. 149s Preparing to unpack .../28-build-essential_12.10ubuntu1_s390x.deb ... 149s Unpacking build-essential (12.10ubuntu1) ... 149s Selecting previously unselected package libdebhelper-perl. 149s Preparing to unpack .../29-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 149s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 149s Selecting previously unselected package libtool. 149s Preparing to unpack .../30-libtool_2.4.7-7build1_all.deb ... 149s Unpacking libtool (2.4.7-7build1) ... 149s Selecting previously unselected package dh-autoreconf. 149s Preparing to unpack .../31-dh-autoreconf_20_all.deb ... 149s Unpacking dh-autoreconf (20) ... 149s Selecting previously unselected package libarchive-zip-perl. 149s Preparing to unpack .../32-libarchive-zip-perl_1.68-1_all.deb ... 149s Unpacking libarchive-zip-perl (1.68-1) ... 149s Selecting previously unselected package libsub-override-perl. 149s Preparing to unpack .../33-libsub-override-perl_0.10-1_all.deb ... 149s Unpacking libsub-override-perl (0.10-1) ... 149s Selecting previously unselected package libfile-stripnondeterminism-perl. 149s Preparing to unpack .../34-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 149s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 149s Selecting previously unselected package dh-strip-nondeterminism. 149s Preparing to unpack .../35-dh-strip-nondeterminism_1.13.1-1_all.deb ... 149s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 149s Selecting previously unselected package debugedit. 149s Preparing to unpack .../36-debugedit_1%3a5.0-5build2_s390x.deb ... 149s Unpacking debugedit (1:5.0-5build2) ... 149s Selecting previously unselected package dwz. 149s Preparing to unpack .../37-dwz_0.15-1build6_s390x.deb ... 149s Unpacking dwz (0.15-1build6) ... 149s Selecting previously unselected package gettext. 149s Preparing to unpack .../38-gettext_0.21-14ubuntu2_s390x.deb ... 149s Unpacking gettext (0.21-14ubuntu2) ... 149s Selecting previously unselected package intltool-debian. 149s Preparing to unpack .../39-intltool-debian_0.35.0+20060710.6_all.deb ... 149s Unpacking intltool-debian (0.35.0+20060710.6) ... 149s Selecting previously unselected package po-debconf. 149s Preparing to unpack .../40-po-debconf_1.0.21+nmu1_all.deb ... 149s Unpacking po-debconf (1.0.21+nmu1) ... 149s Selecting previously unselected package debhelper. 149s Preparing to unpack .../41-debhelper_13.14.1ubuntu5_all.deb ... 149s Unpacking debhelper (13.14.1ubuntu5) ... 149s Selecting previously unselected package dh-apport. 149s Preparing to unpack .../42-dh-apport_2.28.1-0ubuntu3_all.deb ... 149s Unpacking dh-apport (2.28.1-0ubuntu3) ... 149s Selecting previously unselected package golang-1.22-src. 149s Preparing to unpack .../43-golang-1.22-src_1.22.2-2ubuntu0.1_all.deb ... 149s Unpacking golang-1.22-src (1.22.2-2ubuntu0.1) ... 151s Selecting previously unselected package golang-1.22-go. 151s Preparing to unpack .../44-golang-1.22-go_1.22.2-2ubuntu0.1_s390x.deb ... 151s Unpacking golang-1.22-go (1.22.2-2ubuntu0.1) ... 151s Selecting previously unselected package golang-src. 151s Preparing to unpack .../45-golang-src_2%3a1.22~2build1_all.deb ... 151s Unpacking golang-src (2:1.22~2build1) ... 151s Selecting previously unselected package golang-go:s390x. 151s Preparing to unpack .../46-golang-go_2%3a1.22~2build1_s390x.deb ... 151s Unpacking golang-go:s390x (2:1.22~2build1) ... 151s Selecting previously unselected package dh-golang. 151s Preparing to unpack .../47-dh-golang_1.62_all.deb ... 151s Unpacking dh-golang (1.62) ... 151s Selecting previously unselected package autopkgtest-satdep. 151s Preparing to unpack .../48-1-autopkgtest-satdep.deb ... 151s Unpacking autopkgtest-satdep (0) ... 151s Setting up libarchive-zip-perl (1.68-1) ... 151s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 151s Setting up m4 (1.4.19-4build1) ... 151s Setting up libgomp1:s390x (14-20240412-0ubuntu1) ... 152s Setting up dh-apport (2.28.1-0ubuntu3) ... 152s Setting up autotools-dev (20220109.1) ... 152s Setting up gcc-13-base:s390x (13.2.0-23ubuntu4) ... 152s Setting up golang-1.22-src (1.22.2-2ubuntu0.1) ... 152s Setting up libmpc3:s390x (1.3.1-1build1) ... 152s Setting up libatomic1:s390x (14-20240412-0ubuntu1) ... 152s Setting up autopoint (0.21-14ubuntu2) ... 152s Setting up autoconf (2.71-3) ... 152s Setting up libubsan1:s390x (14-20240412-0ubuntu1) ... 152s Setting up dwz (0.15-1build6) ... 152s Setting up libasan8:s390x (14-20240412-0ubuntu1) ... 152s Setting up debugedit (1:5.0-5build2) ... 152s Setting up libsub-override-perl (0.10-1) ... 152s Setting up libisl23:s390x (0.26-3build1) ... 152s Setting up golang-src (2:1.22~2build1) ... 152s Setting up libcc1-0:s390x (14-20240412-0ubuntu1) ... 152s Setting up libitm1:s390x (14-20240412-0ubuntu1) ... 152s Setting up automake (1:1.16.5-1.3ubuntu1) ... 152s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 152s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 152s Setting up gettext (0.21-14ubuntu2) ... 152s Setting up golang-1.22-go (1.22.2-2ubuntu0.1) ... 152s Setting up intltool-debian (0.35.0+20060710.6) ... 152s Setting up cpp-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 152s Setting up dh-strip-nondeterminism (1.13.1-1) ... 152s Setting up libgcc-13-dev:s390x (13.2.0-23ubuntu4) ... 152s Setting up libstdc++-13-dev:s390x (13.2.0-23ubuntu4) ... 152s Setting up cpp-13 (13.2.0-23ubuntu4) ... 152s Setting up cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 152s Setting up golang-go:s390x (2:1.22~2build1) ... 152s Setting up po-debconf (1.0.21+nmu1) ... 152s Setting up gcc-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 152s Setting up gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 152s Setting up g++-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 152s Setting up gcc-13 (13.2.0-23ubuntu4) ... 152s Setting up cpp (4:13.2.0-7ubuntu1) ... 152s Setting up g++-13 (13.2.0-23ubuntu4) ... 152s Setting up libtool (2.4.7-7build1) ... 152s Setting up g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 152s Setting up gcc (4:13.2.0-7ubuntu1) ... 152s Setting up dh-autoreconf (20) ... 152s Setting up g++ (4:13.2.0-7ubuntu1) ... 152s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 152s Setting up build-essential (12.10ubuntu1) ... 152s Setting up debhelper (13.14.1ubuntu5) ... 152s Setting up dh-golang (1.62) ... 152s Setting up autopkgtest-satdep (0) ... 152s Processing triggers for man-db (2.12.0-4build2) ... 152s Processing triggers for install-info (7.1-3build2) ... 152s Processing triggers for libc-bin (2.39-0ubuntu8.2) ... 154s (Reading database ... 94739 files and directories currently installed.) 154s Removing autopkgtest-satdep (0) ... 155s autopkgtest [22:41:21]: test command1: ./debian/tests/test 155s autopkgtest [22:41:21]: test command1: [----------------------- 221s === RUN TestRunSignal 221s === RUN TestRunSignal/Send_SIGINT_exits 221s INFO Starting WSL Pro Service version Dev 222s === RUN TestRunSignal/Send_SIGTERM_exits 222s INFO Starting WSL Pro Service version Dev 222s --- PASS: TestRunSignal (0.20s) 222s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 222s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 222s === RUN TestRun 222s === PAUSE TestRun 222s === CONT TestRun 222s === RUN TestRun/Run_and_exit_successfully 222s === PAUSE TestRun/Run_and_exit_successfully 222s === RUN TestRun/Run_and_return_error 222s === PAUSE TestRun/Run_and_return_error 222s === RUN TestRun/Run_and_return_usage_error 222s === PAUSE TestRun/Run_and_return_usage_error 222s === RUN TestRun/Run_and_usage_error_only_does_not_fail 222s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 222s === CONT TestRun/Run_and_exit_successfully 222s INFO Starting WSL Pro Service version Dev 222s === CONT TestRun/Run_and_usage_error_only_does_not_fail 222s INFO Starting WSL Pro Service version Dev 222s === CONT TestRun/Run_and_return_usage_error 222s INFO Starting WSL Pro Service version Dev 222s ERROR context.Background Error requested 222s === CONT TestRun/Run_and_return_error 222s INFO Starting WSL Pro Service version Dev 222s ERROR context.Background Error requested 222s --- PASS: TestRun (0.00s) 222s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 222s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 222s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 222s --- PASS: TestRun/Run_and_return_error (0.10s) 222s PASS 222s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.608s 223s === RUN TestHelp 223s --- PASS: TestHelp (0.00s) 223s === RUN TestCompletion 223s --- PASS: TestCompletion (0.00s) 223s === RUN TestVersion 223s --- PASS: TestVersion (0.00s) 223s === RUN TestNoUsageError 223s --- PASS: TestNoUsageError (0.00s) 223s === RUN TestUsageError 223s === PAUSE TestUsageError 223s === RUN TestCanQuitWhenExecute 223s === PAUSE TestCanQuitWhenExecute 223s === RUN TestCanQuitTwice 223s === PAUSE TestCanQuitTwice 223s === RUN TestAppCanQuitWithoutExecute 223s === PAUSE TestAppCanQuitWithoutExecute 223s === RUN TestAppRunFailsOnComponentsCreationAndQuit 223s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 223s === RUN TestAppGetRootCmd 223s === PAUSE TestAppGetRootCmd 223s === RUN TestWithProMock 223s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 223s --- SKIP: TestWithProMock (0.00s) 223s === RUN TestWithWslPathMock 223s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 223s --- SKIP: TestWithWslPathMock (0.00s) 223s === RUN TestWithWslInfoMock 223s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 223s --- SKIP: TestWithWslInfoMock (0.00s) 223s === RUN TestWithCmdExeMock 223s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 223s --- SKIP: TestWithCmdExeMock (0.00s) 223s === CONT TestUsageError 223s --- PASS: TestUsageError (0.00s) 223s === CONT TestAppGetRootCmd 223s --- PASS: TestAppGetRootCmd (0.00s) 223s === CONT TestAppRunFailsOnComponentsCreationAndQuit 227s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (3.50s) 227s === CONT TestAppCanQuitWithoutExecute 227s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 227s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 227s === CONT TestCanQuitTwice 227s time="2024-07-18T22:42:33Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 227s time="2024-07-18T22:42:33Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:75 New() Building new daemon" 229s time="2024-07-18T22:42:35Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 229s time="2024-07-18T22:42:35Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 229s time="2024-07-18T22:42:35Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 230s time="2024-07-18T22:42:36Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:33863" 230s time="2024-07-18T22:42:36Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 230s time="2024-07-18T22:42:36Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 230s time="2024-07-18T22:42:36Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/testutils/mock_agent.go:326 (*mockWSLInstanceService).LandscapeConfigCommands() MockWindowsAgent: LandscapeConfigCommands ready" 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/testutils/mock_agent.go:275 (*mockWSLInstanceService).Connected() MockWindowsAgent: Connected ready" 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/testutils/mock_agent.go:300 (*mockWSLInstanceService).ProAttachmentCommands() MockWindowsAgent: ProAttachmentCommands ready" 231s time="2024-07-18T22:42:37Z" level=warning msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:186 (*Daemon).Serve.func1() Daemon: disconnected from Windows host" 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 231s time="2024-07-18T22:42:37Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.Bd8iYp/build.dxw/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 231s --- PASS: TestCanQuitTwice (4.32s) 231s === CONT TestCanQuitWhenExecute 231s time="2024-07-18T22:42:37Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42265" 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 231s time="2024-07-18T22:42:37Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:75 New() Building new daemon" 231s time="2024-07-18T22:42:37Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.Bd8iYp/build.dxw/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 231s time="2024-07-18T22:42:37Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.Bd8iYp/build.dxw/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 233s time="2024-07-18T22:42:39Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 234s time="2024-07-18T22:42:40Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 234s time="2024-07-18T22:42:40Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 235s time="2024-07-18T22:42:41Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:42265" 235s time="2024-07-18T22:42:41Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 235s time="2024-07-18T22:42:41Z" level=warning msg="/tmp/autopkgtest.Bd8iYp/build.dxw/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:42265: connect: connection refused\"" 235s time="2024-07-18T22:42:41Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 235s time="2024-07-18T22:42:41Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 235s time="2024-07-18T22:42:41Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 235s time="2024-07-18T22:42:41Z" level=info msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 235s time="2024-07-18T22:42:41Z" level=debug msg="/tmp/autopkgtest.Bd8iYp/build.dxw/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 235s --- PASS: TestCanQuitWhenExecute (3.48s) 235s PASS 235s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 11.316s 235s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 236s === RUN TestApplyProToken 236s === PAUSE TestApplyProToken 236s === RUN TestApplyLandscapeConfig 236s === PAUSE TestApplyLandscapeConfig 236s === RUN TestWithProMock 236s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 236s --- SKIP: TestWithProMock (0.00s) 236s === RUN TestWithLandscapeConfigMock 236s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 236s --- SKIP: TestWithLandscapeConfigMock (0.00s) 236s === RUN TestWithWslPathMock 236s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 236s --- SKIP: TestWithWslPathMock (0.00s) 236s === RUN TestWithWslInfoMock 236s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 236s --- SKIP: TestWithWslInfoMock (0.00s) 236s === RUN TestWithCmdExeMock 236s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 236s --- SKIP: TestWithCmdExeMock (0.00s) 236s === CONT TestApplyProToken 236s === RUN TestApplyProToken/Success_attaching 236s === PAUSE TestApplyProToken/Success_attaching 236s === RUN TestApplyProToken/Success_detaching 236s === PAUSE TestApplyProToken/Success_detaching 236s === RUN TestApplyProToken/Error_calling_pro_detach 236s === PAUSE TestApplyProToken/Error_calling_pro_detach 236s === RUN TestApplyProToken/Error_calling_pro_attach 236s === PAUSE TestApplyProToken/Error_calling_pro_attach 236s === CONT TestApplyLandscapeConfig 236s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 236s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 236s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 236s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 236s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 236s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 236s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 236s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 236s === CONT TestApplyProToken/Success_attaching 236s time="2024-07-18T22:42:41Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 237s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 237s time="2024-07-18T22:42:43Z" level=info msg="ApplyLandscapeConfig: received config: registering" 238s === CONT TestApplyProToken/Error_calling_pro_attach 238s time="2024-07-18T22:42:44Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 240s === CONT TestApplyProToken/Error_calling_pro_detach 240s time="2024-07-18T22:42:46Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 241s === CONT TestApplyProToken/Success_detaching 241s time="2024-07-18T22:42:47Z" level=info msg="ApplyProToken: Received empty token: detaching" 242s --- PASS: TestApplyProToken (0.00s) 242s --- PASS: TestApplyProToken/Success_attaching (1.75s) 242s --- PASS: TestApplyProToken/Error_calling_pro_attach (1.74s) 242s --- PASS: TestApplyProToken/Error_calling_pro_detach (0.86s) 242s --- PASS: TestApplyProToken/Success_detaching (0.91s) 242s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 242s time="2024-07-18T22:42:48Z" level=info msg="ApplyLandscapeConfig: received config: registering" 243s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 243s time="2024-07-18T22:42:48Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 243s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 243s time="2024-07-18T22:42:49Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 244s --- PASS: TestApplyLandscapeConfig (0.00s) 244s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (0.86s) 244s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (0.86s) 244s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (0.85s) 244s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (0.91s) 244s PASS 244s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 8.748s 244s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 245s === RUN TestNew 245s === PAUSE TestNew 245s === RUN TestServe 245s === PAUSE TestServe 245s === RUN TestServeAndQuit 245s === PAUSE TestServeAndQuit 245s === RUN TestReconnection 245s === PAUSE TestReconnection 245s === RUN TestWithProMock 245s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 245s --- SKIP: TestWithProMock (0.00s) 245s === RUN TestWithWslPathMock 245s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 245s --- SKIP: TestWithWslPathMock (0.00s) 245s === RUN TestWithWslInfoMock 245s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 245s --- SKIP: TestWithWslInfoMock (0.00s) 245s === RUN TestWithCmdExeMock 245s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 245s --- SKIP: TestWithCmdExeMock (0.00s) 245s === CONT TestNew 245s === RUN TestNew/Success 245s === PAUSE TestNew/Success 245s === RUN TestNew/Error_when_WslPath_returns_error 245s === PAUSE TestNew/Error_when_WslPath_returns_error 245s === CONT TestNew/Success 245s time="2024-07-18T22:42:51Z" level=debug msg="Building new daemon" 247s === CONT TestReconnection 247s === RUN TestReconnection/Success_connecting_after_failing_to_connect 247s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 247s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 247s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 247s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 247s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 247s === CONT TestServeAndQuit 247s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 247s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 247s === RUN TestServeAndQuit/Success_with_graceful_quit 247s === PAUSE TestServeAndQuit/Success_with_graceful_quit 247s === RUN TestServeAndQuit/Success_with_forceful_quit 247s === PAUSE TestServeAndQuit/Success_with_forceful_quit 247s === RUN TestServeAndQuit/Success_with_double_quit 247s === PAUSE TestServeAndQuit/Success_with_double_quit 247s === CONT TestServe 247s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 247s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 247s === RUN TestServe/No_connection_because_there_is_no_server 247s === PAUSE TestServe/No_connection_because_there_is_no_server 247s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 247s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 247s === RUN TestServe/Success 247s === PAUSE TestServe/Success 247s === RUN TestServe/Success_with_systemd_notifier_returning_true 247s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 247s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 247s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 247s === RUN TestServe/No_connection_because_the_port_file_is_empty 247s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 247s === RUN TestServe/No_connection_because_the_port_file_has_port_0 247s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 247s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 247s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 247s === RUN TestServe/No_connection_because_there_are_no_certificates 247s === PAUSE TestServe/No_connection_because_there_are_no_certificates 247s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 247s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 247s === RUN TestServe/Error_because_the_context_is_pre-cancelled 247s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 247s === RUN TestServe/Error_because_the_notifier_returns_an_error 247s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 247s === CONT TestNew/Error_when_WslPath_returns_error 247s time="2024-07-18T22:42:53Z" level=debug msg="Building new daemon" 249s --- PASS: TestNew (0.00s) 249s --- PASS: TestNew/Success (2.15s) 249s --- PASS: TestNew/Error_when_WslPath_returns_error (1.90s) 249s === CONT TestReconnection/Success_connecting_after_failing_to_connect 249s time="2024-07-18T22:42:55Z" level=debug msg="Building new daemon" 251s time="2024-07-18T22:42:57Z" level=debug msg="Ready state sent to systemd" 251s time="2024-07-18T22:42:57Z" level=info msg="Daemon: connecting to Windows Agent" 251s time="2024-07-18T22:42:57Z" level=debug msg="Updated systemd status to \"Connecting\"" 251s time="2024-07-18T22:42:57Z" 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_connect1157089820/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect1157089820/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 251s time="2024-07-18T22:42:57Z" level=info msg="Reconnecting to Windows host in 1 seconds" 251s time="2024-07-18T22:42:57Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 251s time="2024-07-18T22:42:57Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33879" 252s time="2024-07-18T22:42:58Z" level=info msg="Daemon: connecting to Windows Agent" 252s time="2024-07-18T22:42:58Z" level=debug msg="Updated systemd status to \"Connecting\"" 253s time="2024-07-18T22:42:59Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33879" 253s time="2024-07-18T22:42:59Z" level=info msg="Daemon: completed connection to Windows Agent" 253s time="2024-07-18T22:42:59Z" level=debug msg="Updated systemd status to \"Connected\"" 253s time="2024-07-18T22:42:59Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 253s time="2024-07-18T22:42:59Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 254s time="2024-07-18T22:43:00Z" level=debug msg="Server: sent preface messages to all streams" 254s time="2024-07-18T22:43:00Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 254s time="2024-07-18T22:43:00Z" level=info msg="MockWindowsAgent: Connected ready" 254s time="2024-07-18T22:43:00Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 254s time="2024-07-18T22:43:00Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 254s time="2024-07-18T22:43:00Z" level=info msg="Stopping daemon requested." 254s time="2024-07-18T22:43:00Z" level=info msg="Stopping active requests." 254s time="2024-07-18T22:43:00Z" level=warning msg="Daemon: disconnected from Windows host" 254s time="2024-07-18T22:43:00Z" level=info msg="Reconnecting to Windows host in 2 seconds" 254s time="2024-07-18T22:43:00Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 254s time="2024-07-18T22:43:00Z" level=debug msg="Updated systemd status to \"Stopped\"" 254s time="2024-07-18T22:43:00Z" level=debug msg="All connections have now ended." 254s time="2024-07-18T22:43:00Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 254s time="2024-07-18T22:43:00Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 254s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 254s time="2024-07-18T22:43:00Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39081" 254s time="2024-07-18T22:43:00Z" level=debug msg="Building new daemon" 256s time="2024-07-18T22:43:02Z" level=info msg="Stopping daemon requested." 256s time="2024-07-18T22:43:02Z" level=info msg="Waiting for active requests to close." 256s time="2024-07-18T22:43:02Z" level=info msg="Stopping daemon requested." 256s time="2024-07-18T22:43:02Z" level=info msg="Waiting for active requests to close." 256s time="2024-07-18T22:43:02Z" level=debug msg="All connections have now ended." 256s time="2024-07-18T22:43:02Z" level=debug msg="Updated systemd status to \"Stopped\"" 256s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 256s time="2024-07-18T22:43:02Z" level=debug msg="Building new daemon" 258s time="2024-07-18T22:43:04Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37381" 258s time="2024-07-18T22:43:04Z" level=debug msg="Ready state sent to systemd" 258s time="2024-07-18T22:43:04Z" level=info msg="Daemon: connecting to Windows Agent" 258s time="2024-07-18T22:43:04Z" level=debug msg="Updated systemd status to \"Connecting\"" 259s time="2024-07-18T22:43:05Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:37381" 259s time="2024-07-18T22:43:05Z" level=info msg="Daemon: completed connection to Windows Agent" 259s time="2024-07-18T22:43:05Z" level=debug msg="Updated systemd status to \"Connected\"" 259s time="2024-07-18T22:43:05Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 259s time="2024-07-18T22:43:05Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 260s time="2024-07-18T22:43:06Z" level=debug msg="Server: sent preface messages to all streams" 260s time="2024-07-18T22:43:06Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 260s time="2024-07-18T22:43:06Z" level=info msg="MockWindowsAgent: Connected ready" 260s time="2024-07-18T22:43:06Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 325s time="2024-07-18T22:44:11Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 325s time="2024-07-18T22:44:11Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 325s time="2024-07-18T22:44:11Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 325s time="2024-07-18T22:44:11Z" level=warning msg="Daemon: disconnected from Windows host" 325s time="2024-07-18T22:44:11Z" level=info msg="Daemon: connecting to Windows Agent" 325s time="2024-07-18T22:44:11Z" level=debug msg="Updated systemd status to \"Connecting\"" 325s time="2024-07-18T22:44:11Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3459355872/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3459355872/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 325s time="2024-07-18T22:44:11Z" level=info msg="Reconnecting to Windows host in 1 seconds" 325s time="2024-07-18T22:44:11Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 325s time="2024-07-18T22:44:11Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38239" 326s time="2024-07-18T22:44:12Z" level=info msg="Daemon: connecting to Windows Agent" 326s time="2024-07-18T22:44:12Z" level=debug msg="Updated systemd status to \"Connecting\"" 327s time="2024-07-18T22:44:13Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38239" 327s time="2024-07-18T22:44:13Z" level=info msg="Daemon: completed connection to Windows Agent" 327s time="2024-07-18T22:44:13Z" level=debug msg="Updated systemd status to \"Connected\"" 327s time="2024-07-18T22:44:13Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 327s time="2024-07-18T22:44:13Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 328s time="2024-07-18T22:44:14Z" level=debug msg="Server: sent preface messages to all streams" 328s time="2024-07-18T22:44:14Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 328s time="2024-07-18T22:44:14Z" level=info msg="MockWindowsAgent: Connected ready" 328s time="2024-07-18T22:44:14Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 328s time="2024-07-18T22:44:14Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 328s time="2024-07-18T22:44:14Z" level=info msg="Stopping daemon requested." 328s time="2024-07-18T22:44:14Z" level=info msg="Stopping active requests." 328s time="2024-07-18T22:44:14Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 328s time="2024-07-18T22:44:14Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 328s time="2024-07-18T22:44:14Z" level=warning msg="Daemon: disconnected from Windows host" 328s time="2024-07-18T22:44:14Z" level=info msg="Reconnecting to Windows host in 2 seconds" 328s time="2024-07-18T22:44:14Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 328s time="2024-07-18T22:44:14Z" level=debug msg="Updated systemd status to \"Stopped\"" 328s time="2024-07-18T22:44:14Z" level=debug msg="All connections have now ended." 328s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 328s time="2024-07-18T22:44:14Z" level=debug msg="Building new daemon" 330s time="2024-07-18T22:44:16Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46477" 330s time="2024-07-18T22:44:16Z" level=debug msg="Ready state sent to systemd" 330s time="2024-07-18T22:44:16Z" level=info msg="Daemon: connecting to Windows Agent" 330s time="2024-07-18T22:44:16Z" level=debug msg="Updated systemd status to \"Connecting\"" 331s time="2024-07-18T22:44:17Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46477" 331s time="2024-07-18T22:44:17Z" level=info msg="Daemon: completed connection to Windows Agent" 331s time="2024-07-18T22:44:17Z" level=debug msg="Updated systemd status to \"Connected\"" 331s time="2024-07-18T22:44:17Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 331s time="2024-07-18T22:44:17Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 332s time="2024-07-18T22:44:18Z" level=debug msg="Server: sent preface messages to all streams" 332s time="2024-07-18T22:44:18Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 332s time="2024-07-18T22:44:18Z" level=info msg="MockWindowsAgent: Connected ready" 332s time="2024-07-18T22:44:18Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 332s time="2024-07-18T22:44:18Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 332s time="2024-07-18T22:44:18Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36609" 332s time="2024-07-18T22:44:18Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 332s time="2024-07-18T22:44:18Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 332s time="2024-07-18T22:44:18Z" level=warning msg="Daemon: disconnected from Windows host" 332s time="2024-07-18T22:44:18Z" level=info msg="Reconnecting to Windows host in 1 seconds" 332s time="2024-07-18T22:44:18Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 333s time="2024-07-18T22:44:19Z" level=info msg="Daemon: connecting to Windows Agent" 333s time="2024-07-18T22:44:19Z" level=debug msg="Updated systemd status to \"Connecting\"" 334s time="2024-07-18T22:44:20Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:36609" 334s time="2024-07-18T22:44:20Z" level=info msg="Daemon: completed connection to Windows Agent" 334s time="2024-07-18T22:44:20Z" level=debug msg="Updated systemd status to \"Connected\"" 334s time="2024-07-18T22:44:20Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 334s time="2024-07-18T22:44:20Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 335s time="2024-07-18T22:44:21Z" level=debug msg="Server: sent preface messages to all streams" 335s time="2024-07-18T22:44:21Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 335s time="2024-07-18T22:44:21Z" level=info msg="MockWindowsAgent: Connected ready" 335s time="2024-07-18T22:44:21Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 335s time="2024-07-18T22:44:21Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 335s time="2024-07-18T22:44:21Z" level=info msg="Stopping daemon requested." 335s time="2024-07-18T22:44:21Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 335s time="2024-07-18T22:44:21Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 335s time="2024-07-18T22:44:21Z" level=info msg="Stopping active requests." 335s time="2024-07-18T22:44:21Z" level=warning msg="Daemon: disconnected from Windows host" 335s time="2024-07-18T22:44:21Z" level=info msg="Reconnecting to Windows host in 2 seconds" 335s time="2024-07-18T22:44:21Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 335s time="2024-07-18T22:44:21Z" level=debug msg="Updated systemd status to \"Stopped\"" 335s time="2024-07-18T22:44:21Z" level=debug msg="All connections have now ended." 335s --- PASS: TestReconnection (0.00s) 335s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (4.89s) 335s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (72.04s) 335s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (7.02s) 335s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 335s time="2024-07-18T22:44:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46737" 335s time="2024-07-18T22:44:21Z" level=debug msg="Building new daemon" 337s time="2024-07-18T22:44:23Z" level=info msg="Daemon: connecting to Windows Agent" 337s time="2024-07-18T22:44:23Z" 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" 337s time="2024-07-18T22:44:23Z" level=info msg="Reconnecting to Windows host in 1 seconds" 338s time="2024-07-18T22:44:24Z" level=info msg="Stopping daemon requested." 338s time="2024-07-18T22:44:24Z" level=info msg="Waiting for active requests to close." 338s time="2024-07-18T22:44:24Z" level=info msg="Daemon: connecting to Windows Agent" 338s time="2024-07-18T22:44:24Z" 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" 338s time="2024-07-18T22:44:24Z" level=info msg="Reconnecting to Windows host in 2 seconds" 338s time="2024-07-18T22:44:24Z" level=debug msg="All connections have now ended." 338s === CONT TestServeAndQuit/Success_with_double_quit 338s time="2024-07-18T22:44:24Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46469" 338s time="2024-07-18T22:44:24Z" level=debug msg="Building new daemon" 340s time="2024-07-18T22:44:26Z" level=debug msg="Ready state sent to systemd" 340s time="2024-07-18T22:44:26Z" level=info msg="Daemon: connecting to Windows Agent" 340s time="2024-07-18T22:44:26Z" level=debug msg="Updated systemd status to \"Connecting\"" 341s time="2024-07-18T22:44:27Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46469" 341s time="2024-07-18T22:44:27Z" level=info msg="Daemon: completed connection to Windows Agent" 341s time="2024-07-18T22:44:27Z" level=debug msg="Updated systemd status to \"Connected\"" 341s time="2024-07-18T22:44:27Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 341s time="2024-07-18T22:44:27Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 342s time="2024-07-18T22:44:28Z" level=debug msg="Server: sent preface messages to all streams" 342s time="2024-07-18T22:44:28Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 342s time="2024-07-18T22:44:28Z" level=info msg="MockWindowsAgent: Connected ready" 342s time="2024-07-18T22:44:28Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 342s time="2024-07-18T22:44:28Z" level=info msg="Stopping daemon requested." 342s time="2024-07-18T22:44:28Z" level=info msg="Waiting for active requests to close." 342s time="2024-07-18T22:44:28Z" level=warning msg="Daemon: disconnected from Windows host" 342s time="2024-07-18T22:44:28Z" level=info msg="Reconnecting to Windows host in 1 seconds" 342s time="2024-07-18T22:44:28Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 342s time="2024-07-18T22:44:28Z" level=debug msg="Updated systemd status to \"Stopped\"" 342s time="2024-07-18T22:44:28Z" level=debug msg="All connections have now ended." 342s time="2024-07-18T22:44:28Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 342s time="2024-07-18T22:44:28Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 342s time="2024-07-18T22:44:28Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 342s time="2024-07-18T22:44:28Z" level=info msg="Stopping daemon requested." 342s time="2024-07-18T22:44:28Z" level=info msg="Waiting for active requests to close." 342s time="2024-07-18T22:44:28Z" level=debug msg="All connections have now ended." 342s === CONT TestServeAndQuit/Success_with_forceful_quit 342s time="2024-07-18T22:44:28Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39581" 342s time="2024-07-18T22:44:28Z" level=debug msg="Building new daemon" 344s time="2024-07-18T22:44:30Z" level=debug msg="Ready state sent to systemd" 344s time="2024-07-18T22:44:30Z" level=info msg="Daemon: connecting to Windows Agent" 344s time="2024-07-18T22:44:30Z" level=debug msg="Updated systemd status to \"Connecting\"" 345s time="2024-07-18T22:44:31Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:39581" 345s time="2024-07-18T22:44:31Z" level=info msg="Daemon: completed connection to Windows Agent" 345s time="2024-07-18T22:44:31Z" level=debug msg="Updated systemd status to \"Connected\"" 345s time="2024-07-18T22:44:31Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 345s time="2024-07-18T22:44:31Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 346s time="2024-07-18T22:44:32Z" level=debug msg="Server: sent preface messages to all streams" 346s time="2024-07-18T22:44:32Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 346s time="2024-07-18T22:44:32Z" level=info msg="MockWindowsAgent: Connected ready" 346s time="2024-07-18T22:44:32Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 346s time="2024-07-18T22:44:32Z" level=info msg="Stopping daemon requested." 346s time="2024-07-18T22:44:32Z" level=info msg="Stopping active requests." 346s time="2024-07-18T22:44:32Z" level=warning msg="Daemon: disconnected from Windows host" 346s time="2024-07-18T22:44:32Z" level=info msg="Reconnecting to Windows host in 1 seconds" 346s time="2024-07-18T22:44:32Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 346s time="2024-07-18T22:44:32Z" level=debug msg="Updated systemd status to \"Stopped\"" 346s time="2024-07-18T22:44:32Z" level=debug msg="All connections have now ended." 346s time="2024-07-18T22:44:32Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 346s time="2024-07-18T22:44:32Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 346s time="2024-07-18T22:44:32Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 346s === CONT TestServeAndQuit/Success_with_graceful_quit 346s time="2024-07-18T22:44:32Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43271" 346s time="2024-07-18T22:44:32Z" level=debug msg="Building new daemon" 348s time="2024-07-18T22:44:34Z" level=debug msg="Ready state sent to systemd" 348s time="2024-07-18T22:44:34Z" level=info msg="Daemon: connecting to Windows Agent" 348s time="2024-07-18T22:44:34Z" level=debug msg="Updated systemd status to \"Connecting\"" 349s time="2024-07-18T22:44:35Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43271" 349s time="2024-07-18T22:44:35Z" level=info msg="Daemon: completed connection to Windows Agent" 349s time="2024-07-18T22:44:35Z" level=debug msg="Updated systemd status to \"Connected\"" 349s time="2024-07-18T22:44:35Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 349s time="2024-07-18T22:44:35Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 350s time="2024-07-18T22:44:36Z" level=debug msg="Server: sent preface messages to all streams" 350s time="2024-07-18T22:44:36Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 350s time="2024-07-18T22:44:36Z" level=info msg="MockWindowsAgent: Connected ready" 350s time="2024-07-18T22:44:36Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 350s time="2024-07-18T22:44:36Z" level=info msg="Stopping daemon requested." 350s time="2024-07-18T22:44:36Z" level=info msg="Waiting for active requests to close." 350s time="2024-07-18T22:44:36Z" level=warning msg="Daemon: disconnected from Windows host" 350s time="2024-07-18T22:44:36Z" level=info msg="Reconnecting to Windows host in 1 seconds" 350s time="2024-07-18T22:44:36Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 350s time="2024-07-18T22:44:36Z" level=debug msg="Updated systemd status to \"Stopped\"" 350s time="2024-07-18T22:44:36Z" level=debug msg="All connections have now ended." 350s time="2024-07-18T22:44:36Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 350s time="2024-07-18T22:44:36Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 350s time="2024-07-18T22:44:36Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 350s --- PASS: TestServeAndQuit (0.00s) 350s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (1.89s) 350s --- PASS: TestServeAndQuit/Success_with_double_quit (4.02s) 350s --- PASS: TestServeAndQuit/Success_with_forceful_quit (4.17s) 350s --- PASS: TestServeAndQuit/Success_with_graceful_quit (4.00s) 350s === CONT TestServe/Error_because_the_notifier_returns_an_error 350s time="2024-07-18T22:44:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44729" 350s time="2024-07-18T22:44:36Z" level=debug msg="Building new daemon" 352s time="2024-07-18T22:44:38Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 352s time="2024-07-18T22:44:38Z" level=info msg="Stopping daemon requested." 352s time="2024-07-18T22:44:38Z" level=info msg="Waiting for active requests to close." 352s time="2024-07-18T22:44:38Z" level=debug msg="All connections have now ended." 352s === CONT TestServe/Error_because_the_context_is_pre-cancelled 352s time="2024-07-18T22:44:38Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38849" 352s time="2024-07-18T22:44:38Z" level=debug msg="Building new daemon" 354s time="2024-07-18T22:44:40Z" level=info msg="Stopping daemon requested." 354s time="2024-07-18T22:44:40Z" level=info msg="Waiting for active requests to close." 354s time="2024-07-18T22:44:40Z" level=debug msg="All connections have now ended." 354s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 354s time="2024-07-18T22:44:40Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39109" 354s time="2024-07-18T22:44:40Z" level=debug msg="Building new daemon" 356s time="2024-07-18T22:44:42Z" level=info msg="Daemon: connecting to Windows Agent" 357s time="2024-07-18T22:44:43Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:39109" 357s time="2024-07-18T22:44:43Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file3804891048/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 357s time="2024-07-18T22:44:43Z" level=info msg="Reconnecting to Windows host in 1 seconds" 358s time="2024-07-18T22:44:44Z" level=info msg="Stopping daemon requested." 358s time="2024-07-18T22:44:44Z" level=info msg="Waiting for active requests to close." 358s time="2024-07-18T22:44:44Z" level=debug msg="All connections have now ended." 358s === CONT TestServe/No_connection_because_there_are_no_certificates 358s time="2024-07-18T22:44:44Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44213" 358s time="2024-07-18T22:44:44Z" level=debug msg="Building new daemon" 360s time="2024-07-18T22:44:46Z" level=info msg="Daemon: connecting to Windows Agent" 361s time="2024-07-18T22:44:47Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44213" 361s time="2024-07-18T22:44:47Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates2764487242/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 361s time="2024-07-18T22:44:47Z" level=info msg="Reconnecting to Windows host in 1 seconds" 362s time="2024-07-18T22:44:48Z" level=info msg="Stopping daemon requested." 362s time="2024-07-18T22:44:48Z" level=info msg="Waiting for active requests to close." 362s time="2024-07-18T22:44:48Z" level=debug msg="All connections have now ended." 362s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 362s time="2024-07-18T22:44:48Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45883" 362s time="2024-07-18T22:44:48Z" level=debug msg="Building new daemon" 364s time="2024-07-18T22:44:50Z" level=info msg="Daemon: connecting to Windows Agent" 364s time="2024-07-18T22:44:50Z" 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" 364s time="2024-07-18T22:44:50Z" level=info msg="Reconnecting to Windows host in 1 seconds" 365s time="2024-07-18T22:44:51Z" level=info msg="Stopping daemon requested." 365s time="2024-07-18T22:44:51Z" level=info msg="Waiting for active requests to close." 365s time="2024-07-18T22:44:51Z" level=debug msg="All connections have now ended." 365s === CONT TestServe/No_connection_because_the_port_file_has_port_0 365s time="2024-07-18T22:44:51Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36419" 365s time="2024-07-18T22:44:51Z" level=debug msg="Building new daemon" 367s time="2024-07-18T22:44:53Z" level=info msg="Daemon: connecting to Windows Agent" 367s time="2024-07-18T22:44:53Z" 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" 367s time="2024-07-18T22:44:53Z" level=info msg="Reconnecting to Windows host in 1 seconds" 368s time="2024-07-18T22:44:54Z" level=info msg="Daemon: connecting to Windows Agent" 368s time="2024-07-18T22:44:54Z" 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" 368s time="2024-07-18T22:44:54Z" level=info msg="Reconnecting to Windows host in 2 seconds" 368s time="2024-07-18T22:44:54Z" level=info msg="Stopping daemon requested." 368s time="2024-07-18T22:44:54Z" level=info msg="Waiting for active requests to close." 368s time="2024-07-18T22:44:54Z" level=debug msg="All connections have now ended." 368s === CONT TestServe/No_connection_because_the_port_file_is_empty 368s time="2024-07-18T22:44:54Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38477" 368s time="2024-07-18T22:44:54Z" level=debug msg="Building new daemon" 370s time="2024-07-18T22:44:56Z" level=info msg="Daemon: connecting to Windows Agent" 370s time="2024-07-18T22:44:56Z" 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" 370s time="2024-07-18T22:44:56Z" level=info msg="Reconnecting to Windows host in 1 seconds" 371s time="2024-07-18T22:44:57Z" level=info msg="Stopping daemon requested." 371s time="2024-07-18T22:44:57Z" level=info msg="Waiting for active requests to close." 371s time="2024-07-18T22:44:57Z" level=debug msg="All connections have now ended." 371s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 371s time="2024-07-18T22:44:57Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38799" 371s time="2024-07-18T22:44:57Z" level=debug msg="Building new daemon" 373s time="2024-07-18T22:44:59Z" level=info msg="Daemon: connecting to Windows Agent" 373s time="2024-07-18T22:44:59Z" 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_exist2843860943/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist2843860943/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 373s time="2024-07-18T22:44:59Z" level=info msg="Reconnecting to Windows host in 1 seconds" 374s time="2024-07-18T22:45:00Z" level=info msg="Stopping daemon requested." 374s time="2024-07-18T22:45:00Z" level=info msg="Waiting for active requests to close." 374s time="2024-07-18T22:45:00Z" level=debug msg="All connections have now ended." 374s === CONT TestServe/Success_with_systemd_notifier_returning_true 374s time="2024-07-18T22:45:00Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35975" 374s time="2024-07-18T22:45:00Z" level=debug msg="Building new daemon" 376s time="2024-07-18T22:45:02Z" level=debug msg="Ready state sent to systemd" 376s time="2024-07-18T22:45:02Z" level=info msg="Daemon: connecting to Windows Agent" 376s time="2024-07-18T22:45:02Z" level=debug msg="Updated systemd status to \"Connecting\"" 377s time="2024-07-18T22:45:03Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35975" 377s time="2024-07-18T22:45:03Z" level=info msg="Daemon: completed connection to Windows Agent" 377s time="2024-07-18T22:45:03Z" level=debug msg="Updated systemd status to \"Connected\"" 377s time="2024-07-18T22:45:03Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 377s time="2024-07-18T22:45:03Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 378s time="2024-07-18T22:45:04Z" level=debug msg="Server: sent preface messages to all streams" 378s time="2024-07-18T22:45:04Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 378s time="2024-07-18T22:45:04Z" level=info msg="MockWindowsAgent: Connected ready" 378s time="2024-07-18T22:45:04Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 379s time="2024-07-18T22:45:05Z" level=info msg="Stopping daemon requested." 379s time="2024-07-18T22:45:05Z" level=info msg="Waiting for active requests to close." 379s time="2024-07-18T22:45:05Z" level=warning msg="Daemon: disconnected from Windows host" 379s time="2024-07-18T22:45:05Z" level=info msg="Reconnecting to Windows host in 1 seconds" 379s time="2024-07-18T22:45:05Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 379s time="2024-07-18T22:45:05Z" level=debug msg="Updated systemd status to \"Stopped\"" 379s time="2024-07-18T22:45:05Z" level=debug msg="All connections have now ended." 379s time="2024-07-18T22:45:05Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 379s time="2024-07-18T22:45:05Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 379s time="2024-07-18T22:45:05Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 379s === CONT TestServe/Success 379s time="2024-07-18T22:45:05Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41759" 379s time="2024-07-18T22:45:05Z" level=debug msg="Building new daemon" 381s time="2024-07-18T22:45:07Z" level=info msg="Daemon: connecting to Windows Agent" 382s time="2024-07-18T22:45:08Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:41759" 382s time="2024-07-18T22:45:08Z" level=info msg="Daemon: completed connection to Windows Agent" 382s time="2024-07-18T22:45:08Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 382s time="2024-07-18T22:45:08Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 383s time="2024-07-18T22:45:09Z" level=debug msg="Server: sent preface messages to all streams" 383s time="2024-07-18T22:45:09Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 383s time="2024-07-18T22:45:09Z" level=info msg="MockWindowsAgent: Connected ready" 383s time="2024-07-18T22:45:09Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 385s time="2024-07-18T22:45:11Z" level=info msg="Stopping daemon requested." 385s time="2024-07-18T22:45:11Z" level=info msg="Waiting for active requests to close." 385s time="2024-07-18T22:45:11Z" level=warning msg="Daemon: disconnected from Windows host" 385s time="2024-07-18T22:45:11Z" level=info msg="Reconnecting to Windows host in 1 seconds" 385s time="2024-07-18T22:45:11Z" level=debug msg="All connections have now ended." 385s time="2024-07-18T22:45:11Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 385s time="2024-07-18T22:45:11Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 385s time="2024-07-18T22:45:11Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 385s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 385s time="2024-07-18T22:45:11Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36061" 385s time="2024-07-18T22:45:11Z" level=debug msg="Building new daemon" 387s time="2024-07-18T22:45:13Z" level=info msg="Daemon: connecting to Windows Agent" 388s time="2024-07-18T22:45:14Z" level=info msg="Stopping daemon requested." 388s time="2024-07-18T22:45:14Z" level=info msg="Waiting for active requests to close." 388s time="2024-07-18T22:45:14Z" level=debug msg="All connections have now ended." 388s === CONT TestServe/No_connection_because_there_is_no_server 388s time="2024-07-18T22:45:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46127" 388s time="2024-07-18T22:45:14Z" level=debug msg="Building new daemon" 390s time="2024-07-18T22:45:16Z" level=info msg="Daemon: connecting to Windows Agent" 391s time="2024-07-18T22:45:17Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46127" 391s time="2024-07-18T22:45:17Z" level=info msg="Daemon: completed connection to Windows Agent" 391s time="2024-07-18T22:45:17Z" 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:46127: connect: connection refused\"" 391s time="2024-07-18T22:45:17Z" level=info msg="Reconnecting to Windows host in 1 seconds" 391s time="2024-07-18T22:45:17Z" level=info msg="Stopping daemon requested." 391s time="2024-07-18T22:45:17Z" level=info msg="Waiting for active requests to close." 391s time="2024-07-18T22:45:17Z" level=debug msg="All connections have now ended." 391s --- PASS: TestServe (0.00s) 391s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (2.98s) 391s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (1.92s) 391s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (1.95s) 391s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (4.05s) 391s --- PASS: TestServe/No_connection_because_there_are_no_certificates (3.96s) 391s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (3.12s) 391s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (2.90s) 391s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (2.90s) 391s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (2.97s) 391s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (5.02s) 391s --- PASS: TestServe/Success (5.95s) 391s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (2.81s) 391s --- PASS: TestServe/No_connection_because_there_is_no_server (2.89s) 391s PASS 391s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 145.505s 392s === RUN TestConnect 392s === PAUSE TestConnect 392s === RUN TestSendAndRecv 392s --- PASS: TestSendAndRecv (0.40s) 392s === RUN TestServe 392s === PAUSE TestServe 392s === RUN TestStop 392s === PAUSE TestStop 392s === RUN TestWithProMock 392s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 392s --- SKIP: TestWithProMock (0.00s) 392s === RUN TestWithWslPathMock 392s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 392s --- SKIP: TestWithWslPathMock (0.00s) 392s === RUN TestWithWslInfoMock 392s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 392s --- SKIP: TestWithWslInfoMock (0.00s) 392s === RUN TestWithCmdExeMock 392s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 392s --- SKIP: TestWithCmdExeMock (0.00s) 392s === CONT TestConnect 392s === RUN TestConnect/Success 392s === PAUSE TestConnect/Success 392s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 392s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 392s === CONT TestConnect/Success 392s === CONT TestStop 392s time="2024-07-18T22:45:18Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33845" 393s time="2024-07-18T22:45:19Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 393s time="2024-07-18T22:45:19Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 393s time="2024-07-18T22:45:19Z" level=info msg="MockWindowsAgent: Connected ready" 403s time="2024-07-18T22:45:29Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 403s --- PASS: TestStop (11.11s) 403s === CONT TestServe 403s time="2024-07-18T22:45:29Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 403s time="2024-07-18T22:45:29Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 403s time="2024-07-18T22:45:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46283" 404s time="2024-07-18T22:45:30Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 404s time="2024-07-18T22:45:30Z" level=info msg="MockWindowsAgent: Connected ready" 404s time="2024-07-18T22:45:30Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 408s time="2024-07-18T22:45:34Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 408s time="2024-07-18T22:45:34Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 408s time="2024-07-18T22:45:34Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 408s --- PASS: TestServe (4.83s) 408s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 428s --- PASS: TestConnect (0.00s) 428s --- PASS: TestConnect/Success (0.30s) 428s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.00s) 428s PASS 428s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 36.651s 429s === RUN TestInfo 429s === PAUSE TestInfo 429s === RUN TestWslDistroName 429s === PAUSE TestWslDistroName 429s === RUN TestUserProfileDir 429s === PAUSE TestUserProfileDir 429s === RUN TestProStatus 429s === PAUSE TestProStatus 429s === RUN TestProAttach 429s === PAUSE TestProAttach 429s === RUN TestProDetach 429s === PAUSE TestProDetach 429s === RUN TestLandscapeEnable 429s === PAUSE TestLandscapeEnable 429s === RUN TestWindowsHostAddress 429s === PAUSE TestWindowsHostAddress 429s === RUN TestLandscapeDisable 429s === PAUSE TestLandscapeDisable 429s === RUN TestRealBackend 429s === PAUSE TestRealBackend 429s === RUN TestWithProMock 429s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 429s --- SKIP: TestWithProMock (0.00s) 429s === RUN TestWithLandscapeConfigMock 429s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 429s --- SKIP: TestWithLandscapeConfigMock (0.00s) 429s === RUN TestWithWslPathMock 429s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 429s --- SKIP: TestWithWslPathMock (0.00s) 429s === RUN TestWithWslInfoMock 429s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 429s --- SKIP: TestWithWslInfoMock (0.00s) 429s === RUN TestWithCmdExeMock 429s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 429s --- SKIP: TestWithCmdExeMock (0.00s) 429s === CONT TestInfo 429s === RUN TestInfo/Error_when_WslDistroName_fails 429s === PAUSE TestInfo/Error_when_WslDistroName_fails 429s === RUN TestInfo/Error_when_pro_status_command_fails 429s === PAUSE TestInfo/Error_when_pro_status_command_fails 429s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 429s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 429s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 429s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 429s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 429s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 429s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 429s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 429s === RUN TestInfo/Success 429s === PAUSE TestInfo/Success 429s === CONT TestInfo/Error_when_WslDistroName_fails 430s === CONT TestRealBackend 430s --- PASS: TestRealBackend (0.00s) 430s === CONT TestLandscapeDisable 430s === RUN TestLandscapeDisable/Success 430s === PAUSE TestLandscapeDisable/Success 430s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 430s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 430s === CONT TestWindowsHostAddress 430s === RUN TestWindowsHostAddress/Success_without_NAT 430s === PAUSE TestWindowsHostAddress/Success_without_NAT 431s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 431s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 431s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 431s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 431s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 431s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 431s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 431s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 431s === CONT TestLandscapeEnable 431s === RUN TestLandscapeEnable/Success 431s === PAUSE TestLandscapeEnable/Success 431s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 431s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 431s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 431s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 431s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 431s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 431s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 431s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 431s === RUN TestLandscapeEnable/Success_overriding_computer_title 431s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 431s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 431s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 431s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 431s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 431s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 431s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 431s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 431s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 431s === CONT TestProDetach 431s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 431s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 431s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 431s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 431s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 431s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 431s === RUN TestProDetach/success_on_unattached_distro 431s === PAUSE TestProDetach/success_on_unattached_distro 431s === RUN TestProDetach/success_on_attached_distro 431s === PAUSE TestProDetach/success_on_attached_distro 431s === CONT TestProAttach 431s === RUN TestProAttach/success 431s === PAUSE TestProAttach/success 431s === RUN TestProAttach/error_on_'pro_attach'_error 431s === PAUSE TestProAttach/error_on_'pro_attach'_error 431s === CONT TestProStatus 431s === RUN TestProStatus/success_on_attached_distro 431s === PAUSE TestProStatus/success_on_attached_distro 431s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 431s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 431s === RUN TestProStatus/error_on_'pro_attach'_error 431s === PAUSE TestProStatus/error_on_'pro_attach'_error 431s === RUN TestProStatus/success_on_unattached_distro 431s === PAUSE TestProStatus/success_on_unattached_distro 431s === CONT TestUserProfileDir 431s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 431s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 431s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 431s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 431s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 431s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 431s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 431s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 431s === RUN TestUserProfileDir/Error_on_cmd.exe_error 431s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 431s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 431s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 431s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 431s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 431s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 431s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 431s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 431s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 431s === RUN TestUserProfileDir/Error_on_wslpath_error 431s === PAUSE TestUserProfileDir/Error_on_wslpath_error 431s === CONT TestWslDistroName 431s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 431s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 431s === RUN TestWslDistroName/Success_using_wslpath 431s === PAUSE TestWslDistroName/Success_using_wslpath 431s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 431s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 431s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 431s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 431s === CONT TestInfo/Success 431s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 432s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 433s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 434s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 435s === CONT TestInfo/Error_when_pro_status_command_fails 436s --- PASS: TestInfo (0.00s) 436s --- PASS: TestInfo/Error_when_WslDistroName_fails (1.04s) 436s --- PASS: TestInfo/Success (0.87s) 436s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (0.89s) 436s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (0.85s) 436s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (0.89s) 436s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (0.87s) 436s --- PASS: TestInfo/Error_when_pro_status_command_fails (0.84s) 436s === CONT TestLandscapeDisable/Success 437s === CONT TestWindowsHostAddress/Success_without_NAT 437s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 438s --- PASS: TestLandscapeDisable (0.00s) 438s --- PASS: TestLandscapeDisable/Success (0.85s) 438s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (0.88s) 438s === CONT TestLandscapeEnable/Success 439s system_test.go:456: testdata/TestLandscapeEnable/golden/success 439s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 440s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 441s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 442s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 443s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 444s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 445s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 445s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 446s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 447s --- PASS: TestWindowsHostAddress (0.00s) 447s --- PASS: TestWindowsHostAddress/Success_without_NAT (0.85s) 447s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (0.87s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (0.86s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (0.87s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (0.85s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (0.96s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (0.91s) 447s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (0.88s) 447s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (0.86s) 447s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (0.87s) 447s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 448s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 449s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 449s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 449s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 451s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 451s === CONT TestLandscapeEnable/Success_overriding_computer_title 451s time="2024-07-18T22:46:17Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 452s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 452s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 452s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 452s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 452s time="2024-07-18T22:46:18Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 453s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 453s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 453s time="2024-07-18T22:46:19Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 454s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 454s --- PASS: TestLandscapeEnable (0.00s) 454s --- PASS: TestLandscapeEnable/Success (0.90s) 454s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (0.88s) 454s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 454s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 454s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (1.74s) 454s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (0.92s) 454s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 454s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (0.95s) 454s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (0.87s) 454s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (0.94s) 454s === CONT TestProAttach/success 455s === CONT TestProDetach/success_on_attached_distro 456s === CONT TestProDetach/success_on_unattached_distro 457s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 458s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 459s --- PASS: TestProDetach (0.00s) 459s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (0.87s) 459s --- PASS: TestProDetach/success_on_attached_distro (0.95s) 459s --- PASS: TestProDetach/success_on_unattached_distro (0.91s) 459s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (0.97s) 459s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (0.91s) 459s === CONT TestProStatus/success_on_attached_distro 460s === CONT TestProAttach/error_on_'pro_attach'_error 461s --- PASS: TestProAttach (0.00s) 461s --- PASS: TestProAttach/success (0.94s) 461s --- PASS: TestProAttach/error_on_'pro_attach'_error (0.90s) 461s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 462s === CONT TestProStatus/success_on_unattached_distro 463s === CONT TestProStatus/error_on_'pro_attach'_error 464s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 465s --- PASS: TestProStatus (0.00s) 465s --- PASS: TestProStatus/success_on_attached_distro (0.89s) 465s --- PASS: TestProStatus/success_on_unattached_distro (0.88s) 465s --- PASS: TestProStatus/error_on_'pro_attach'_error (0.97s) 465s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (0.88s) 465s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 465s === CONT TestUserProfileDir/Error_on_wslpath_error 467s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 469s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 470s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 472s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 474s === CONT TestUserProfileDir/Error_on_cmd.exe_error 475s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 475s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 475s system_test.go:205: Removing default proc/mounts 475s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 475s system_test.go:205: Removing default proc/mounts 475s --- PASS: TestUserProfileDir (0.00s) 475s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (1.73s) 475s --- PASS: TestUserProfileDir/Error_on_wslpath_error (1.74s) 475s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (1.77s) 475s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (1.71s) 475s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (1.76s) 475s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (1.73s) 475s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (0.94s) 475s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 475s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 475s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 475s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 476s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 477s === CONT TestWslDistroName/Success_using_wslpath 478s --- PASS: TestWslDistroName (0.00s) 478s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 478s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (0.92s) 478s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (0.95s) 478s --- PASS: TestWslDistroName/Success_using_wslpath (0.97s) 478s PASS 478s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 48.277s 478s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 478s autopkgtest [22:46:44]: test command1: -----------------------] 479s autopkgtest [22:46:45]: test command1: - - - - - - - - - - results - - - - - - - - - - 479s command1 PASS 479s autopkgtest [22:46:45]: @@@@@@@@@@@@@@@@@@@@ summary 479s command1 PASS 491s nova [W] Using flock in scalingstack-bos01-s390x 491s Creating nova instance adt-noble-s390x-wsl-pro-service-20240718-223846-juju-7f2275-prod-proposed-migration-environment-3-895c74c6-d878-4c1e-8bdf-e5d3da72ec8e from image adt/ubuntu-noble-s390x-server-20240718.img (UUID c7c1de59-a80b-40f0-8daf-e179a4b90ace)...