0s autopkgtest [01:45:28]: starting date and time: 2025-04-11 01:45:28+0000 0s autopkgtest [01:45:28]: git checkout: 325255d2 Merge branch 'pin-any-arch' into 'ubuntu/production' 0s autopkgtest [01:45:28]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.1pn_dz6z/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/35.1ubuntu0~24.04' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest-s390x --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-s390x-18.secgroup --name adt-noble-s390x-wsl-pro-service-20250411-014528-juju-7f2275-prod-proposed-migration-environment-2-e6c00ee7-3796-48a2-9504-8e743e9b9be2 --image adt/ubuntu-noble-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration-s390x -e TERM=linux --mirror=http://ftpmaster.internal/ubuntu/ 82s autopkgtest [01:46:50]: testbed dpkg architecture: s390x 82s autopkgtest [01:46:50]: testbed apt version: 2.7.14build2 82s autopkgtest [01:46:50]: @@@@@@@@@@@@@@@@@@@@ test bed setup 82s autopkgtest [01:46:50]: testbed release detected to be: None 83s autopkgtest [01:46:51]: updating testbed package index (apt update) 83s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [265 kB] 84s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 84s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 84s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 84s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [61.6 kB] 84s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [65.6 kB] 84s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [25.2 kB] 84s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [75.1 kB] 84s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [2172 B] 84s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [1360 B] 84s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 84s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [264 kB] 84s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [2500 B] 84s Get:14 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 87s Fetched 763 kB in 1s (988 kB/s) 87s Reading package lists... 88s autopkgtest [01:46:56]: upgrading testbed (apt dist-upgrade and autopurge) 88s Reading package lists... 88s Building dependency tree... 88s Reading state information... 88s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 88s Starting 2 pkgProblemResolver with broken count: 0 88s Done 88s Entering ResolveByKeep 88s 88s The following packages will be upgraded: 88s pci.ids ubuntu-pro-client ubuntu-pro-client-l10n 89s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 89s Need to get 552 kB of archives. 89s After this operation, 110 kB of additional disk space will be used. 89s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main s390x ubuntu-pro-client-l10n s390x 35.1ubuntu0~24.04 [19.8 kB] 89s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main s390x ubuntu-pro-client s390x 35.1ubuntu0~24.04 [257 kB] 89s Get:3 http://ftpmaster.internal/ubuntu noble-updates/main s390x pci.ids all 0.0~2024.03.31-1ubuntu0.1 [275 kB] 89s Fetched 552 kB in 1s (1055 kB/s) 89s (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 ... 54308 files and directories currently installed.) 89s Preparing to unpack .../ubuntu-pro-client-l10n_35.1ubuntu0~24.04_s390x.deb ... 89s Unpacking ubuntu-pro-client-l10n (35.1ubuntu0~24.04) over (34~24.04) ... 89s Preparing to unpack .../ubuntu-pro-client_35.1ubuntu0~24.04_s390x.deb ... 89s Unpacking ubuntu-pro-client (35.1ubuntu0~24.04) over (34~24.04) ... 89s Preparing to unpack .../pci.ids_0.0~2024.03.31-1ubuntu0.1_all.deb ... 89s Unpacking pci.ids (0.0~2024.03.31-1ubuntu0.1) over (0.0~2024.03.31-1) ... 89s Setting up pci.ids (0.0~2024.03.31-1ubuntu0.1) ... 89s Setting up ubuntu-pro-client (35.1ubuntu0~24.04) ... 89s Installing new version of config file /etc/apparmor.d/ubuntu_pro_apt_news ... 89s Installing new version of config file /etc/apt/apt.conf.d/20apt-esm-hook.conf ... 91s Setting up ubuntu-pro-client-l10n (35.1ubuntu0~24.04) ... 91s Processing triggers for man-db (2.12.0-4build2) ... 91s Reading package lists... 91s Building dependency tree... 91s Reading state information... 91s Starting pkgProblemResolver with broken count: 0 91s Starting 2 pkgProblemResolver with broken count: 0 91s Done 92s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 92s autopkgtest [01:47:00]: rebooting testbed after setup commands that affected boot 118s autopkgtest [01:47:26]: testbed running kernel: Linux 6.8.0-57-generic #59-Ubuntu SMP Sat Mar 15 16:24:45 UTC 2025 120s autopkgtest [01:47:28]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 122s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 122s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 122s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 122s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 122s gpgv: Can't check signature: No public key 122s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 122s autopkgtest [01:47:30]: testing package wsl-pro-service version 0.1.4 122s autopkgtest [01:47:30]: build not needed 124s autopkgtest [01:47:32]: test command1: preparing testbed 124s Reading package lists... 124s Building dependency tree... 124s Reading state information... 124s Starting pkgProblemResolver with broken count: 0 124s Starting 2 pkgProblemResolver with broken count: 0 124s Done 125s The following NEW packages will be installed: 125s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 125s cpp-13-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit dh-apport 125s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 125s g++-13-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-13 gcc-13-base 125s gcc-13-s390x-linux-gnu gcc-s390x-linux-gnu gettext golang-1.22-go 125s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 125s libasan8 libatomic1 libcc1-0 libdebhelper-perl 125s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 125s libmpc3 libstdc++-13-dev libsub-override-perl libtool libubsan1 m4 125s po-debconf 125s 0 upgraded, 48 newly installed, 0 to remove and 0 not upgraded. 125s Need to get 94.3 MB of archives. 125s After this operation, 393 MB of additional disk space will be used. 125s Get:1 http://ftpmaster.internal/ubuntu noble/main s390x m4 s390x 1.4.19-4build1 [256 kB] 125s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x autoconf all 2.71-3 [339 kB] 125s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x autotools-dev all 20220109.1 [44.9 kB] 125s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x automake all 1:1.16.5-1.3ubuntu1 [558 kB] 125s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x autopoint all 0.21-14ubuntu2 [422 kB] 125s Get:6 http://ftpmaster.internal/ubuntu noble-updates/main s390x gcc-13-base s390x 13.3.0-6ubuntu2~24.04 [51.5 kB] 125s Get:7 http://ftpmaster.internal/ubuntu noble-updates/main s390x libisl23 s390x 0.26-3build1.1 [702 kB] 125s Get:8 http://ftpmaster.internal/ubuntu noble-updates/main s390x libmpc3 s390x 1.3.1-1build1.1 [58.0 kB] 125s Get:9 http://ftpmaster.internal/ubuntu noble-updates/main s390x cpp-13-s390x-linux-gnu s390x 13.3.0-6ubuntu2~24.04 [8804 kB] 126s Get:10 http://ftpmaster.internal/ubuntu noble-updates/main s390x cpp-13 s390x 13.3.0-6ubuntu2~24.04 [1036 B] 126s Get:11 http://ftpmaster.internal/ubuntu noble/main s390x cpp-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [5308 B] 126s Get:12 http://ftpmaster.internal/ubuntu noble/main s390x cpp s390x 4:13.2.0-7ubuntu1 [22.4 kB] 126s Get:13 http://ftpmaster.internal/ubuntu noble-updates/main s390x libcc1-0 s390x 14.2.0-4ubuntu2~24.04 [51.0 kB] 126s Get:14 http://ftpmaster.internal/ubuntu noble-updates/main s390x libgomp1 s390x 14.2.0-4ubuntu2~24.04 [152 kB] 126s Get:15 http://ftpmaster.internal/ubuntu noble-updates/main s390x libitm1 s390x 14.2.0-4ubuntu2~24.04 [31.2 kB] 126s Get:16 http://ftpmaster.internal/ubuntu noble-updates/main s390x libatomic1 s390x 14.2.0-4ubuntu2~24.04 [9576 B] 126s Get:17 http://ftpmaster.internal/ubuntu noble-updates/main s390x libasan8 s390x 14.2.0-4ubuntu2~24.04 [3008 kB] 126s Get:18 http://ftpmaster.internal/ubuntu noble-updates/main s390x libubsan1 s390x 14.2.0-4ubuntu2~24.04 [1187 kB] 126s Get:19 http://ftpmaster.internal/ubuntu noble-updates/main s390x libgcc-13-dev s390x 13.3.0-6ubuntu2~24.04 [1003 kB] 126s Get:20 http://ftpmaster.internal/ubuntu noble-updates/main s390x gcc-13-s390x-linux-gnu s390x 13.3.0-6ubuntu2~24.04 [17.2 MB] 126s Get:21 http://ftpmaster.internal/ubuntu noble-updates/main s390x gcc-13 s390x 13.3.0-6ubuntu2~24.04 [484 kB] 126s Get:22 http://ftpmaster.internal/ubuntu noble/main s390x gcc-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [1208 B] 126s Get:23 http://ftpmaster.internal/ubuntu noble/main s390x gcc s390x 4:13.2.0-7ubuntu1 [5014 B] 126s Get:24 http://ftpmaster.internal/ubuntu noble-updates/main s390x libstdc++-13-dev s390x 13.3.0-6ubuntu2~24.04 [2535 kB] 126s Get:25 http://ftpmaster.internal/ubuntu noble-updates/main s390x g++-13-s390x-linux-gnu s390x 13.3.0-6ubuntu2~24.04 [10.2 MB] 127s Get:26 http://ftpmaster.internal/ubuntu noble-updates/main s390x g++-13 s390x 13.3.0-6ubuntu2~24.04 [16.0 kB] 127s Get:27 http://ftpmaster.internal/ubuntu noble/main s390x g++-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [956 B] 127s Get:28 http://ftpmaster.internal/ubuntu noble/main s390x g++ s390x 4:13.2.0-7ubuntu1 [1096 B] 127s Get:29 http://ftpmaster.internal/ubuntu noble/main s390x build-essential s390x 12.10ubuntu1 [4930 B] 127s Get:30 http://ftpmaster.internal/ubuntu noble/main s390x libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 127s Get:31 http://ftpmaster.internal/ubuntu noble/main s390x libtool all 2.4.7-7build1 [166 kB] 127s Get:32 http://ftpmaster.internal/ubuntu noble/main s390x dh-autoreconf all 20 [16.1 kB] 127s Get:33 http://ftpmaster.internal/ubuntu noble/main s390x libarchive-zip-perl all 1.68-1 [90.2 kB] 127s Get:34 http://ftpmaster.internal/ubuntu noble/main s390x libsub-override-perl all 0.10-1 [10.0 kB] 127s Get:35 http://ftpmaster.internal/ubuntu noble/main s390x libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 127s Get:36 http://ftpmaster.internal/ubuntu noble/main s390x dh-strip-nondeterminism all 1.13.1-1 [5362 B] 127s Get:37 http://ftpmaster.internal/ubuntu noble/main s390x debugedit s390x 1:5.0-5build2 [50.5 kB] 127s Get:38 http://ftpmaster.internal/ubuntu noble/main s390x dwz s390x 0.15-1build6 [122 kB] 127s Get:39 http://ftpmaster.internal/ubuntu noble/main s390x gettext s390x 0.21-14ubuntu2 [915 kB] 127s Get:40 http://ftpmaster.internal/ubuntu noble/main s390x intltool-debian all 0.35.0+20060710.6 [23.2 kB] 127s Get:41 http://ftpmaster.internal/ubuntu noble/main s390x po-debconf all 1.0.21+nmu1 [233 kB] 127s Get:42 http://ftpmaster.internal/ubuntu noble/main s390x debhelper all 13.14.1ubuntu5 [869 kB] 127s Get:43 http://ftpmaster.internal/ubuntu noble-updates/universe s390x dh-apport all 2.28.1-0ubuntu3.5 [18.2 kB] 127s Get:44 http://ftpmaster.internal/ubuntu noble-updates/main s390x golang-1.22-src all 1.22.2-2ubuntu0.3 [19.7 MB] 127s Get:45 http://ftpmaster.internal/ubuntu noble-updates/main s390x golang-1.22-go s390x 1.22.2-2ubuntu0.3 [24.7 MB] 128s Get:46 http://ftpmaster.internal/ubuntu noble/main s390x golang-src all 2:1.22~2build1 [5078 B] 128s Get:47 http://ftpmaster.internal/ubuntu noble/main s390x golang-go s390x 2:1.22~2build1 [44.0 kB] 128s Get:48 http://ftpmaster.internal/ubuntu noble/main s390x dh-golang all 1.62 [25.2 kB] 128s Fetched 94.3 MB in 4s (26.9 MB/s) 128s Selecting previously unselected package m4. 129s (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 ... 54324 files and directories currently installed.) 129s Preparing to unpack .../00-m4_1.4.19-4build1_s390x.deb ... 129s Unpacking m4 (1.4.19-4build1) ... 129s Selecting previously unselected package autoconf. 129s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 129s Unpacking autoconf (2.71-3) ... 129s Selecting previously unselected package autotools-dev. 129s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 129s Unpacking autotools-dev (20220109.1) ... 129s Selecting previously unselected package automake. 129s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 129s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 129s Selecting previously unselected package autopoint. 129s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 129s Unpacking autopoint (0.21-14ubuntu2) ... 129s Selecting previously unselected package gcc-13-base:s390x. 129s Preparing to unpack .../05-gcc-13-base_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking gcc-13-base:s390x (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package libisl23:s390x. 129s Preparing to unpack .../06-libisl23_0.26-3build1.1_s390x.deb ... 129s Unpacking libisl23:s390x (0.26-3build1.1) ... 129s Selecting previously unselected package libmpc3:s390x. 129s Preparing to unpack .../07-libmpc3_1.3.1-1build1.1_s390x.deb ... 129s Unpacking libmpc3:s390x (1.3.1-1build1.1) ... 129s Selecting previously unselected package cpp-13-s390x-linux-gnu. 129s Preparing to unpack .../08-cpp-13-s390x-linux-gnu_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking cpp-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package cpp-13. 129s Preparing to unpack .../09-cpp-13_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking cpp-13 (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package cpp-s390x-linux-gnu. 129s Preparing to unpack .../10-cpp-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package cpp. 129s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking cpp (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package libcc1-0:s390x. 129s Preparing to unpack .../12-libcc1-0_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libcc1-0:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libgomp1:s390x. 129s Preparing to unpack .../13-libgomp1_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libgomp1:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libitm1:s390x. 129s Preparing to unpack .../14-libitm1_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libitm1:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libatomic1:s390x. 129s Preparing to unpack .../15-libatomic1_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libatomic1:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libasan8:s390x. 129s Preparing to unpack .../16-libasan8_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libasan8:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libubsan1:s390x. 129s Preparing to unpack .../17-libubsan1_14.2.0-4ubuntu2~24.04_s390x.deb ... 129s Unpacking libubsan1:s390x (14.2.0-4ubuntu2~24.04) ... 129s Selecting previously unselected package libgcc-13-dev:s390x. 129s Preparing to unpack .../18-libgcc-13-dev_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking libgcc-13-dev:s390x (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package gcc-13-s390x-linux-gnu. 129s Preparing to unpack .../19-gcc-13-s390x-linux-gnu_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking gcc-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package gcc-13. 129s Preparing to unpack .../20-gcc-13_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking gcc-13 (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package gcc-s390x-linux-gnu. 129s Preparing to unpack .../21-gcc-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package gcc. 129s Preparing to unpack .../22-gcc_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking gcc (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package libstdc++-13-dev:s390x. 129s Preparing to unpack .../23-libstdc++-13-dev_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking libstdc++-13-dev:s390x (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package g++-13-s390x-linux-gnu. 129s Preparing to unpack .../24-g++-13-s390x-linux-gnu_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking g++-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package g++-13. 129s Preparing to unpack .../25-g++-13_13.3.0-6ubuntu2~24.04_s390x.deb ... 129s Unpacking g++-13 (13.3.0-6ubuntu2~24.04) ... 129s Selecting previously unselected package g++-s390x-linux-gnu. 129s Preparing to unpack .../26-g++-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package g++. 129s Preparing to unpack .../27-g++_4%3a13.2.0-7ubuntu1_s390x.deb ... 129s Unpacking g++ (4:13.2.0-7ubuntu1) ... 129s Selecting previously unselected package build-essential. 129s Preparing to unpack .../28-build-essential_12.10ubuntu1_s390x.deb ... 129s Unpacking build-essential (12.10ubuntu1) ... 129s Selecting previously unselected package libdebhelper-perl. 129s Preparing to unpack .../29-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 129s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 129s Selecting previously unselected package libtool. 129s Preparing to unpack .../30-libtool_2.4.7-7build1_all.deb ... 129s Unpacking libtool (2.4.7-7build1) ... 129s Selecting previously unselected package dh-autoreconf. 129s Preparing to unpack .../31-dh-autoreconf_20_all.deb ... 129s Unpacking dh-autoreconf (20) ... 129s Selecting previously unselected package libarchive-zip-perl. 129s Preparing to unpack .../32-libarchive-zip-perl_1.68-1_all.deb ... 129s Unpacking libarchive-zip-perl (1.68-1) ... 129s Selecting previously unselected package libsub-override-perl. 129s Preparing to unpack .../33-libsub-override-perl_0.10-1_all.deb ... 129s Unpacking libsub-override-perl (0.10-1) ... 129s Selecting previously unselected package libfile-stripnondeterminism-perl. 129s Preparing to unpack .../34-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 129s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 129s Selecting previously unselected package dh-strip-nondeterminism. 129s Preparing to unpack .../35-dh-strip-nondeterminism_1.13.1-1_all.deb ... 129s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 129s Selecting previously unselected package debugedit. 129s Preparing to unpack .../36-debugedit_1%3a5.0-5build2_s390x.deb ... 129s Unpacking debugedit (1:5.0-5build2) ... 129s Selecting previously unselected package dwz. 129s Preparing to unpack .../37-dwz_0.15-1build6_s390x.deb ... 129s Unpacking dwz (0.15-1build6) ... 129s Selecting previously unselected package gettext. 129s Preparing to unpack .../38-gettext_0.21-14ubuntu2_s390x.deb ... 129s Unpacking gettext (0.21-14ubuntu2) ... 130s Selecting previously unselected package intltool-debian. 130s Preparing to unpack .../39-intltool-debian_0.35.0+20060710.6_all.deb ... 130s Unpacking intltool-debian (0.35.0+20060710.6) ... 130s Selecting previously unselected package po-debconf. 130s Preparing to unpack .../40-po-debconf_1.0.21+nmu1_all.deb ... 130s Unpacking po-debconf (1.0.21+nmu1) ... 130s Selecting previously unselected package debhelper. 130s Preparing to unpack .../41-debhelper_13.14.1ubuntu5_all.deb ... 130s Unpacking debhelper (13.14.1ubuntu5) ... 130s Selecting previously unselected package dh-apport. 130s Preparing to unpack .../42-dh-apport_2.28.1-0ubuntu3.5_all.deb ... 130s Unpacking dh-apport (2.28.1-0ubuntu3.5) ... 130s Selecting previously unselected package golang-1.22-src. 130s Preparing to unpack .../43-golang-1.22-src_1.22.2-2ubuntu0.3_all.deb ... 130s Unpacking golang-1.22-src (1.22.2-2ubuntu0.3) ... 130s Selecting previously unselected package golang-1.22-go. 130s Preparing to unpack .../44-golang-1.22-go_1.22.2-2ubuntu0.3_s390x.deb ... 130s Unpacking golang-1.22-go (1.22.2-2ubuntu0.3) ... 131s Selecting previously unselected package golang-src. 131s Preparing to unpack .../45-golang-src_2%3a1.22~2build1_all.deb ... 131s Unpacking golang-src (2:1.22~2build1) ... 131s Selecting previously unselected package golang-go:s390x. 131s Preparing to unpack .../46-golang-go_2%3a1.22~2build1_s390x.deb ... 131s Unpacking golang-go:s390x (2:1.22~2build1) ... 131s Selecting previously unselected package dh-golang. 131s Preparing to unpack .../47-dh-golang_1.62_all.deb ... 131s Unpacking dh-golang (1.62) ... 131s Setting up libarchive-zip-perl (1.68-1) ... 131s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 131s Setting up m4 (1.4.19-4build1) ... 131s Setting up libgomp1:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up dh-apport (2.28.1-0ubuntu3.5) ... 131s Setting up autotools-dev (20220109.1) ... 131s Setting up gcc-13-base:s390x (13.3.0-6ubuntu2~24.04) ... 131s Setting up golang-1.22-src (1.22.2-2ubuntu0.3) ... 131s Setting up libmpc3:s390x (1.3.1-1build1.1) ... 131s Setting up libatomic1:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up autopoint (0.21-14ubuntu2) ... 131s Setting up autoconf (2.71-3) ... 131s Setting up libubsan1:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up dwz (0.15-1build6) ... 131s Setting up libasan8:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up debugedit (1:5.0-5build2) ... 131s Setting up libsub-override-perl (0.10-1) ... 131s Setting up libisl23:s390x (0.26-3build1.1) ... 131s Setting up golang-src (2:1.22~2build1) ... 131s Setting up libcc1-0:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up libitm1:s390x (14.2.0-4ubuntu2~24.04) ... 131s Setting up automake (1:1.16.5-1.3ubuntu1) ... 131s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 131s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 131s Setting up gettext (0.21-14ubuntu2) ... 131s Setting up golang-1.22-go (1.22.2-2ubuntu0.3) ... 131s Setting up intltool-debian (0.35.0+20060710.6) ... 131s Setting up cpp-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 131s Setting up dh-strip-nondeterminism (1.13.1-1) ... 131s Setting up libgcc-13-dev:s390x (13.3.0-6ubuntu2~24.04) ... 131s Setting up libstdc++-13-dev:s390x (13.3.0-6ubuntu2~24.04) ... 131s Setting up cpp-13 (13.3.0-6ubuntu2~24.04) ... 131s Setting up cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 131s Setting up golang-go:s390x (2:1.22~2build1) ... 131s Setting up po-debconf (1.0.21+nmu1) ... 131s Setting up gcc-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 131s Setting up gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 131s Setting up g++-13-s390x-linux-gnu (13.3.0-6ubuntu2~24.04) ... 131s Setting up gcc-13 (13.3.0-6ubuntu2~24.04) ... 131s Setting up cpp (4:13.2.0-7ubuntu1) ... 131s Setting up g++-13 (13.3.0-6ubuntu2~24.04) ... 131s Setting up libtool (2.4.7-7build1) ... 131s Setting up g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 131s Setting up gcc (4:13.2.0-7ubuntu1) ... 131s Setting up dh-autoreconf (20) ... 131s Setting up g++ (4:13.2.0-7ubuntu1) ... 131s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 131s Setting up build-essential (12.10ubuntu1) ... 131s Setting up debhelper (13.14.1ubuntu5) ... 131s Setting up dh-golang (1.62) ... 131s Processing triggers for man-db (2.12.0-4build2) ... 131s Processing triggers for install-info (7.1-3build2) ... 131s Processing triggers for libc-bin (2.39-0ubuntu8.4) ... 132s autopkgtest [01:47:40]: test command1: ./debian/tests/test 132s autopkgtest [01:47:40]: test command1: [----------------------- 160s === RUN TestRunSignal 160s === RUN TestRunSignal/Send_SIGINT_exits 160s INFO Starting WSL Pro Service version Dev 160s === RUN TestRunSignal/Send_SIGTERM_exits 160s INFO Starting WSL Pro Service version Dev 160s --- PASS: TestRunSignal (0.20s) 160s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 160s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 160s === RUN TestRun 160s === PAUSE TestRun 160s === CONT TestRun 160s === RUN TestRun/Run_and_exit_successfully 160s === PAUSE TestRun/Run_and_exit_successfully 160s === RUN TestRun/Run_and_return_error 160s === PAUSE TestRun/Run_and_return_error 160s === RUN TestRun/Run_and_return_usage_error 160s === PAUSE TestRun/Run_and_return_usage_error 160s === RUN TestRun/Run_and_usage_error_only_does_not_fail 160s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 160s === CONT TestRun/Run_and_exit_successfully 160s === CONT TestRun/Run_and_return_usage_error 160s INFO Starting WSL Pro Service version Dev 160s INFO Starting WSL Pro Service version Dev 160s ERROR context.Background Error requested 160s === CONT TestRun/Run_and_usage_error_only_does_not_fail 160s === CONT TestRun/Run_and_return_error 160s INFO Starting WSL Pro Service version Dev 160s INFO Starting WSL Pro Service version Dev 160s ERROR context.Background Error requested 160s --- PASS: TestRun (0.00s) 160s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 160s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 160s --- PASS: TestRun/Run_and_return_error (0.10s) 160s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 160s PASS 160s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.406s 160s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 167s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 170s === RUN TestHelp 170s --- PASS: TestHelp (0.00s) 170s === RUN TestCompletion 170s --- PASS: TestCompletion (0.00s) 170s === RUN TestVersion 170s --- PASS: TestVersion (0.00s) 170s === RUN TestNoUsageError 170s --- PASS: TestNoUsageError (0.00s) 170s === RUN TestUsageError 170s === PAUSE TestUsageError 170s === RUN TestCanQuitWhenExecute 170s === PAUSE TestCanQuitWhenExecute 170s === RUN TestCanQuitTwice 170s === PAUSE TestCanQuitTwice 170s === RUN TestAppCanQuitWithoutExecute 170s === PAUSE TestAppCanQuitWithoutExecute 170s === RUN TestAppRunFailsOnComponentsCreationAndQuit 170s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 170s === RUN TestAppGetRootCmd 170s === PAUSE TestAppGetRootCmd 170s === RUN TestWithProMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithProMock (0.00s) 170s === RUN TestWithWslPathMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithWslPathMock (0.00s) 170s === RUN TestWithWslInfoMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithWslInfoMock (0.00s) 170s === RUN TestWithCmdExeMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithCmdExeMock (0.00s) 170s === CONT TestUsageError 170s --- PASS: TestUsageError (0.00s) 170s === CONT TestAppGetRootCmd 170s --- PASS: TestAppGetRootCmd (0.00s) 170s === CONT TestAppRunFailsOnComponentsCreationAndQuit 170s === CONT TestCanQuitTwice 170s time="2025-04-11T01:48:08Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 170s time="2025-04-11T01:48:08Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:75 New() Building new daemon" 170s time="2025-04-11T01:48:11Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 170s time="2025-04-11T01:48:11Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 170s time="2025-04-11T01:48:11Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:11Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:13Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:13Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:13Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (4.75s) 170s === CONT TestAppCanQuitWithoutExecute 170s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 170s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 170s === CONT TestCanQuitWhenExecute 170s time="2025-04-11T01:48:13Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34979" 170s time="2025-04-11T01:48:13Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 170s time="2025-04-11T01:48:13Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:75 New() Building new daemon" 170s time="2025-04-11T01:48:13Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:44977" 170s time="2025-04-11T01:48:13Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 170s time="2025-04-11T01:48:13Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 170s time="2025-04-11T01:48:13Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 170s time="2025-04-11T01:48:14Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 170s time="2025-04-11T01:48:14Z" level=warning msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:186 (*Daemon).Serve.func1() Daemon: disconnected from Windows host" 170s time="2025-04-11T01:48:14Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 170s time="2025-04-11T01:48:14Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s time="2025-04-11T01:48:14Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:14Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:14Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s time="2025-04-11T01:48:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:14Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:14Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:14Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s --- PASS: TestCanQuitTwice (6.33s) 170s time="2025-04-11T01:48:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:15Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 170s time="2025-04-11T01:48:16Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:34979" 170s time="2025-04-11T01:48:16Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 170s time="2025-04-11T01:48:16Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 170s time="2025-04-11T01:48:16Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 170s time="2025-04-11T01:48:16Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:16Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:16Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:16Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:16Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.MZGFUy/build.Vbt/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 170s time="2025-04-11T01:48:17Z" level=warning msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: could not serve: could not send first Connnected message: EOF" 170s time="2025-04-11T01:48:17Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 170s time="2025-04-11T01:48:17Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s time="2025-04-11T01:48:17Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 170s time="2025-04-11T01:48:17Z" level=info msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 170s time="2025-04-11T01:48:17Z" level=debug msg="/tmp/autopkgtest.MZGFUy/build.Vbt/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 170s --- PASS: TestCanQuitWhenExecute (4.76s) 170s PASS 170s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 9.520s 170s === RUN TestApplyProToken 170s === PAUSE TestApplyProToken 170s === RUN TestApplyLandscapeConfig 170s === PAUSE TestApplyLandscapeConfig 170s === RUN TestWithProMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithProMock (0.00s) 170s === RUN TestWithLandscapeConfigMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithLandscapeConfigMock (0.00s) 170s === RUN TestWithWslPathMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithWslPathMock (0.00s) 170s === RUN TestWithWslInfoMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithWslInfoMock (0.00s) 170s === RUN TestWithCmdExeMock 170s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 170s --- SKIP: TestWithCmdExeMock (0.00s) 170s === CONT TestApplyProToken 170s === RUN TestApplyProToken/Error_calling_pro_attach 170s === PAUSE TestApplyProToken/Error_calling_pro_attach 170s === RUN TestApplyProToken/Success_attaching 170s === PAUSE TestApplyProToken/Success_attaching 170s === RUN TestApplyProToken/Success_detaching 170s === PAUSE TestApplyProToken/Success_detaching 170s === RUN TestApplyProToken/Error_calling_pro_detach 170s === PAUSE TestApplyProToken/Error_calling_pro_detach 170s === CONT TestApplyProToken/Error_calling_pro_attach 170s === CONT TestApplyLandscapeConfig 170s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 170s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 170s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 170s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 170s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 170s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 170s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 170s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 170s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 170s time="2025-04-11T01:48:09Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 170s time="2025-04-11T01:48:09Z" level=info msg="ApplyLandscapeConfig: received config: registering" 170s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 170s time="2025-04-11T01:48:10Z" level=info msg="ApplyLandscapeConfig: received config: registering" 170s === CONT TestApplyProToken/Error_calling_pro_detach 170s time="2025-04-11T01:48:11Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 170s === CONT TestApplyProToken/Success_detaching 170s time="2025-04-11T01:48:12Z" level=info msg="ApplyProToken: Received empty token: detaching" 170s === CONT TestApplyProToken/Success_attaching 170s time="2025-04-11T01:48:13Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 170s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 170s time="2025-04-11T01:48:13Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 170s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 170s time="2025-04-11T01:48:14Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 170s --- PASS: TestApplyProToken (0.00s) 170s --- PASS: TestApplyProToken/Error_calling_pro_attach (2.86s) 170s --- PASS: TestApplyProToken/Success_detaching (1.14s) 170s --- PASS: TestApplyProToken/Error_calling_pro_detach (1.37s) 170s --- PASS: TestApplyProToken/Success_attaching (2.34s) 170s --- PASS: TestApplyLandscapeConfig (0.00s) 170s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (1.43s) 170s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (1.25s) 170s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (1.48s) 170s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (1.04s) 170s PASS 170s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 6.571s 225s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 249s === RUN TestNew 249s === PAUSE TestNew 249s === RUN TestServe 249s === PAUSE TestServe 249s === RUN TestServeAndQuit 249s === PAUSE TestServeAndQuit 249s === RUN TestReconnection 249s === PAUSE TestReconnection 249s === RUN TestWithProMock 249s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 249s --- SKIP: TestWithProMock (0.00s) 249s === RUN TestWithWslPathMock 249s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 249s --- SKIP: TestWithWslPathMock (0.00s) 249s === RUN TestWithWslInfoMock 249s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 249s --- SKIP: TestWithWslInfoMock (0.00s) 249s === RUN TestWithCmdExeMock 249s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 249s --- SKIP: TestWithCmdExeMock (0.00s) 249s === CONT TestNew 249s === RUN TestNew/Success 249s === PAUSE TestNew/Success 249s === RUN TestNew/Error_when_WslPath_returns_error 249s === PAUSE TestNew/Error_when_WslPath_returns_error 249s === CONT TestServeAndQuit 249s === RUN TestServeAndQuit/Success_with_graceful_quit 249s === CONT TestReconnection 249s === PAUSE TestServeAndQuit/Success_with_graceful_quit 249s === RUN TestServeAndQuit/Success_with_forceful_quit 249s === RUN TestReconnection/Success_connecting_after_failing_to_connect 249s === PAUSE TestServeAndQuit/Success_with_forceful_quit 249s === RUN TestServeAndQuit/Success_with_double_quit 249s === PAUSE TestServeAndQuit/Success_with_double_quit 249s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 249s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 249s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 249s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 249s === CONT TestServe 249s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 249s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 249s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 249s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 249s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 249s === RUN TestServe/Error_because_the_context_is_pre-cancelled 249s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 249s === RUN TestServe/Success 249s === PAUSE TestServe/Success 249s === RUN TestServe/Success_with_systemd_notifier_returning_true 249s === CONT TestNew/Success 249s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 249s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 249s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 249s === RUN TestServe/No_connection_because_the_port_file_has_port_0 249s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 249s === RUN TestServe/No_connection_because_there_are_no_certificates 249s === PAUSE TestServe/No_connection_because_there_are_no_certificates 249s === RUN TestServe/Error_because_the_notifier_returns_an_error 249s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 249s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 249s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 249s === RUN TestServe/No_connection_because_the_port_file_is_empty 249s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 249s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 249s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 249s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 249s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 249s === RUN TestServe/No_connection_because_there_is_no_server 249s === PAUSE TestServe/No_connection_because_there_is_no_server 249s === CONT TestNew/Error_when_WslPath_returns_error 249s time="2025-04-11T01:48:16Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:16Z" level=debug msg="Building new daemon" 249s === CONT TestServeAndQuit/Success_with_graceful_quit 249s time="2025-04-11T01:48:18Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42421" 249s time="2025-04-11T01:48:18Z" level=debug msg="Building new daemon" 249s --- PASS: TestNew (0.00s) 249s --- PASS: TestNew/Error_when_WslPath_returns_error (2.31s) 249s --- PASS: TestNew/Success (2.38s) 249s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 249s time="2025-04-11T01:48:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42181" 249s time="2025-04-11T01:48:19Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:21Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:21Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:21Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:21Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:21Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:21Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:21Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:21Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s === CONT TestServeAndQuit/Success_with_double_quit 249s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44037" 249s time="2025-04-11T01:48:21Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:22Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:42421" 249s time="2025-04-11T01:48:22Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:22Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:22Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:22Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:24Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:24Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:24Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:24Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:24Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:24Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:24Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:24Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:24Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:24Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:24Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:24Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:48:24Z" level=debug msg="All connections have now ended." 249s time="2025-04-11T01:48:24Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:24Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:24Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s === CONT TestServeAndQuit/Success_with_forceful_quit 249s time="2025-04-11T01:48:24Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40515" 249s time="2025-04-11T01:48:24Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:25Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44037" 249s time="2025-04-11T01:48:25Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:25Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:25Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:25Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:25Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:25Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:25Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:25Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:25Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:25Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:25Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:25Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:25Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:25Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:48:25Z" level=debug msg="All connections have now ended." 249s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:26Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:26Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:26Z" level=debug msg="All connections have now ended." 249s === CONT TestReconnection/Success_connecting_after_failing_to_connect 249s time="2025-04-11T01:48:26Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:26Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:26Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:26Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:26Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40515" 249s time="2025-04-11T01:48:26Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:26Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:26Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:26Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:27Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:27Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:27Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:27Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:27Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:27Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:27Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:27Z" 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_connect2315215759/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect2315215759/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 249s time="2025-04-11T01:48:27Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:27Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:27Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:27Z" level=info msg="Stopping active requests." 249s time="2025-04-11T01:48:27Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:27Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:27Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:27Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:48:27Z" level=debug msg="All connections have now ended." 249s time="2025-04-11T01:48:27Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:27Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:27Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:27Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39645" 249s --- PASS: TestServeAndQuit (0.00s) 249s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (2.48s) 249s --- PASS: TestServeAndQuit/Success_with_graceful_quit (5.25s) 249s --- PASS: TestServeAndQuit/Success_with_double_quit (4.52s) 249s --- PASS: TestServeAndQuit/Success_with_forceful_quit (3.61s) 249s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 249s time="2025-04-11T01:48:27Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:28Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:28Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45677" 249s time="2025-04-11T01:48:29Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:29Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:29Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:29Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:39645" 249s time="2025-04-11T01:48:29Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:29Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:29Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:29Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:29Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45677" 249s time="2025-04-11T01:48:29Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:29Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:29Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:29Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:30Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:30Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:30Z" level=info msg="Stopping active requests." 249s time="2025-04-11T01:48:30Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:30Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:30Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:30Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:30Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:48:30Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:30Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:48:30Z" level=debug msg="All connections have now ended." 249s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 249s time="2025-04-11T01:48:30Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:30Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:30Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:31Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38439" 249s time="2025-04-11T01:48:31Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:48:31Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:31Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:32Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38439" 249s time="2025-04-11T01:48:32Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:32Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:32Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:32Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:32Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:32Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:32Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:32Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:32Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:32Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:32Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:32Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:32Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:32Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:32Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42475" 249s time="2025-04-11T01:48:33Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:33Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:48:34Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:42475" 249s time="2025-04-11T01:48:34Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:34Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:48:34Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:48:34Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:48:34Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:48:34Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:48:34Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:48:34Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:48:34Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:34Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:34Z" level=info msg="Stopping active requests." 249s time="2025-04-11T01:48:34Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:34Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:48:34Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:48:34Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:48:34Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:48:34Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:48:34Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 249s time="2025-04-11T01:48:34Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41991" 249s time="2025-04-11T01:48:34Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:35Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:36Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:41991" 249s time="2025-04-11T01:48:36Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file3202083791/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 249s time="2025-04-11T01:48:36Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:36Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:36Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:36Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/Error_because_the_notifier_returns_an_error 249s time="2025-04-11T01:48:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35463" 249s time="2025-04-11T01:48:36Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:38Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 249s time="2025-04-11T01:48:38Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:38Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:38Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_there_is_no_server 249s time="2025-04-11T01:48:38Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40855" 249s time="2025-04-11T01:48:38Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:39Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:39Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40855" 249s time="2025-04-11T01:48:39Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:48:39Z" 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:40855: connect: connection refused\"" 249s time="2025-04-11T01:48:39Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:40Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:40Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:40Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 249s time="2025-04-11T01:48:40Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46001" 249s time="2025-04-11T01:48:40Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:41Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:41Z" 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" 249s time="2025-04-11T01:48:41Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:42Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:42Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:42Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:42Z" 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" 249s time="2025-04-11T01:48:42Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:48:42Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 249s time="2025-04-11T01:48:42Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46725" 249s time="2025-04-11T01:48:42Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:43Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:43Z" 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" 249s time="2025-04-11T01:48:43Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:44Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:44Z" 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" 249s time="2025-04-11T01:48:44Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:48:45Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:45Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:45Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_the_port_file_is_empty 249s time="2025-04-11T01:48:45Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35603" 249s time="2025-04-11T01:48:45Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:47Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:47Z" 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" 249s time="2025-04-11T01:48:47Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:48Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:48Z" 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" 249s time="2025-04-11T01:48:48Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:48:48Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:48Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:48Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 249s time="2025-04-11T01:48:48Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35823" 249s time="2025-04-11T01:48:48Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:50Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:51Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:51Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:51Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 249s time="2025-04-11T01:48:51Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34649" 249s time="2025-04-11T01:48:51Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:53Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:53Z" 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_exist1283425710/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist1283425710/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 249s time="2025-04-11T01:48:53Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:54Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:54Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:54Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_there_are_no_certificates 249s time="2025-04-11T01:48:55Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45143" 249s time="2025-04-11T01:48:55Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:48:57Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:48:58Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45143" 249s time="2025-04-11T01:48:58Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates1366196878/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 249s time="2025-04-11T01:48:58Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:48:59Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:48:59Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:48:59Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/No_connection_because_the_port_file_has_port_0 249s time="2025-04-11T01:48:59Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44065" 249s time="2025-04-11T01:48:59Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:49:01Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:49:01Z" 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" 249s time="2025-04-11T01:49:01Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:49:02Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:49:02Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:49:02Z" level=debug msg="All connections have now ended." 249s === CONT TestServe/Success_with_systemd_notifier_returning_true 249s time="2025-04-11T01:49:02Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35043" 249s time="2025-04-11T01:49:02Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:49:04Z" level=debug msg="Ready state sent to systemd" 249s time="2025-04-11T01:49:04Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:49:04Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:49:05Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35043" 249s time="2025-04-11T01:49:05Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:49:05Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:49:05Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:49:05Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:49:06Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:49:06Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:49:06Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:49:06Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:49:08Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:49:08Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:49:08Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:49:08Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:49:08Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:49:08Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:49:08Z" level=debug msg="All connections have now ended." 249s time="2025-04-11T01:49:08Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s === CONT TestServe/Success 249s time="2025-04-11T01:49:08Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37525" 249s time="2025-04-11T01:49:08Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:49:08Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:08Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:10Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:49:11Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:37525" 249s time="2025-04-11T01:49:11Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:49:11Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:49:11Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:49:12Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:49:12Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:49:12Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:49:12Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:49:14Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:49:14Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:49:14Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:49:14Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:49:14Z" level=debug msg="All connections have now ended." 249s time="2025-04-11T01:49:14Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:14Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:14Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s === CONT TestServe/Error_because_the_context_is_pre-cancelled 249s time="2025-04-11T01:49:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43533" 249s time="2025-04-11T01:49:14Z" level=debug msg="Building new daemon" 249s time="2025-04-11T01:49:15Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:49:15Z" level=info msg="Waiting for active requests to close." 249s time="2025-04-11T01:49:15Z" level=debug msg="All connections have now ended." 249s --- PASS: TestServe (0.00s) 249s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (2.15s) 249s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (1.16s) 249s --- PASS: TestServe/No_connection_because_there_is_no_server (2.13s) 249s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (2.14s) 249s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (3.13s) 249s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (2.88s) 249s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (3.39s) 249s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (3.20s) 249s --- PASS: TestServe/No_connection_because_there_are_no_certificates (4.07s) 249s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (3.06s) 249s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (6.12s) 249s --- PASS: TestServe/Success (6.09s) 249s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (1.14s) 249s time="2025-04-11T01:49:35Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:35Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:35Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:35Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:49:35Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:49:35Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:49:35Z" 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_dropped3328143590/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3328143590/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 249s time="2025-04-11T01:49:35Z" level=info msg="Reconnecting to Windows host in 1 seconds" 249s time="2025-04-11T01:49:35Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:49:35Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33591" 249s time="2025-04-11T01:49:36Z" level=info msg="Daemon: connecting to Windows Agent" 249s time="2025-04-11T01:49:36Z" level=debug msg="Updated systemd status to \"Connecting\"" 249s time="2025-04-11T01:49:37Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33591" 249s time="2025-04-11T01:49:37Z" level=info msg="Daemon: completed connection to Windows Agent" 249s time="2025-04-11T01:49:37Z" level=debug msg="Updated systemd status to \"Connected\"" 249s time="2025-04-11T01:49:37Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 249s time="2025-04-11T01:49:37Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 249s time="2025-04-11T01:49:37Z" level=debug msg="Server: sent preface messages to all streams" 249s time="2025-04-11T01:49:37Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 249s time="2025-04-11T01:49:37Z" level=info msg="MockWindowsAgent: Connected ready" 249s time="2025-04-11T01:49:37Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 249s time="2025-04-11T01:49:37Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:37Z" level=info msg="Stopping daemon requested." 249s time="2025-04-11T01:49:37Z" level=info msg="Stopping active requests." 249s time="2025-04-11T01:49:37Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:37Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 249s time="2025-04-11T01:49:37Z" level=warning msg="Daemon: disconnected from Windows host" 249s time="2025-04-11T01:49:37Z" level=info msg="Reconnecting to Windows host in 2 seconds" 249s time="2025-04-11T01:49:37Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 249s time="2025-04-11T01:49:37Z" level=debug msg="Updated systemd status to \"Stopped\"" 249s time="2025-04-11T01:49:37Z" level=debug msg="All connections have now ended." 249s --- PASS: TestReconnection (0.00s) 249s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (4.28s) 249s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (4.48s) 249s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (70.03s) 249s PASS 249s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 81.208s 250s === RUN TestConnect 250s === PAUSE TestConnect 250s === RUN TestSendAndRecv 250s --- PASS: TestSendAndRecv (0.40s) 250s === RUN TestServe 250s === PAUSE TestServe 250s === RUN TestStop 250s === PAUSE TestStop 250s === RUN TestWithProMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithProMock (0.00s) 250s === RUN TestWithWslPathMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithWslPathMock (0.00s) 250s === RUN TestWithWslInfoMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithWslInfoMock (0.00s) 250s === RUN TestWithCmdExeMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithCmdExeMock (0.00s) 250s === CONT TestConnect 250s === RUN TestConnect/Success 250s === PAUSE TestConnect/Success 250s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 250s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 250s === CONT TestStop 250s === CONT TestServe 250s time="2025-04-11T01:48:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39423" 250s time="2025-04-11T01:48:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33217" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: Connected ready" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: Connected ready" 250s time="2025-04-11T01:48:21Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 250s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 250s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 250s time="2025-04-11T01:48:25Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 250s --- PASS: TestServe (5.51s) 250s === CONT TestConnect/Success 250s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 250s time="2025-04-11T01:48:31Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 250s time="2025-04-11T01:48:31Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 250s time="2025-04-11T01:48:31Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 250s --- PASS: TestStop (11.72s) 250s --- PASS: TestConnect (0.00s) 250s --- PASS: TestConnect/Success (0.31s) 250s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.00s) 250s PASS 250s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 26.224s 250s === RUN TestInfo 250s === PAUSE TestInfo 250s === RUN TestWslDistroName 250s === PAUSE TestWslDistroName 250s === RUN TestUserProfileDir 250s === PAUSE TestUserProfileDir 250s === RUN TestProStatus 250s === PAUSE TestProStatus 250s === RUN TestProAttach 250s === PAUSE TestProAttach 250s === RUN TestProDetach 250s === PAUSE TestProDetach 250s === RUN TestLandscapeEnable 250s === PAUSE TestLandscapeEnable 250s === RUN TestWindowsHostAddress 250s === PAUSE TestWindowsHostAddress 250s === RUN TestLandscapeDisable 250s === PAUSE TestLandscapeDisable 250s === RUN TestRealBackend 250s === PAUSE TestRealBackend 250s === RUN TestWithProMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithProMock (0.00s) 250s === RUN TestWithLandscapeConfigMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithLandscapeConfigMock (0.00s) 250s === RUN TestWithWslPathMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithWslPathMock (0.00s) 250s === RUN TestWithWslInfoMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithWslInfoMock (0.00s) 250s === RUN TestWithCmdExeMock 250s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 250s --- SKIP: TestWithCmdExeMock (0.00s) 250s === CONT TestInfo 250s === CONT TestProDetach 250s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 250s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 250s === RUN TestProDetach/success_on_unattached_distro 250s === PAUSE TestProDetach/success_on_unattached_distro 250s === RUN TestProDetach/success_on_attached_distro 250s === PAUSE TestProDetach/success_on_attached_distro 250s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 250s === RUN TestInfo/Success 250s === PAUSE TestInfo/Success 250s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 250s === RUN TestInfo/Error_when_WslDistroName_fails 250s === PAUSE TestInfo/Error_when_WslDistroName_fails 250s === RUN TestInfo/Error_when_pro_status_command_fails 250s === PAUSE TestInfo/Error_when_pro_status_command_fails 250s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 250s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 250s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 250s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 250s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 250s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 250s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 250s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 250s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 250s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 250s === CONT TestProAttach 250s === RUN TestProAttach/success 250s === PAUSE TestProAttach/success 250s === RUN TestProAttach/error_on_'pro_attach'_error 250s === PAUSE TestProAttach/error_on_'pro_attach'_error 250s === CONT TestProStatus 250s === RUN TestProStatus/success_on_unattached_distro 250s === PAUSE TestProStatus/success_on_unattached_distro 250s === RUN TestProStatus/success_on_attached_distro 250s === PAUSE TestProStatus/success_on_attached_distro 250s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 250s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 250s === RUN TestProStatus/error_on_'pro_attach'_error 250s === PAUSE TestProStatus/error_on_'pro_attach'_error 250s === CONT TestUserProfileDir 250s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 250s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 250s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 250s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 250s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 250s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 250s === RUN TestUserProfileDir/Error_on_cmd.exe_error 250s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 250s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 250s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 250s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 250s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 250s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 250s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 250s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 250s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 250s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 250s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 250s === RUN TestUserProfileDir/Error_on_wslpath_error 250s === PAUSE TestUserProfileDir/Error_on_wslpath_error 250s === CONT TestWslDistroName 250s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 250s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 250s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 250s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 250s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 250s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 250s === RUN TestWslDistroName/Success_using_wslpath 250s === PAUSE TestWslDistroName/Success_using_wslpath 250s === CONT TestLandscapeDisable 250s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 250s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 250s === RUN TestLandscapeDisable/Success 250s === PAUSE TestLandscapeDisable/Success 250s === CONT TestRealBackend 250s --- PASS: TestRealBackend (0.00s) 250s === CONT TestLandscapeEnable 250s === RUN TestLandscapeEnable/Success_overriding_computer_title 250s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 250s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 250s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 250s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 250s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 250s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 250s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 250s === RUN TestLandscapeEnable/Success 250s === PAUSE TestLandscapeEnable/Success 250s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 250s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 250s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 250s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 250s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 250s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 250s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 250s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 250s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 250s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 250s === CONT TestWindowsHostAddress 250s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 250s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 250s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 250s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 250s === RUN TestWindowsHostAddress/Success_without_NAT 250s === PAUSE TestWindowsHostAddress/Success_without_NAT 250s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 250s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 250s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 250s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 250s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 250s === CONT TestInfo/Success 250s === CONT TestProAttach/success 250s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 250s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 250s === CONT TestProDetach/success_on_attached_distro 250s === CONT TestProDetach/success_on_unattached_distro 250s === CONT TestProStatus/success_on_unattached_distro 250s --- PASS: TestProDetach (0.00s) 250s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (1.20s) 250s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (0.80s) 250s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (1.06s) 250s --- PASS: TestProDetach/success_on_attached_distro (1.12s) 250s --- PASS: TestProDetach/success_on_unattached_distro (1.07s) 250s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 250s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 250s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 250s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 250s === CONT TestInfo/Error_when_pro_status_command_fails 250s === CONT TestInfo/Error_when_WslDistroName_fails 250s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 250s --- PASS: TestInfo (0.00s) 250s --- PASS: TestInfo/Success (1.17s) 250s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (1.15s) 250s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (1.01s) 250s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (1.07s) 250s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (1.07s) 250s --- PASS: TestInfo/Error_when_pro_status_command_fails (1.04s) 250s --- PASS: TestInfo/Error_when_WslDistroName_fails (1.12s) 250s === CONT TestProAttach/error_on_'pro_attach'_error 250s --- PASS: TestProAttach (0.00s) 250s --- PASS: TestProAttach/success (0.80s) 250s --- PASS: TestProAttach/error_on_'pro_attach'_error (0.79s) 250s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 250s === CONT TestProStatus/error_on_'pro_attach'_error 250s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 250s === CONT TestProStatus/success_on_attached_distro 250s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 250s === CONT TestUserProfileDir/Error_on_wslpath_error 250s --- PASS: TestProStatus (0.00s) 250s --- PASS: TestProStatus/success_on_unattached_distro (1.13s) 250s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (1.06s) 250s --- PASS: TestProStatus/error_on_'pro_attach'_error (1.16s) 250s --- PASS: TestProStatus/success_on_attached_distro (1.10s) 250s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 250s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 250s system_test.go:205: Removing default proc/mounts 250s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 250s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 250s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 250s === CONT TestUserProfileDir/Error_on_cmd.exe_error 250s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 250s system_test.go:205: Removing default proc/mounts 250s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 250s === CONT TestLandscapeEnable/Success_overriding_computer_title 250s time="2025-04-11T01:49:02Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 250s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 250s === CONT TestWslDistroName/Success_using_wslpath 250s --- PASS: TestUserProfileDir (0.00s) 250s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (1.89s) 250s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 250s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 250s --- PASS: TestUserProfileDir/Error_on_wslpath_error (1.82s) 250s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (1.82s) 250s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (1.98s) 250s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (1.95s) 250s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 250s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (0.83s) 250s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (2.20s) 250s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 250s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 250s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 250s --- PASS: TestWslDistroName (0.00s) 250s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (0.97s) 250s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 250s --- PASS: TestWslDistroName/Success_using_wslpath (0.89s) 250s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (1.19s) 250s === CONT TestLandscapeDisable/Success 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 250s --- PASS: TestLandscapeDisable (0.00s) 250s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (1.09s) 250s --- PASS: TestLandscapeDisable/Success (1.06s) 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 250s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 250s === CONT TestWindowsHostAddress/Success_without_NAT 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 250s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 250s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 250s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 250s --- PASS: TestWindowsHostAddress (0.00s) 250s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (1.01s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (1.09s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (0.81s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (0.81s) 250s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (0.66s) 250s --- PASS: TestWindowsHostAddress/Success_without_NAT (0.73s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (0.79s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (0.99s) 250s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (1.11s) 250s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (1.11s) 250s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 250s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 250s === NAME TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 250s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 250s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 250s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 250s time="2025-04-11T01:49:11Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 250s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 250s === CONT TestLandscapeEnable/Success 250s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 250s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 250s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 250s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 250s time="2025-04-11T01:49:12Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 250s === NAME TestLandscapeEnable/Success 250s system_test.go:456: testdata/TestLandscapeEnable/golden/success 250s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 250s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 250s --- PASS: TestLandscapeEnable (0.00s) 250s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (1.03s) 250s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (1.17s) 250s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (2.18s) 250s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 250s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (1.20s) 250s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 250s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (0.96s) 250s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 250s --- PASS: TestLandscapeEnable/Success (0.76s) 250s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (0.74s) 250s PASS 250s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 26.937s 250s autopkgtest [01:49:38]: test command1: -----------------------] 250s autopkgtest [01:49:38]: test command1: - - - - - - - - - - results - - - - - - - - - - 250s command1 PASS 251s autopkgtest [01:49:39]: @@@@@@@@@@@@@@@@@@@@ summary 251s command1 PASS 269s nova [W] Using flock in prodstack6-s390x 269s Creating nova instance adt-noble-s390x-wsl-pro-service-20250411-014528-juju-7f2275-prod-proposed-migration-environment-2-e6c00ee7-3796-48a2-9504-8e743e9b9be2 from image adt/ubuntu-noble-s390x-server-20250410.img (UUID b1d73aad-be47-4853-9063-a4b983a112ed)... 269s nova [W] Timed out waiting for 2eeb796d-5252-4af9-9e3d-d1e402109e03 to get deleted.