0s autopkgtest [07:29:45]: starting date and time: 2024-07-19 07:29:45+0000 0s autopkgtest [07:29:45]: git checkout: fd3bed09 nova: allow more retries for quota issues 0s autopkgtest [07:29:45]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.b6yi_ugn/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:ubuntu-advantage-tools --apt-upgrade wsl-pro-service --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=ubuntu-advantage-tools/33.2~24.04' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-2@bos03-arm64-2.secgroup --name adt-noble-arm64-wsl-pro-service-20240719-072944-juju-7f2275-prod-proposed-migration-environment-2-5925edd6-d721-4bb0-8d6d-7270678c17e2 --image adt/ubuntu-noble-arm64-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 1550s autopkgtest [07:55:35]: testbed dpkg architecture: arm64 1551s autopkgtest [07:55:36]: testbed apt version: 2.7.14build2 1551s autopkgtest [07:55:36]: @@@@@@@@@@@@@@@@@@@@ test bed setup 1555s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [265 kB] 1558s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [5700 B] 1558s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [9944 B] 1558s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [33.0 kB] 1558s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 Packages [68.7 kB] 1558s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 c-n-f Metadata [2480 B] 1558s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 Packages [58.7 kB] 1558s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 c-n-f Metadata [116 B] 1558s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 Packages [44.0 kB] 1558s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 c-n-f Metadata [1424 B] 1558s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 c-n-f Metadata [116 B] 1562s Fetched 489 kB in 4s (127 kB/s) 1562s Reading package lists... 1568s Reading package lists... 1569s Building dependency tree... 1569s Reading state information... 1569s Calculating upgrade... 1570s The following packages will be upgraded: 1570s ubuntu-pro-client ubuntu-pro-client-l10n xkb-data 1570s 3 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1570s Need to get 647 kB of archives. 1570s After this operation, 25.6 kB of additional disk space will be used. 1570s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 ubuntu-pro-client-l10n arm64 33.2~24.04 [19.3 kB] 1570s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 ubuntu-pro-client arm64 33.2~24.04 [230 kB] 1570s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 xkb-data all 2.41-2ubuntu1.1 [397 kB] 1572s Fetched 647 kB in 1s (906 kB/s) 1573s (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 ... 112532 files and directories currently installed.) 1573s Preparing to unpack .../ubuntu-pro-client-l10n_33.2~24.04_arm64.deb ... 1573s Unpacking ubuntu-pro-client-l10n (33.2~24.04) over (32.3.1~24.04) ... 1574s Preparing to unpack .../ubuntu-pro-client_33.2~24.04_arm64.deb ... 1574s Unpacking ubuntu-pro-client (33.2~24.04) over (32.3.1~24.04) ... 1575s Preparing to unpack .../xkb-data_2.41-2ubuntu1.1_all.deb ... 1575s Unpacking xkb-data (2.41-2ubuntu1.1) over (2.41-2ubuntu1) ... 1577s Setting up xkb-data (2.41-2ubuntu1.1) ... 1577s Setting up ubuntu-pro-client (33.2~24.04) ... 1577s Installing new version of config file /etc/apparmor.d/ubuntu_pro_apt_news ... 1583s Setting up ubuntu-pro-client-l10n (33.2~24.04) ... 1583s Processing triggers for man-db (2.12.0-4build2) ... 1585s Reading package lists... 1585s Building dependency tree... 1585s Reading state information... 1586s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1589s Hit:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease 1589s Hit:2 http://ftpmaster.internal/ubuntu noble InRelease 1589s Hit:3 http://ftpmaster.internal/ubuntu noble-updates InRelease 1589s Hit:4 http://ftpmaster.internal/ubuntu noble-security InRelease 1593s Reading package lists... 1594s Reading package lists... 1594s Building dependency tree... 1594s Reading state information... 1594s Calculating upgrade... 1595s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1595s Reading package lists... 1595s Building dependency tree... 1595s Reading state information... 1596s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 1596s autopkgtest [07:56:21]: rebooting testbed after setup commands that affected boot 1602s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1635s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1668s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1701s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 1711s autopkgtest [07:58:16]: testbed running kernel: Linux 6.8.0-38-generic #38-Ubuntu SMP PREEMPT_DYNAMIC Fri Jun 7 17:43:15 UTC 2024 1715s autopkgtest [07:58:20]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 1719s Get:1 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (dsc) [1420 B] 1719s Get:2 http://ftpmaster.internal/ubuntu noble/main wsl-pro-service 0.1.4 (tar) [1762 kB] 1720s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 1720s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 1720s gpgv: Can't check signature: No public key 1720s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 1722s autopkgtest [07:58:27]: testing package wsl-pro-service version 0.1.4 1724s autopkgtest [07:58:29]: build not needed 1726s autopkgtest [07:58:31]: test command1: preparing testbed 1728s Reading package lists... 1728s Building dependency tree... 1728s Reading state information... 1729s Starting pkgProblemResolver with broken count: 0 1729s Starting 2 pkgProblemResolver with broken count: 0 1729s Done 1729s The following additional packages will be installed: 1729s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 1729s cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu debhelper debugedit dh-apport 1729s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 1729s g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13 1729s gcc-13-aarch64-linux-gnu gcc-13-base gcc-aarch64-linux-gnu gettext 1729s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 1729s libarchive-zip-perl libasan8 libatomic1 libcc1-0 libdebhelper-perl 1729s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libhwasan0 libisl23 1729s libitm1 liblsan0 libmpc3 libstdc++-13-dev libsub-override-perl libtool 1729s libtsan2 libubsan1 m4 po-debconf 1729s Suggested packages: 1729s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 1729s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 1729s gcc-doc gdb-aarch64-linux-gnu gettext-doc libasprintf-dev libgettextpo-dev 1729s bzr | brz git mercurial subversion libstdc++-13-doc libtool-doc gfortran 1729s | fortran95-compiler gcj-jdk m4-doc libmail-box-perl 1729s Recommended packages: 1729s pkg-config libarchive-cpio-perl libltdl-dev libmail-sendmail-perl 1729s The following NEW packages will be installed: 1729s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 1729s cpp cpp-13 cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu debhelper 1729s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 1729s g++-13 g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13 1729s gcc-13-aarch64-linux-gnu gcc-13-base gcc-aarch64-linux-gnu gettext 1729s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 1729s libarchive-zip-perl libasan8 libatomic1 libcc1-0 libdebhelper-perl 1729s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libhwasan0 libisl23 1729s libitm1 liblsan0 libmpc3 libstdc++-13-dev libsub-override-perl libtool 1729s libtsan2 libubsan1 m4 po-debconf 1730s 0 upgraded, 52 newly installed, 0 to remove and 0 not upgraded. 1730s Need to get 106 MB/106 MB of archives. 1730s After this operation, 441 MB of additional disk space will be used. 1730s Get:1 /tmp/autopkgtest.G4Vb4N/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [760 B] 1730s Get:2 http://ftpmaster.internal/ubuntu noble/main arm64 m4 arm64 1.4.19-4build1 [240 kB] 1730s Get:3 http://ftpmaster.internal/ubuntu noble/main arm64 autoconf all 2.71-3 [339 kB] 1730s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 autotools-dev all 20220109.1 [44.9 kB] 1730s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 automake all 1:1.16.5-1.3ubuntu1 [558 kB] 1731s Get:6 http://ftpmaster.internal/ubuntu noble/main arm64 autopoint all 0.21-14ubuntu2 [422 kB] 1731s Get:7 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13-base arm64 13.2.0-23ubuntu4 [49.0 kB] 1731s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 libisl23 arm64 0.26-3build1 [669 kB] 1731s Get:9 http://ftpmaster.internal/ubuntu noble/main arm64 libmpc3 arm64 1.3.1-1build1 [56.4 kB] 1731s Get:10 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [10.3 MB] 1733s Get:11 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13 arm64 13.2.0-23ubuntu4 [1032 B] 1733s Get:12 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [5316 B] 1733s Get:13 http://ftpmaster.internal/ubuntu noble/main arm64 cpp arm64 4:13.2.0-7ubuntu1 [22.4 kB] 1733s Get:14 http://ftpmaster.internal/ubuntu noble/main arm64 libcc1-0 arm64 14-20240412-0ubuntu1 [44.7 kB] 1733s Get:15 http://ftpmaster.internal/ubuntu noble/main arm64 libgomp1 arm64 14-20240412-0ubuntu1 [144 kB] 1733s Get:16 http://ftpmaster.internal/ubuntu noble/main arm64 libitm1 arm64 14-20240412-0ubuntu1 [27.9 kB] 1733s Get:17 http://ftpmaster.internal/ubuntu noble/main arm64 libatomic1 arm64 14-20240412-0ubuntu1 [11.4 kB] 1733s Get:18 http://ftpmaster.internal/ubuntu noble/main arm64 libasan8 arm64 14-20240412-0ubuntu1 [2921 kB] 1733s Get:19 http://ftpmaster.internal/ubuntu noble/main arm64 liblsan0 arm64 14-20240412-0ubuntu1 [1286 kB] 1733s Get:20 http://ftpmaster.internal/ubuntu noble/main arm64 libtsan2 arm64 14-20240412-0ubuntu1 [2692 kB] 1733s Get:21 http://ftpmaster.internal/ubuntu noble/main arm64 libubsan1 arm64 14-20240412-0ubuntu1 [1155 kB] 1733s Get:22 http://ftpmaster.internal/ubuntu noble/main arm64 libhwasan0 arm64 14-20240412-0ubuntu1 [1604 kB] 1733s Get:23 http://ftpmaster.internal/ubuntu noble/main arm64 libgcc-13-dev arm64 13.2.0-23ubuntu4 [2470 kB] 1733s Get:24 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [20.1 MB] 1734s Get:25 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13 arm64 13.2.0-23ubuntu4 [472 kB] 1734s Get:26 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [1198 B] 1734s Get:27 http://ftpmaster.internal/ubuntu noble/main arm64 gcc arm64 4:13.2.0-7ubuntu1 [5018 B] 1734s Get:28 http://ftpmaster.internal/ubuntu noble/main arm64 libstdc++-13-dev arm64 13.2.0-23ubuntu4 [2379 kB] 1734s Get:29 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [11.7 MB] 1735s Get:30 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13 arm64 13.2.0-23ubuntu4 [14.5 kB] 1735s Get:31 http://ftpmaster.internal/ubuntu noble/main arm64 g++-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [962 B] 1735s Get:32 http://ftpmaster.internal/ubuntu noble/main arm64 g++ arm64 4:13.2.0-7ubuntu1 [1082 B] 1735s Get:33 http://ftpmaster.internal/ubuntu noble/main arm64 build-essential arm64 12.10ubuntu1 [4932 B] 1735s Get:34 http://ftpmaster.internal/ubuntu noble/main arm64 libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 1735s Get:35 http://ftpmaster.internal/ubuntu noble/main arm64 libtool all 2.4.7-7build1 [166 kB] 1735s Get:36 http://ftpmaster.internal/ubuntu noble/main arm64 dh-autoreconf all 20 [16.1 kB] 1735s Get:37 http://ftpmaster.internal/ubuntu noble/main arm64 libarchive-zip-perl all 1.68-1 [90.2 kB] 1735s Get:38 http://ftpmaster.internal/ubuntu noble/main arm64 libsub-override-perl all 0.10-1 [10.0 kB] 1735s Get:39 http://ftpmaster.internal/ubuntu noble/main arm64 libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 1735s Get:40 http://ftpmaster.internal/ubuntu noble/main arm64 dh-strip-nondeterminism all 1.13.1-1 [5362 B] 1735s Get:41 http://ftpmaster.internal/ubuntu noble/main arm64 debugedit arm64 1:5.0-5build2 [45.3 kB] 1735s Get:42 http://ftpmaster.internal/ubuntu noble/main arm64 dwz arm64 0.15-1build6 [113 kB] 1735s Get:43 http://ftpmaster.internal/ubuntu noble/main arm64 gettext arm64 0.21-14ubuntu2 [845 kB] 1735s Get:44 http://ftpmaster.internal/ubuntu noble/main arm64 intltool-debian all 0.35.0+20060710.6 [23.2 kB] 1735s Get:45 http://ftpmaster.internal/ubuntu noble/main arm64 po-debconf all 1.0.21+nmu1 [233 kB] 1735s Get:46 http://ftpmaster.internal/ubuntu noble/main arm64 debhelper all 13.14.1ubuntu5 [869 kB] 1735s Get:47 http://ftpmaster.internal/ubuntu noble-updates/universe arm64 dh-apport all 2.28.1-0ubuntu3 [17.2 kB] 1735s Get:48 http://ftpmaster.internal/ubuntu noble-updates/main arm64 golang-1.22-src all 1.22.2-2ubuntu0.1 [19.7 MB] 1737s Get:49 http://ftpmaster.internal/ubuntu noble-updates/main arm64 golang-1.22-go arm64 1.22.2-2ubuntu0.1 [23.6 MB] 1738s Get:50 http://ftpmaster.internal/ubuntu noble/main arm64 golang-src all 2:1.22~2build1 [5078 B] 1738s Get:51 http://ftpmaster.internal/ubuntu noble/main arm64 golang-go arm64 2:1.22~2build1 [43.9 kB] 1738s Get:52 http://ftpmaster.internal/ubuntu noble/main arm64 dh-golang all 1.62 [25.2 kB] 1749s Fetched 106 MB in 9s (12.3 MB/s) 1749s Selecting previously unselected package m4. 1749s (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 ... 112533 files and directories currently installed.) 1749s Preparing to unpack .../00-m4_1.4.19-4build1_arm64.deb ... 1749s Unpacking m4 (1.4.19-4build1) ... 1750s Selecting previously unselected package autoconf. 1752s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 1752s Unpacking autoconf (2.71-3) ... 1753s Selecting previously unselected package autotools-dev. 1768s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 1768s Unpacking autotools-dev (20220109.1) ... 1775s Selecting previously unselected package automake. 1782s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 1783s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 1783s Selecting previously unselected package autopoint. 1786s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 1786s Unpacking autopoint (0.21-14ubuntu2) ... 1787s Selecting previously unselected package gcc-13-base:arm64. 1788s Preparing to unpack .../05-gcc-13-base_13.2.0-23ubuntu4_arm64.deb ... 1788s Unpacking gcc-13-base:arm64 (13.2.0-23ubuntu4) ... 1788s Selecting previously unselected package libisl23:arm64. 1790s Preparing to unpack .../06-libisl23_0.26-3build1_arm64.deb ... 1790s Unpacking libisl23:arm64 (0.26-3build1) ... 1790s Selecting previously unselected package libmpc3:arm64. 1791s Preparing to unpack .../07-libmpc3_1.3.1-1build1_arm64.deb ... 1791s Unpacking libmpc3:arm64 (1.3.1-1build1) ... 1791s Selecting previously unselected package cpp-13-aarch64-linux-gnu. 1793s Preparing to unpack .../08-cpp-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 1793s Unpacking cpp-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1793s Selecting previously unselected package cpp-13. 1794s Preparing to unpack .../09-cpp-13_13.2.0-23ubuntu4_arm64.deb ... 1794s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 1795s Selecting previously unselected package cpp-aarch64-linux-gnu. 1796s Preparing to unpack .../10-cpp-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 1796s Unpacking cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1796s Selecting previously unselected package cpp. 1797s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_arm64.deb ... 1797s Unpacking cpp (4:13.2.0-7ubuntu1) ... 1797s Selecting previously unselected package libcc1-0:arm64. 1798s Preparing to unpack .../12-libcc1-0_14-20240412-0ubuntu1_arm64.deb ... 1798s Unpacking libcc1-0:arm64 (14-20240412-0ubuntu1) ... 1798s Selecting previously unselected package libgomp1:arm64. 1799s Preparing to unpack .../13-libgomp1_14-20240412-0ubuntu1_arm64.deb ... 1799s Unpacking libgomp1:arm64 (14-20240412-0ubuntu1) ... 1799s Selecting previously unselected package libitm1:arm64. 1800s Preparing to unpack .../14-libitm1_14-20240412-0ubuntu1_arm64.deb ... 1800s Unpacking libitm1:arm64 (14-20240412-0ubuntu1) ... 1801s Selecting previously unselected package libatomic1:arm64. 1802s Preparing to unpack .../15-libatomic1_14-20240412-0ubuntu1_arm64.deb ... 1802s Unpacking libatomic1:arm64 (14-20240412-0ubuntu1) ... 1802s Selecting previously unselected package libasan8:arm64. 1803s Preparing to unpack .../16-libasan8_14-20240412-0ubuntu1_arm64.deb ... 1803s Unpacking libasan8:arm64 (14-20240412-0ubuntu1) ... 1803s Selecting previously unselected package liblsan0:arm64. 1805s Preparing to unpack .../17-liblsan0_14-20240412-0ubuntu1_arm64.deb ... 1805s Unpacking liblsan0:arm64 (14-20240412-0ubuntu1) ... 1805s Selecting previously unselected package libtsan2:arm64. 1806s Preparing to unpack .../18-libtsan2_14-20240412-0ubuntu1_arm64.deb ... 1806s Unpacking libtsan2:arm64 (14-20240412-0ubuntu1) ... 1806s Selecting previously unselected package libubsan1:arm64. 1807s Preparing to unpack .../19-libubsan1_14-20240412-0ubuntu1_arm64.deb ... 1807s Unpacking libubsan1:arm64 (14-20240412-0ubuntu1) ... 1807s Selecting previously unselected package libhwasan0:arm64. 1809s Preparing to unpack .../20-libhwasan0_14-20240412-0ubuntu1_arm64.deb ... 1809s Unpacking libhwasan0:arm64 (14-20240412-0ubuntu1) ... 1809s Selecting previously unselected package libgcc-13-dev:arm64. 1810s Preparing to unpack .../21-libgcc-13-dev_13.2.0-23ubuntu4_arm64.deb ... 1810s Unpacking libgcc-13-dev:arm64 (13.2.0-23ubuntu4) ... 1810s Selecting previously unselected package gcc-13-aarch64-linux-gnu. 1812s Preparing to unpack .../22-gcc-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 1812s Unpacking gcc-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1812s Selecting previously unselected package gcc-13. 1814s Preparing to unpack .../23-gcc-13_13.2.0-23ubuntu4_arm64.deb ... 1814s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 1815s Selecting previously unselected package gcc-aarch64-linux-gnu. 1816s Preparing to unpack .../24-gcc-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 1816s Unpacking gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1816s Selecting previously unselected package gcc. 1818s Preparing to unpack .../25-gcc_4%3a13.2.0-7ubuntu1_arm64.deb ... 1818s Unpacking gcc (4:13.2.0-7ubuntu1) ... 1818s Selecting previously unselected package libstdc++-13-dev:arm64. 1824s Preparing to unpack .../26-libstdc++-13-dev_13.2.0-23ubuntu4_arm64.deb ... 1824s Unpacking libstdc++-13-dev:arm64 (13.2.0-23ubuntu4) ... 1825s Selecting previously unselected package g++-13-aarch64-linux-gnu. 1832s Preparing to unpack .../27-g++-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 1832s Unpacking g++-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1833s Selecting previously unselected package g++-13. 1835s Preparing to unpack .../28-g++-13_13.2.0-23ubuntu4_arm64.deb ... 1835s Unpacking g++-13 (13.2.0-23ubuntu4) ... 1835s Selecting previously unselected package g++-aarch64-linux-gnu. 1837s Preparing to unpack .../29-g++-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 1837s Unpacking g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1837s Selecting previously unselected package g++. 1839s Preparing to unpack .../30-g++_4%3a13.2.0-7ubuntu1_arm64.deb ... 1839s Unpacking g++ (4:13.2.0-7ubuntu1) ... 1839s Selecting previously unselected package build-essential. 1840s Preparing to unpack .../31-build-essential_12.10ubuntu1_arm64.deb ... 1840s Unpacking build-essential (12.10ubuntu1) ... 1840s Selecting previously unselected package libdebhelper-perl. 1840s Preparing to unpack .../32-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 1840s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 1840s Selecting previously unselected package libtool. 1843s Preparing to unpack .../33-libtool_2.4.7-7build1_all.deb ... 1843s Unpacking libtool (2.4.7-7build1) ... 1844s Selecting previously unselected package dh-autoreconf. 1851s Preparing to unpack .../34-dh-autoreconf_20_all.deb ... 1851s Unpacking dh-autoreconf (20) ... 1852s Selecting previously unselected package libarchive-zip-perl. 1855s Preparing to unpack .../35-libarchive-zip-perl_1.68-1_all.deb ... 1855s Unpacking libarchive-zip-perl (1.68-1) ... 1856s Selecting previously unselected package libsub-override-perl. 1858s Preparing to unpack .../36-libsub-override-perl_0.10-1_all.deb ... 1858s Unpacking libsub-override-perl (0.10-1) ... 1859s Selecting previously unselected package libfile-stripnondeterminism-perl. 1860s Preparing to unpack .../37-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 1860s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 1861s Selecting previously unselected package dh-strip-nondeterminism. 1863s Preparing to unpack .../38-dh-strip-nondeterminism_1.13.1-1_all.deb ... 1863s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 1863s Selecting previously unselected package debugedit. 1864s Preparing to unpack .../39-debugedit_1%3a5.0-5build2_arm64.deb ... 1864s Unpacking debugedit (1:5.0-5build2) ... 1865s Selecting previously unselected package dwz. 1866s Preparing to unpack .../40-dwz_0.15-1build6_arm64.deb ... 1866s Unpacking dwz (0.15-1build6) ... 1866s Selecting previously unselected package gettext. 1868s Preparing to unpack .../41-gettext_0.21-14ubuntu2_arm64.deb ... 1868s Unpacking gettext (0.21-14ubuntu2) ... 1868s Selecting previously unselected package intltool-debian. 1869s Preparing to unpack .../42-intltool-debian_0.35.0+20060710.6_all.deb ... 1869s Unpacking intltool-debian (0.35.0+20060710.6) ... 1869s Selecting previously unselected package po-debconf. 1871s Preparing to unpack .../43-po-debconf_1.0.21+nmu1_all.deb ... 1871s Unpacking po-debconf (1.0.21+nmu1) ... 1872s Selecting previously unselected package debhelper. 1874s Preparing to unpack .../44-debhelper_13.14.1ubuntu5_all.deb ... 1874s Unpacking debhelper (13.14.1ubuntu5) ... 1874s Selecting previously unselected package dh-apport. 1877s Preparing to unpack .../45-dh-apport_2.28.1-0ubuntu3_all.deb ... 1877s Unpacking dh-apport (2.28.1-0ubuntu3) ... 1878s Selecting previously unselected package golang-1.22-src. 1880s Preparing to unpack .../46-golang-1.22-src_1.22.2-2ubuntu0.1_all.deb ... 1880s Unpacking golang-1.22-src (1.22.2-2ubuntu0.1) ... 1883s Selecting previously unselected package golang-1.22-go. 1885s Preparing to unpack .../47-golang-1.22-go_1.22.2-2ubuntu0.1_arm64.deb ... 1885s Unpacking golang-1.22-go (1.22.2-2ubuntu0.1) ... 1885s Selecting previously unselected package golang-src. 1886s Preparing to unpack .../48-golang-src_2%3a1.22~2build1_all.deb ... 1887s Unpacking golang-src (2:1.22~2build1) ... 1887s Selecting previously unselected package golang-go:arm64. 1889s Preparing to unpack .../49-golang-go_2%3a1.22~2build1_arm64.deb ... 1890s Unpacking golang-go:arm64 (2:1.22~2build1) ... 1890s Selecting previously unselected package dh-golang. 1891s Preparing to unpack .../50-dh-golang_1.62_all.deb ... 1891s Unpacking dh-golang (1.62) ... 1891s Selecting previously unselected package autopkgtest-satdep. 1894s Preparing to unpack .../51-1-autopkgtest-satdep.deb ... 1894s Unpacking autopkgtest-satdep (0) ... 1895s Setting up libarchive-zip-perl (1.68-1) ... 1895s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 1895s Setting up m4 (1.4.19-4build1) ... 1895s Setting up libgomp1:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up dh-apport (2.28.1-0ubuntu3) ... 1895s Setting up autotools-dev (20220109.1) ... 1895s Setting up gcc-13-base:arm64 (13.2.0-23ubuntu4) ... 1895s Setting up golang-1.22-src (1.22.2-2ubuntu0.1) ... 1895s Setting up libmpc3:arm64 (1.3.1-1build1) ... 1895s Setting up libatomic1:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up autopoint (0.21-14ubuntu2) ... 1895s Setting up autoconf (2.71-3) ... 1895s Setting up libubsan1:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up dwz (0.15-1build6) ... 1895s Setting up libhwasan0:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up libasan8:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up debugedit (1:5.0-5build2) ... 1895s Setting up libsub-override-perl (0.10-1) ... 1895s Setting up libtsan2:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up libisl23:arm64 (0.26-3build1) ... 1895s Setting up golang-src (2:1.22~2build1) ... 1895s Setting up libcc1-0:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up liblsan0:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up libitm1:arm64 (14-20240412-0ubuntu1) ... 1895s Setting up automake (1:1.16.5-1.3ubuntu1) ... 1896s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 1896s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 1896s Setting up gettext (0.21-14ubuntu2) ... 1896s Setting up cpp-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1896s Setting up golang-1.22-go (1.22.2-2ubuntu0.1) ... 1896s Setting up intltool-debian (0.35.0+20060710.6) ... 1896s Setting up cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1896s Setting up dh-strip-nondeterminism (1.13.1-1) ... 1896s Setting up libgcc-13-dev:arm64 (13.2.0-23ubuntu4) ... 1896s Setting up libstdc++-13-dev:arm64 (13.2.0-23ubuntu4) ... 1896s Setting up cpp-13 (13.2.0-23ubuntu4) ... 1896s Setting up golang-go:arm64 (2:1.22~2build1) ... 1896s Setting up po-debconf (1.0.21+nmu1) ... 1896s Setting up gcc-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1896s Setting up gcc-13 (13.2.0-23ubuntu4) ... 1896s Setting up cpp (4:13.2.0-7ubuntu1) ... 1896s Setting up g++-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 1896s Setting up gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1896s Setting up g++-13 (13.2.0-23ubuntu4) ... 1896s Setting up libtool (2.4.7-7build1) ... 1896s Setting up gcc (4:13.2.0-7ubuntu1) ... 1896s Setting up dh-autoreconf (20) ... 1896s Setting up g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 1896s Setting up debhelper (13.14.1ubuntu5) ... 1896s Setting up g++ (4:13.2.0-7ubuntu1) ... 1896s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 1896s Setting up build-essential (12.10ubuntu1) ... 1896s Setting up dh-golang (1.62) ... 1896s Setting up autopkgtest-satdep (0) ... 1896s Processing triggers for man-db (2.12.0-4build2) ... 1903s Processing triggers for install-info (7.1-3build2) ... 1904s Processing triggers for libc-bin (2.39-0ubuntu8.2) ... 1911s (Reading database ... 129103 files and directories currently installed.) 1911s Removing autopkgtest-satdep (0) ... 1912s autopkgtest [08:01:37]: test command1: ./debian/tests/test 1912s autopkgtest [08:01:37]: test command1: [----------------------- 2028s === RUN TestRunSignal 2028s === RUN TestRunSignal/Send_SIGINT_exits 2028s INFO Starting WSL Pro Service version Dev 2028s === RUN TestRunSignal/Send_SIGTERM_exits 2028s INFO Starting WSL Pro Service version Dev 2028s --- PASS: TestRunSignal (0.20s) 2028s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 2028s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 2028s === RUN TestRun 2028s === PAUSE TestRun 2028s === CONT TestRun 2028s === RUN TestRun/Run_and_exit_successfully 2028s === PAUSE TestRun/Run_and_exit_successfully 2028s === RUN TestRun/Run_and_return_error 2028s === PAUSE TestRun/Run_and_return_error 2028s === RUN TestRun/Run_and_return_usage_error 2028s === PAUSE TestRun/Run_and_return_usage_error 2028s === RUN TestRun/Run_and_usage_error_only_does_not_fail 2028s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 2028s === CONT TestRun/Run_and_exit_successfully 2028s === CONT TestRun/Run_and_return_usage_error 2028s INFO Starting WSL Pro Service version Dev 2028s INFO Starting WSL Pro Service version Dev 2028s ERROR context.Background Error requested 2028s === CONT TestRun/Run_and_usage_error_only_does_not_fail 2028s === CONT TestRun/Run_and_return_error 2028s INFO Starting WSL Pro Service version Dev 2028s INFO Starting WSL Pro Service version Dev 2028s ERROR context.Background Error requested 2028s --- PASS: TestRun (0.00s) 2028s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 2028s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 2028s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 2028s --- PASS: TestRun/Run_and_return_error (0.10s) 2028s PASS 2028s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 1.095s 2029s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 2074s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 2083s === RUN TestHelp 2083s --- PASS: TestHelp (0.05s) 2083s === RUN TestCompletion 2083s --- PASS: TestCompletion (0.03s) 2083s === RUN TestVersion 2083s --- PASS: TestVersion (0.00s) 2083s === RUN TestNoUsageError 2083s --- PASS: TestNoUsageError (0.00s) 2083s === RUN TestUsageError 2083s === PAUSE TestUsageError 2083s === RUN TestCanQuitWhenExecute 2083s === PAUSE TestCanQuitWhenExecute 2083s === RUN TestCanQuitTwice 2083s === PAUSE TestCanQuitTwice 2083s === RUN TestAppCanQuitWithoutExecute 2083s === PAUSE TestAppCanQuitWithoutExecute 2083s === RUN TestAppRunFailsOnComponentsCreationAndQuit 2083s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 2083s === RUN TestAppGetRootCmd 2083s === PAUSE TestAppGetRootCmd 2083s === RUN TestWithProMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithProMock (0.00s) 2083s === RUN TestWithWslPathMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithWslPathMock (0.00s) 2083s === RUN TestWithWslInfoMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithWslInfoMock (0.00s) 2083s === RUN TestWithCmdExeMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithCmdExeMock (0.00s) 2083s === CONT TestUsageError 2083s === CONT TestAppCanQuitWithoutExecute 2083s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 2083s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 2083s === CONT TestAppGetRootCmd 2083s --- PASS: TestAppGetRootCmd (0.00s) 2083s === CONT TestAppRunFailsOnComponentsCreationAndQuit 2083s --- PASS: TestUsageError (0.00s) 2083s === CONT TestCanQuitTwice 2083s time="2024-07-19T08:03:39Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 2083s time="2024-07-19T08:03:39Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:75 New() Building new daemon" 2083s time="2024-07-19T08:03:53Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 2083s time="2024-07-19T08:03:56Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 2083s time="2024-07-19T08:03:56Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:03:56Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:01Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:04:01Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:01Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (24.75s) 2083s === CONT TestCanQuitWhenExecute 2083s time="2024-07-19T08:04:01Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38669" 2083s time="2024-07-19T08:04:01Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 2083s time="2024-07-19T08:04:01Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:75 New() Building new daemon" 2083s time="2024-07-19T08:04:06Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:34313" 2083s time="2024-07-19T08:04:06Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 2083s time="2024-07-19T08:04:07Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 2083s time="2024-07-19T08:04:07Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 2083s time="2024-07-19T08:04:20Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/testutils/mock_agent.go:275 (*mockWSLInstanceService).Connected() MockWindowsAgent: Connected ready" 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/testutils/mock_agent.go:326 (*mockWSLInstanceService).LandscapeConfigCommands() MockWindowsAgent: LandscapeConfigCommands ready" 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/testutils/mock_agent.go:300 (*mockWSLInstanceService).ProAttachmentCommands() MockWindowsAgent: ProAttachmentCommands ready" 2083s time="2024-07-19T08:04:20Z" level=warning msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: serve error: could not receive ProAttachCmd: context canceled" 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 2083s time="2024-07-19T08:04:20Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:20Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s time="2024-07-19T08:04:20Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.G4Vb4N/build.A4f/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:04:20Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:20Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s --- PASS: TestCanQuitTwice (42.93s) 2083s time="2024-07-19T08:04:20Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.G4Vb4N/build.A4f/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 2083s time="2024-07-19T08:04:20Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.G4Vb4N/build.A4f/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 2083s time="2024-07-19T08:04:24Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 2083s time="2024-07-19T08:04:25Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:04:25Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:27Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:38669" 2083s time="2024-07-19T08:04:27Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 2083s time="2024-07-19T08:04:27Z" level=warning msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:38669: connect: connection refused\"" 2083s time="2024-07-19T08:04:27Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 2083s time="2024-07-19T08:04:27Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s time="2024-07-19T08:04:27Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 2083s time="2024-07-19T08:04:27Z" level=info msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 2083s time="2024-07-19T08:04:27Z" level=debug msg="/tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 2083s --- PASS: TestCanQuitWhenExecute (25.95s) 2083s PASS 2083s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 53.575s 2083s === RUN TestApplyProToken 2083s === PAUSE TestApplyProToken 2083s === RUN TestApplyLandscapeConfig 2083s === PAUSE TestApplyLandscapeConfig 2083s === RUN TestWithProMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithProMock (0.00s) 2083s === RUN TestWithLandscapeConfigMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithLandscapeConfigMock (0.00s) 2083s === RUN TestWithWslPathMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithWslPathMock (0.00s) 2083s === RUN TestWithWslInfoMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithWslInfoMock (0.00s) 2083s === RUN TestWithCmdExeMock 2083s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2083s --- SKIP: TestWithCmdExeMock (0.00s) 2083s === CONT TestApplyProToken 2083s === RUN TestApplyProToken/Success_attaching 2083s === PAUSE TestApplyProToken/Success_attaching 2083s === RUN TestApplyProToken/Success_detaching 2083s === PAUSE TestApplyProToken/Success_detaching 2083s === RUN TestApplyProToken/Error_calling_pro_detach 2083s === PAUSE TestApplyProToken/Error_calling_pro_detach 2083s === RUN TestApplyProToken/Error_calling_pro_attach 2083s === PAUSE TestApplyProToken/Error_calling_pro_attach 2083s === CONT TestApplyProToken/Success_attaching 2083s time="2024-07-19T08:03:36Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 2083s === CONT TestApplyProToken/Error_calling_pro_attach 2083s time="2024-07-19T08:03:36Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 2083s === CONT TestApplyProToken/Error_calling_pro_detach 2083s time="2024-07-19T08:03:47Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 2083s === CONT TestApplyProToken/Success_detaching 2083s time="2024-07-19T08:03:48Z" level=info msg="ApplyProToken: Received empty token: detaching" 2083s === CONT TestApplyLandscapeConfig 2083s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 2083s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 2083s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 2083s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 2083s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 2083s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 2083s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 2083s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 2083s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 2083s time="2024-07-19T08:03:53Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 2083s --- PASS: TestApplyProToken (0.00s) 2083s --- PASS: TestApplyProToken/Success_attaching (11.42s) 2083s --- PASS: TestApplyProToken/Error_calling_pro_attach (12.22s) 2083s --- PASS: TestApplyProToken/Error_calling_pro_detach (6.12s) 2083s --- PASS: TestApplyProToken/Success_detaching (6.25s) 2083s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 2083s time="2024-07-19T08:03:54Z" level=info msg="ApplyLandscapeConfig: received config: registering" 2083s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 2083s time="2024-07-19T08:04:00Z" level=info msg="ApplyLandscapeConfig: received config: registering" 2083s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 2083s time="2024-07-19T08:04:01Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 2083s --- PASS: TestApplyLandscapeConfig (0.00s) 2083s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (6.32s) 2083s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (6.71s) 2083s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (18.24s) 2083s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (17.35s) 2083s PASS 2083s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 42.984s 2379s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 2404s === RUN TestNew 2404s === PAUSE TestNew 2404s === RUN TestServe 2404s === PAUSE TestServe 2404s === RUN TestServeAndQuit 2404s === PAUSE TestServeAndQuit 2404s === RUN TestReconnection 2404s === PAUSE TestReconnection 2404s === RUN TestWithProMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithProMock (0.00s) 2404s === RUN TestWithWslPathMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslPathMock (0.00s) 2404s === RUN TestWithWslInfoMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslInfoMock (0.00s) 2404s === RUN TestWithCmdExeMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithCmdExeMock (0.00s) 2404s === CONT TestNew 2404s === RUN TestNew/Error_when_WslPath_returns_error 2404s === PAUSE TestNew/Error_when_WslPath_returns_error 2404s === RUN TestNew/Success 2404s === PAUSE TestNew/Success 2404s === CONT TestNew/Error_when_WslPath_returns_error 2404s time="2024-07-19T08:04:24Z" level=debug msg="Building new daemon" 2404s === CONT TestServeAndQuit 2404s === RUN TestServeAndQuit/Success_with_forceful_quit 2404s === PAUSE TestServeAndQuit/Success_with_forceful_quit 2404s === RUN TestServeAndQuit/Success_with_double_quit 2404s === PAUSE TestServeAndQuit/Success_with_double_quit 2404s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 2404s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 2404s === RUN TestServeAndQuit/Success_with_graceful_quit 2404s === PAUSE TestServeAndQuit/Success_with_graceful_quit 2404s === CONT TestServeAndQuit/Success_with_forceful_quit 2404s time="2024-07-19T08:04:24Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38067" 2404s time="2024-07-19T08:04:24Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:04:31Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:04:31Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:04:31Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s === CONT TestServe 2404s === RUN TestServe/Success 2404s === PAUSE TestServe/Success 2404s === RUN TestServe/No_connection_because_the_port_file_is_empty 2404s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 2404s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 2404s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 2404s === RUN TestServe/No_connection_because_the_port_file_has_port_0 2404s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 2404s === RUN TestServe/No_connection_because_there_is_no_server 2404s === PAUSE TestServe/No_connection_because_there_is_no_server 2404s === RUN TestServe/Success_with_systemd_notifier_returning_true 2404s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 2404s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 2404s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 2404s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 2404s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 2404s === RUN TestServe/No_connection_because_there_are_no_certificates 2404s === PAUSE TestServe/No_connection_because_there_are_no_certificates 2404s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 2404s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 2404s === RUN TestServe/Error_because_the_context_is_pre-cancelled 2404s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 2404s === RUN TestServe/Error_because_the_notifier_returns_an_error 2404s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 2404s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 2404s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 2404s === CONT TestNew/Success 2404s time="2024-07-19T08:04:31Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:04:35Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38067" 2404s time="2024-07-19T08:04:35Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:04:35Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:04:35Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:04:35Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:04:40Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:04:40Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:04:40Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:04:40Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:04:40Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:04:40Z" level=info msg="Stopping active requests." 2404s time="2024-07-19T08:04:40Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:04:40Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:04:40Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:04:40Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:04:40Z" level=debug msg="All connections have now ended." 2404s time="2024-07-19T08:04:40Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:04:40Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:04:40Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s === CONT TestReconnection 2404s === RUN TestReconnection/Success_connecting_after_failing_to_connect 2404s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 2404s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 2404s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 2404s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 2404s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 2404s === CONT TestServeAndQuit/Success_with_graceful_quit 2404s time="2024-07-19T08:04:40Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44911" 2404s time="2024-07-19T08:04:40Z" level=debug msg="Building new daemon" 2404s --- PASS: TestNew (0.00s) 2404s --- PASS: TestNew/Error_when_WslPath_returns_error (7.62s) 2404s --- PASS: TestNew/Success (8.97s) 2404s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 2404s time="2024-07-19T08:04:40Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45245" 2404s time="2024-07-19T08:04:40Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:04:48Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:04:48Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:04:48Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:04:48Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:04:48Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:04:48Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:04:48Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:04:48Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s === CONT TestServeAndQuit/Success_with_double_quit 2404s time="2024-07-19T08:04:48Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38929" 2404s time="2024-07-19T08:04:48Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:04:53Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44911" 2404s time="2024-07-19T08:04:53Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:04:53Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:04:53Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:04:53Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s === NAME TestServeAndQuit/Success_with_graceful_quit 2404s daemon_test.go:296: 2404s Error Trace: /tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon_test.go:296 2404s Error: Condition never satisfied 2404s Test: TestServeAndQuit/Success_with_graceful_quit 2404s Messages: Daemon never connected to agent's service 2404s === CONT TestServe/Success 2404s time="2024-07-19T08:05:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:07Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:07Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46499" 2404s time="2024-07-19T08:05:07Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:05:08Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:05:08Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:05:08Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:05:08Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:05:14Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38929" 2404s time="2024-07-19T08:05:14Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:05:14Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:05:14Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:05:14Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:05:22Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:05:22Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:05:22Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:05:22Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:05:22Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:22Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:22Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:05:22Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:05:22Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:05:22Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:05:22Z" level=debug msg="All connections have now ended." 2404s time="2024-07-19T08:05:22Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:22Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:22Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:22Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:22Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:22Z" level=debug msg="All connections have now ended." 2404s --- FAIL: TestServeAndQuit (0.00s) 2404s --- PASS: TestServeAndQuit/Success_with_forceful_quit (16.43s) 2404s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (7.39s) 2404s --- FAIL: TestServeAndQuit/Success_with_graceful_quit (26.63s) 2404s --- PASS: TestServeAndQuit/Success_with_double_quit (34.36s) 2404s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 2404s time="2024-07-19T08:05:22Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:05:22Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45353" 2404s time="2024-07-19T08:05:22Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:05:29Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46499" 2404s time="2024-07-19T08:05:29Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:05:29Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:05:29Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:05:34Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:05:34Z" 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" 2404s time="2024-07-19T08:05:34Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:05:35Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:05:35Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:05:35Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:05:35Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:05:35Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:35Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:35Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 2404s time="2024-07-19T08:05:35Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45211" 2404s time="2024-07-19T08:05:35Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:05:38Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:38Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:38Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:05:38Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:05:38Z" level=debug msg="All connections have now ended." 2404s time="2024-07-19T08:05:38Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:38Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:38Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s === CONT TestServe/Error_because_the_notifier_returns_an_error 2404s time="2024-07-19T08:05:38Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37865" 2404s time="2024-07-19T08:05:38Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:05:48Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:05:57Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 2404s time="2024-07-19T08:05:57Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:57Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:57Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/Error_because_the_context_is_pre-cancelled 2404s time="2024-07-19T08:05:57Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41363" 2404s time="2024-07-19T08:05:57Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:05:58Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:05:58Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:05:58Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 2404s time="2024-07-19T08:05:58Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33351" 2404s time="2024-07-19T08:05:58Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:06:09Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:06:09Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:06:09Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_there_are_no_certificates 2404s time="2024-07-19T08:06:09Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:40045" 2404s time="2024-07-19T08:06:09Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:06:09Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:06:20Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:33351" 2404s time="2024-07-19T08:06:20Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file1446740339/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 2404s time="2024-07-19T08:06:20Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:06:21Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:06:21Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:06:21Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_there_is_no_server 2404s time="2024-07-19T08:06:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38679" 2404s time="2024-07-19T08:06:21Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:06:36Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:06:47Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:06:48Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:40045" 2404s time="2024-07-19T08:06:48Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates2088304090/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 2404s time="2024-07-19T08:06:48Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:06:49Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:06:49Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:06:49Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 2404s time="2024-07-19T08:06:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45633" 2404s time="2024-07-19T08:06:49Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:02Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38679" 2404s time="2024-07-19T08:07:02Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:07:02Z" 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:38679: connect: connection refused\"" 2404s time="2024-07-19T08:07:02Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:02Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:02Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:02Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/Success_with_systemd_notifier_returning_true 2404s time="2024-07-19T08:07:02Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43017" 2404s time="2024-07-19T08:07:02Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:11Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:11Z" 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_exist3715162698/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist3715162698/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 2404s time="2024-07-19T08:07:11Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:12Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:12Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:12Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:12Z" 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_exist3715162698/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist3715162698/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 2404s time="2024-07-19T08:07:12Z" level=info msg="Reconnecting to Windows host in 2 seconds" 2404s time="2024-07-19T08:07:12Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 2404s time="2024-07-19T08:07:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35007" 2404s time="2024-07-19T08:07:12Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:17Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:07:17Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:17Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:07:23Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43017" 2404s time="2024-07-19T08:07:23Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:07:23Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:07:23Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:07:23Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:07:26Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:26Z" 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" 2404s time="2024-07-19T08:07:26Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:27Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:27Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:27Z" level=debug msg="All connections have now ended." 2404s === CONT TestServe/No_connection_because_the_port_file_has_port_0 2404s time="2024-07-19T08:07:27Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45669" 2404s time="2024-07-19T08:07:27Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:32Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:07:32Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:07:32Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:07:32Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:07:33Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:33Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:33Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:07:33Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:33Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:07:33Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:07:33Z" level=debug msg="All connections have now ended." 2404s time="2024-07-19T08:07:33Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s === CONT TestServe/No_connection_because_the_port_file_is_empty 2404s time="2024-07-19T08:07:33Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:07:33Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:07:33Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46557" 2404s time="2024-07-19T08:07:33Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:39Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:39Z" 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" 2404s time="2024-07-19T08:07:39Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:40Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:40Z" 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" 2404s time="2024-07-19T08:07:40Z" level=info msg="Reconnecting to Windows host in 2 seconds" 2404s time="2024-07-19T08:07:40Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:40Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:40Z" level=debug msg="All connections have now ended." 2404s === CONT TestReconnection/Success_connecting_after_failing_to_connect 2404s time="2024-07-19T08:07:40Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:48Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07: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" 2404s time="2024-07-19T08:07:48Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:49Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:49Z" 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" 2404s time="2024-07-19T08:07:49Z" level=info msg="Reconnecting to Windows host in 2 seconds" 2404s time="2024-07-19T08:07:49Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:07:49Z" level=info msg="Waiting for active requests to close." 2404s time="2024-07-19T08:07:49Z" level=debug msg="All connections have now ended." 2404s --- PASS: TestServe (0.00s) 2404s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (13.50s) 2404s --- PASS: TestServe/Success (31.46s) 2404s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (18.76s) 2404s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (22.19s) 2404s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (11.87s) 2404s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (23.59s) 2404s --- PASS: TestServe/No_connection_because_there_are_no_certificates (39.86s) 2404s --- PASS: TestServe/No_connection_because_there_is_no_server (41.00s) 2404s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (23.15s) 2404s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (15.67s) 2404s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (30.86s) 2404s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (12.97s) 2404s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (15.84s) 2404s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 2404s time="2024-07-19T08:07:49Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:07:53Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:07:53Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:07:53Z" 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_connect3015438638/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3015438638/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 2404s time="2024-07-19T08:07:53Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:07:53Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:07:54Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35549" 2404s time="2024-07-19T08:07:54Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:07:54Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:08:03Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35549" 2404s time="2024-07-19T08:08:03Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:08:03Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:08:03Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:08:03Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:08:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43879" 2404s time="2024-07-19T08:08:12Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:08:12Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:08:12Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s === NAME TestReconnection/Success_connecting_after_failing_to_connect 2404s daemon_test.go:392: 2404s Error Trace: /tmp/autopkgtest.G4Vb4N/build.A4f/src/internal/daemon/daemon_test.go:392 2404s Error: Condition never satisfied 2404s Test: TestReconnection/Success_connecting_after_failing_to_connect 2404s Messages: Daemon never connected to agent's service 2404s time="2024-07-19T08:08:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:14Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:08:14Z" level=info msg="Stopping active requests." 2404s time="2024-07-19T08:08:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:14Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:15Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:08:15Z" level=debug msg="All connections have now ended." 2404s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 2404s time="2024-07-19T08:08:15Z" level=debug msg="Building new daemon" 2404s time="2024-07-19T08:08:27Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43879" 2404s time="2024-07-19T08:08:27Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:08:27Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:08:27Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:08:27Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:08:33Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41327" 2404s time="2024-07-19T08:08:33Z" level=debug msg="Ready state sent to systemd" 2404s time="2024-07-19T08:08:33Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:08:33Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:08:36Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:08:36Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:08:36Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:08:36Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:08:45Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:41327" 2404s time="2024-07-19T08:08:45Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:08:45Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:08:45Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:08:45Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:08:52Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:08:52Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:08:52Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:08:52Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:08:52Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:52Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:08:52Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:08:52Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:08:52Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:52Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:08:52Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42595" 2404s time="2024-07-19T08:08:53Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:08:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:09:02Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:42595" 2404s time="2024-07-19T08:09:02Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:09:02Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:09:02Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:09:02Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:09:10Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:09:10Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:09:10Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:09:10Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:09:10Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:10Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:09:10Z" level=info msg="Stopping active requests." 2404s time="2024-07-19T08:09:10Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:10Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:10Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:09:10Z" level=info msg="Reconnecting to Windows host in 2 seconds" 2404s time="2024-07-19T08:09:10Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:09:10Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:09:10Z" level=debug msg="All connections have now ended." 2404s time="2024-07-19T08:09:41Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:41Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:09:41Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:09:41Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:09:41Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3959269744/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped3959269744/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 2404s time="2024-07-19T08:09:41Z" level=info msg="Reconnecting to Windows host in 1 seconds" 2404s time="2024-07-19T08:09:41Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:09:41Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:41Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:41Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38741" 2404s time="2024-07-19T08:09:42Z" level=info msg="Daemon: connecting to Windows Agent" 2404s time="2024-07-19T08:09:42Z" level=debug msg="Updated systemd status to \"Connecting\"" 2404s time="2024-07-19T08:09:44Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38741" 2404s time="2024-07-19T08:09:44Z" level=info msg="Daemon: completed connection to Windows Agent" 2404s time="2024-07-19T08:09:44Z" level=debug msg="Updated systemd status to \"Connected\"" 2404s time="2024-07-19T08:09:44Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 2404s time="2024-07-19T08:09:44Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 2404s time="2024-07-19T08:09:49Z" level=debug msg="Server: sent preface messages to all streams" 2404s time="2024-07-19T08:09:49Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:09:49Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:09:49Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:09:49Z" level=info msg="Stopping daemon requested." 2404s time="2024-07-19T08:09:49Z" level=info msg="Stopping active requests." 2404s time="2024-07-19T08:09:49Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:49Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:49Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:09:49Z" level=warning msg="Daemon: disconnected from Windows host" 2404s time="2024-07-19T08:09:49Z" level=info msg="Reconnecting to Windows host in 2 seconds" 2404s time="2024-07-19T08:09:49Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 2404s time="2024-07-19T08:09:49Z" level=debug msg="Updated systemd status to \"Stopped\"" 2404s time="2024-07-19T08:09:49Z" level=debug msg="All connections have now ended." 2404s --- FAIL: TestReconnection (0.00s) 2404s --- FAIL: TestReconnection/Success_connecting_after_failing_to_connect (34.41s) 2404s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (55.59s) 2404s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (119.99s) 2404s FAIL 2404s FAIL github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 326.003s 2404s === RUN TestConnect 2404s === PAUSE TestConnect 2404s === RUN TestSendAndRecv 2404s --- PASS: TestSendAndRecv (0.42s) 2404s === RUN TestServe 2404s === PAUSE TestServe 2404s === RUN TestStop 2404s === PAUSE TestStop 2404s === RUN TestWithProMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithProMock (0.00s) 2404s === RUN TestWithWslPathMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslPathMock (0.00s) 2404s === RUN TestWithWslInfoMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslInfoMock (0.00s) 2404s === RUN TestWithCmdExeMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithCmdExeMock (0.00s) 2404s === CONT TestConnect 2404s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 2404s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 2404s === RUN TestConnect/Success 2404s === PAUSE TestConnect/Success 2404s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 2404s === CONT TestStop 2404s time="2024-07-19T08:04:33Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41477" 2404s time="2024-07-19T08:04:39Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:04:39Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:04:39Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:04:50Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:04:50Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:04:50Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s --- PASS: TestStop (16.55s) 2404s === CONT TestConnect/Success 2404s === CONT TestServe 2404s time="2024-07-19T08:04:50Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33401" 2404s --- PASS: TestConnect (0.00s) 2404s --- PASS: TestConnect/Success (0.39s) 2404s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (23.70s) 2404s time="2024-07-19T08:05:06Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 2404s time="2024-07-19T08:05:06Z" level=info msg="MockWindowsAgent: Connected ready" 2404s time="2024-07-19T08:05:06Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 2404s time="2024-07-19T08:05:29Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 2404s --- PASS: TestServe (38.45s) 2404s time="2024-07-19T08:05:29Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s time="2024-07-19T08:05:29Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 2404s PASS 2404s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 56.706s 2404s === RUN TestInfo 2404s === PAUSE TestInfo 2404s === RUN TestWslDistroName 2404s === PAUSE TestWslDistroName 2404s === RUN TestUserProfileDir 2404s === PAUSE TestUserProfileDir 2404s === RUN TestProStatus 2404s === PAUSE TestProStatus 2404s === RUN TestProAttach 2404s === PAUSE TestProAttach 2404s === RUN TestProDetach 2404s === PAUSE TestProDetach 2404s === RUN TestLandscapeEnable 2404s === PAUSE TestLandscapeEnable 2404s === RUN TestWindowsHostAddress 2404s === PAUSE TestWindowsHostAddress 2404s === RUN TestLandscapeDisable 2404s === PAUSE TestLandscapeDisable 2404s === RUN TestRealBackend 2404s === PAUSE TestRealBackend 2404s === RUN TestWithProMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithProMock (0.00s) 2404s === RUN TestWithLandscapeConfigMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithLandscapeConfigMock (0.00s) 2404s === RUN TestWithWslPathMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslPathMock (0.00s) 2404s === RUN TestWithWslInfoMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithWslInfoMock (0.00s) 2404s === RUN TestWithCmdExeMock 2404s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 2404s --- SKIP: TestWithCmdExeMock (0.00s) 2404s === CONT TestInfo 2404s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 2404s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 2404s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 2404s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 2404s === RUN TestInfo/Success 2404s === PAUSE TestInfo/Success 2404s === RUN TestInfo/Error_when_WslDistroName_fails 2404s === PAUSE TestInfo/Error_when_WslDistroName_fails 2404s === RUN TestInfo/Error_when_pro_status_command_fails 2404s === PAUSE TestInfo/Error_when_pro_status_command_fails 2404s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 2404s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 2404s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 2404s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 2404s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 2404s === CONT TestUserProfileDir 2404s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 2404s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 2404s === RUN TestUserProfileDir/Error_on_wslpath_error 2404s === PAUSE TestUserProfileDir/Error_on_wslpath_error 2404s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 2404s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 2404s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 2404s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 2404s === RUN TestUserProfileDir/Error_on_cmd.exe_error 2404s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 2404s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 2404s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 2404s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 2404s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 2404s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 2404s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 2404s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 2404s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 2404s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 2404s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 2404s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 2404s === CONT TestRealBackend 2404s --- PASS: TestRealBackend (0.05s) 2404s === CONT TestLandscapeDisable 2404s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 2404s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 2404s === RUN TestLandscapeDisable/Success 2404s === PAUSE TestLandscapeDisable/Success 2404s === CONT TestWindowsHostAddress 2404s === RUN TestWindowsHostAddress/Success_without_NAT 2404s === PAUSE TestWindowsHostAddress/Success_without_NAT 2404s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 2404s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 2404s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 2404s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 2404s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 2404s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 2404s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 2404s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 2404s === CONT TestLandscapeEnable 2404s === RUN TestLandscapeEnable/Success 2404s === PAUSE TestLandscapeEnable/Success 2404s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 2404s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 2404s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 2404s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 2404s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 2404s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 2404s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 2404s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 2404s === RUN TestLandscapeEnable/Success_overriding_computer_title 2404s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 2404s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 2404s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 2404s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 2404s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 2404s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 2404s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 2404s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 2404s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 2404s === CONT TestProDetach 2404s === RUN TestProDetach/success_on_unattached_distro 2404s === PAUSE TestProDetach/success_on_unattached_distro 2404s === RUN TestProDetach/success_on_attached_distro 2404s === PAUSE TestProDetach/success_on_attached_distro 2404s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 2404s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 2404s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 2404s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 2404s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 2404s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 2404s === CONT TestProAttach 2404s === RUN TestProAttach/success 2404s === PAUSE TestProAttach/success 2404s === RUN TestProAttach/error_on_'pro_attach'_error 2404s === PAUSE TestProAttach/error_on_'pro_attach'_error 2404s === CONT TestProStatus 2404s === RUN TestProStatus/success_on_unattached_distro 2404s === PAUSE TestProStatus/success_on_unattached_distro 2404s === RUN TestProStatus/success_on_attached_distro 2404s === PAUSE TestProStatus/success_on_attached_distro 2404s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 2404s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 2404s === RUN TestProStatus/error_on_'pro_attach'_error 2404s === PAUSE TestProStatus/error_on_'pro_attach'_error 2404s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 2404s system_test.go:205: Removing default proc/mounts 2404s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 2404s system_test.go:205: Removing default proc/mounts 2404s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 2404s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 2404s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 2404s === CONT TestUserProfileDir/Error_on_cmd.exe_error 2404s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 2404s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 2404s === CONT TestUserProfileDir/Error_on_wslpath_error 2404s === CONT TestInfo/Error_when_pro_status_command_fails 2404s --- PASS: TestUserProfileDir (0.00s) 2404s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 2404s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 2404s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (17.46s) 2404s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (17.74s) 2404s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (11.92s) 2404s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (11.15s) 2404s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.02s) 2404s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (6.99s) 2404s --- PASS: TestUserProfileDir/Error_on_wslpath_error (28.89s) 2404s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (29.64s) 2404s === CONT TestWslDistroName 2404s === RUN TestWslDistroName/Success_using_wslpath 2404s === PAUSE TestWslDistroName/Success_using_wslpath 2404s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 2404s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 2404s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 2404s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 2404s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 2404s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 2404s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 2404s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 2404s === CONT TestInfo/Success 2404s === CONT TestInfo/Error_when_WslDistroName_fails 2404s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 2404s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 2404s --- PASS: TestInfo (0.00s) 2404s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (7.27s) 2404s --- PASS: TestInfo/Error_when_pro_status_command_fails (9.83s) 2404s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (9.56s) 2404s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (8.01s) 2404s --- PASS: TestInfo/Success (8.50s) 2404s --- PASS: TestInfo/Error_when_WslDistroName_fails (8.73s) 2404s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (8.02s) 2404s === CONT TestLandscapeDisable/Success 2404s === CONT TestWindowsHostAddress/Success_without_NAT 2404s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 2404s --- PASS: TestLandscapeDisable (0.06s) 2404s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (7.12s) 2404s --- PASS: TestLandscapeDisable/Success (7.38s) 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 2404s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 2404s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 2404s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 2404s === CONT TestLandscapeEnable/Success 2404s --- PASS: TestWindowsHostAddress (0.00s) 2404s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (7.01s) 2404s --- PASS: TestWindowsHostAddress/Success_without_NAT (8.16s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (7.74s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (7.92s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (5.32s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (6.26s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (7.67s) 2404s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (8.20s) 2404s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (6.00s) 2404s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (5.61s) 2404s === CONT TestLandscapeEnable/Success_overriding_computer_title 2404s time="2024-07-19T08:07:53Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 2404s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 2404s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 2404s === NAME TestLandscapeEnable/Success 2404s system_test.go:456: testdata/TestLandscapeEnable/golden/success 2404s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 2404s time="2024-07-19T08:08:03Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 2404s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 2404s time="2024-07-19T08:08:14Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 2404s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 2404s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 2404s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 2404s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 2404s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 2404s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 2404s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 2404s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 2404s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 2404s === CONT TestProDetach/success_on_unattached_distro 2404s === NAME TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 2404s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 2404s --- PASS: TestLandscapeEnable (0.00s) 2404s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (9.15s) 2404s --- PASS: TestLandscapeEnable/Success (9.40s) 2404s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (11.30s) 2404s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (11.31s) 2404s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (13.30s) 2404s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (7.04s) 2404s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.01s) 2404s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.01s) 2404s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 2404s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (20.47s) 2404s === CONT TestProAttach/success 2404s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 2404s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 2404s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 2404s === CONT TestProDetach/success_on_attached_distro 2404s === CONT TestProStatus/success_on_unattached_distro 2404s --- PASS: TestProDetach (0.01s) 2404s --- PASS: TestProDetach/success_on_unattached_distro (10.94s) 2404s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (6.34s) 2404s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (7.25s) 2404s --- PASS: TestProDetach/success_on_attached_distro (9.27s) 2404s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (10.56s) 2404s === CONT TestProAttach/error_on_'pro_attach'_error 2404s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 2404s --- PASS: TestProAttach (0.00s) 2404s --- PASS: TestProAttach/success (11.31s) 2404s --- PASS: TestProAttach/error_on_'pro_attach'_error (7.88s) 2404s === CONT TestProStatus/error_on_'pro_attach'_error 2404s === CONT TestProStatus/success_on_attached_distro 2404s === CONT TestWslDistroName/Success_using_wslpath 2404s --- PASS: TestProStatus (0.00s) 2404s --- PASS: TestProStatus/success_on_unattached_distro (8.45s) 2404s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (4.43s) 2404s --- PASS: TestProStatus/error_on_'pro_attach'_error (4.47s) 2404s --- PASS: TestProStatus/success_on_attached_distro (4.01s) 2404s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 2404s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 2404s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 2404s --- PASS: TestWslDistroName (0.00s) 2404s --- PASS: TestWslDistroName/Success_using_wslpath (4.33s) 2404s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 2404s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (4.48s) 2404s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (4.08s) 2404s PASS 2404s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 226.878s 2404s FAIL 2405s autopkgtest [08:09:50]: test command1: -----------------------] 2406s autopkgtest [08:09:51]: test command1: - - - - - - - - - - results - - - - - - - - - - 2406s command1 FAIL non-zero exit status 1 2407s autopkgtest [08:09:52]: @@@@@@@@@@@@@@@@@@@@ summary 2407s command1 FAIL non-zero exit status 1 2463s nova [W] Skipping flock in bos03-arm64 2463s Creating nova instance adt-noble-arm64-wsl-pro-service-20240719-072944-juju-7f2275-prod-proposed-migration-environment-2-5925edd6-d721-4bb0-8d6d-7270678c17e2 from image adt/ubuntu-noble-arm64-server-20240718.img (UUID 370049df-211d-4f97-8804-2e971c614a3a)...