0s autopkgtest [19:01:25]: starting date and time: 2024-03-25 19:01:25+0000 0s autopkgtest [19:01:25]: git checkout: 4a1cd702 l/adt_testbed: don't blame the testbed for unsolvable build deps 0s autopkgtest [19:01:25]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.e_tqjkfn/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --setup-commands /home/ubuntu/autopkgtest/setup-commands/setup-testbed --apt-pocket=proposed=src:ubuntu-advantage-tools,src:apt --apt-upgrade wsl-pro-service --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=ubuntu-advantage-tools/31.2.2 apt/2.7.14' -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos02-ppc64el-12.secgroup --name adt-noble-ppc64el-wsl-pro-service-20240325-190124-juju-7f2275-prod-proposed-migration-environment-3 --image adt/ubuntu-noble-ppc64el-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-3 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://ftpmaster.internal/ubuntu/ 121s autopkgtest [19:03:26]: testbed dpkg architecture: ppc64el 121s autopkgtest [19:03:26]: testbed apt version: 2.7.12 121s autopkgtest [19:03:26]: @@@@@@@@@@@@@@@@@@@@ test bed setup 122s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 123s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [4045 kB] 123s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [497 kB] 123s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [7608 B] 123s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [56.0 kB] 123s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el Packages [700 kB] 123s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el c-n-f Metadata [3116 B] 123s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el Packages [1372 B] 123s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted ppc64el c-n-f Metadata [116 B] 123s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el Packages [4269 kB] 124s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe ppc64el c-n-f Metadata [8652 B] 124s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el Packages [61.7 kB] 124s Get:13 http://ftpmaster.internal/ubuntu noble-proposed/multiverse ppc64el c-n-f Metadata [116 B] 127s Fetched 9767 kB in 3s (3639 kB/s) 127s Reading package lists... 130s Reading package lists... 130s Building dependency tree... 130s Reading state information... 130s Calculating upgrade... 130s The following packages will be REMOVED: 130s libapt-pkg6.0 libdb5.3 libgnutls30 libhogweed6 libnettle8 130s The following NEW packages will be installed: 130s libapt-pkg6.0t64 libdb5.3t64 libgnutls30t64 libhogweed6t64 libnettle8t64 130s The following packages will be upgraded: 130s apt apt-utils ubuntu-pro-client ubuntu-pro-client-l10n 131s 4 upgraded, 5 newly installed, 5 to remove and 0 not upgraded. 131s Need to get 5387 kB of archives. 131s After this operation, 735 kB of additional disk space will be used. 131s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el libnettle8t64 ppc64el 3.9.1-2.2 [226 kB] 131s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el libhogweed6t64 ppc64el 3.9.1-2.2 [208 kB] 131s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el libgnutls30t64 ppc64el 3.8.3-1.1ubuntu2 [1154 kB] 131s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el ubuntu-pro-client-l10n ppc64el 31.2.2 [19.4 kB] 131s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el ubuntu-pro-client ppc64el 31.2.2 [215 kB] 131s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el libdb5.3t64 ppc64el 5.3.28+dfsg2-6 [875 kB] 131s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el libapt-pkg6.0t64 ppc64el 2.7.14 [1063 kB] 131s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el apt ppc64el 2.7.14 [1401 kB] 132s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/main ppc64el apt-utils ppc64el 2.7.14 [226 kB] 132s Fetched 5387 kB in 1s (5090 kB/s) 132s dpkg: libnettle8:ppc64el: dependency problems, but removing anyway as you requested: 132s librtmp1:ppc64el depends on libnettle8. 132s libhogweed6:ppc64el depends on libnettle8. 132s libgnutls30:ppc64el depends on libnettle8 (>= 3.9~). 132s libcurl3-gnutls:ppc64el depends on libnettle8. 132s libarchive13:ppc64el depends on libnettle8. 132s 132s (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 ... 70156 files and directories currently installed.) 132s Removing libnettle8:ppc64el (3.9.1-2) ... 132s Selecting previously unselected package libnettle8t64:ppc64el. 132s (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 ... 70149 files and directories currently installed.) 132s Preparing to unpack .../libnettle8t64_3.9.1-2.2_ppc64el.deb ... 132s Unpacking libnettle8t64:ppc64el (3.9.1-2.2) ... 132s Setting up libnettle8t64:ppc64el (3.9.1-2.2) ... 132s dpkg: libhogweed6:ppc64el: dependency problems, but removing anyway as you requested: 132s librtmp1:ppc64el depends on libhogweed6. 132s libjcat1:ppc64el depends on libhogweed6. 132s libgnutls30:ppc64el depends on libhogweed6 (>= 3.6). 132s 132s (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 ... 70157 files and directories currently installed.) 132s Removing libhogweed6:ppc64el (3.9.1-2) ... 132s Selecting previously unselected package libhogweed6t64:ppc64el. 132s (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 ... 70152 files and directories currently installed.) 132s Preparing to unpack .../libhogweed6t64_3.9.1-2.2_ppc64el.deb ... 132s Unpacking libhogweed6t64:ppc64el (3.9.1-2.2) ... 132s Setting up libhogweed6t64:ppc64el (3.9.1-2.2) ... 132s dpkg: libgnutls30:ppc64el: dependency problems, but removing anyway as you requested: 132s librtmp1:ppc64el depends on libgnutls30 (>= 3.7.2). 132s libldap2:ppc64el depends on libgnutls30 (>= 3.8.2). 132s libjcat1:ppc64el depends on libgnutls30 (>= 3.7.3). 132s libcurl3-gnutls:ppc64el depends on libgnutls30 (>= 3.8.2). 132s fwupd depends on libgnutls30 (>= 3.7.3). 132s dirmngr depends on libgnutls30 (>= 3.8.1). 132s apt depends on libgnutls30 (>= 3.8.1). 132s 132s (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 ... 70158 files and directories currently installed.) 132s Removing libgnutls30:ppc64el (3.8.3-1ubuntu1) ... 132s Selecting previously unselected package libgnutls30t64:ppc64el. 132s (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 ... 70149 files and directories currently installed.) 132s Preparing to unpack .../libgnutls30t64_3.8.3-1.1ubuntu2_ppc64el.deb ... 132s Unpacking libgnutls30t64:ppc64el (3.8.3-1.1ubuntu2) ... 132s Setting up libgnutls30t64:ppc64el (3.8.3-1.1ubuntu2) ... 132s (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 ... 70177 files and directories currently installed.) 132s Preparing to unpack .../ubuntu-pro-client-l10n_31.2.2_ppc64el.deb ... 132s Unpacking ubuntu-pro-client-l10n (31.2.2) over (31.1) ... 132s Preparing to unpack .../ubuntu-pro-client_31.2.2_ppc64el.deb ... 133s Unpacking ubuntu-pro-client (31.2.2) over (31.1) ... 133s dpkg: libdb5.3:ppc64el: dependency problems, but removing anyway as you requested: 133s libsasl2-modules-db:ppc64el depends on libdb5.3. 133s libpython3.12-stdlib:ppc64el depends on libdb5.3. 133s libpython3.11-stdlib:ppc64el depends on libdb5.3. 133s libperl5.38:ppc64el depends on libdb5.3. 133s libpam-modules:ppc64el depends on libdb5.3. 133s iproute2 depends on libdb5.3. 133s apt-utils depends on libdb5.3. 133s 133s (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 ... 70177 files and directories currently installed.) 133s Removing libdb5.3:ppc64el (5.3.28+dfsg2-4) ... 133s Selecting previously unselected package libdb5.3t64:ppc64el. 133s (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 ... 70171 files and directories currently installed.) 133s Preparing to unpack .../libdb5.3t64_5.3.28+dfsg2-6_ppc64el.deb ... 133s Unpacking libdb5.3t64:ppc64el (5.3.28+dfsg2-6) ... 133s Setting up libdb5.3t64:ppc64el (5.3.28+dfsg2-6) ... 133s dpkg: libapt-pkg6.0:ppc64el: dependency problems, but removing anyway as you requested: 133s python3-apt depends on libapt-pkg6.0 (>= 2.7.11). 133s apt-utils depends on libapt-pkg6.0 (>= 2.7.12). 133s apt depends on libapt-pkg6.0 (>= 2.7.12). 133s 133s (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 ... 70177 files and directories currently installed.) 133s Removing libapt-pkg6.0:ppc64el (2.7.12) ... 133s Selecting previously unselected package libapt-pkg6.0t64:ppc64el. 133s (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 ... 70128 files and directories currently installed.) 133s Preparing to unpack .../libapt-pkg6.0t64_2.7.14_ppc64el.deb ... 133s Unpacking libapt-pkg6.0t64:ppc64el (2.7.14) ... 133s Setting up libapt-pkg6.0t64:ppc64el (2.7.14) ... 133s (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 ... 70178 files and directories currently installed.) 133s Preparing to unpack .../apt_2.7.14_ppc64el.deb ... 133s Unpacking apt (2.7.14) over (2.7.12) ... 133s Setting up apt (2.7.14) ... 134s (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 ... 70178 files and directories currently installed.) 134s Preparing to unpack .../apt-utils_2.7.14_ppc64el.deb ... 134s Unpacking apt-utils (2.7.14) over (2.7.12) ... 134s Setting up apt-utils (2.7.14) ... 134s Setting up ubuntu-pro-client (31.2.2) ... 135s Setting up ubuntu-pro-client-l10n (31.2.2) ... 135s Processing triggers for man-db (2.12.0-3) ... 137s Processing triggers for libc-bin (2.39-0ubuntu6) ... 139s Reading package lists... 139s Building dependency tree... 139s Reading state information... 139s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 143s sh: Attempting to set up Debian/Ubuntu apt sources automatically 143s sh: Distribution appears to be Ubuntu 143s Reading package lists... 144s Building dependency tree... 144s Reading state information... 144s eatmydata is already the newest version (131-1). 144s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 144s Reading package lists... 144s Building dependency tree... 144s Reading state information... 144s dbus is already the newest version (1.14.10-4ubuntu1). 144s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 144s Reading package lists... 144s Building dependency tree... 144s Reading state information... 145s rng-tools-debian is already the newest version (2.4). 145s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 145s Reading package lists... 145s Building dependency tree... 145s Reading state information... 145s The following packages will be REMOVED: 145s cloud-init* python3-configobj* python3-debconf* 145s 0 upgraded, 0 newly installed, 3 to remove and 0 not upgraded. 145s After this operation, 3256 kB disk space will be freed. 145s (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 ... 70178 files and directories currently installed.) 145s Removing cloud-init (24.1.2-0ubuntu1) ... 146s Removing python3-configobj (5.0.8-3) ... 146s Removing python3-debconf (1.5.86) ... 146s Processing triggers for man-db (2.12.0-3) ... 146s (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 ... 69789 files and directories currently installed.) 146s Purging configuration files for cloud-init (24.1.2-0ubuntu1) ... 147s dpkg: warning: while removing cloud-init, directory '/etc/cloud/cloud.cfg.d' not empty so not removed 147s Processing triggers for rsyslog (8.2312.0-3ubuntu3) ... 147s invoke-rc.d: policy-rc.d denied execution of try-restart. 147s Reading package lists... 147s Building dependency tree... 147s Reading state information... 147s linux-generic is already the newest version (6.8.0-11.11+1). 147s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 148s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 148s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 148s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 150s Reading package lists... 151s Reading package lists... 151s Building dependency tree... 151s Reading state information... 151s Calculating upgrade... 151s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 151s Reading package lists... 151s Building dependency tree... 151s Reading state information... 151s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 152s autopkgtest [19:03:57]: rebooting testbed after setup commands that affected boot 313s autopkgtest [19:06:38]: testbed running kernel: Linux 6.8.0-11-generic #11-Ubuntu SMP Wed Feb 14 00:33:03 UTC 2024 316s autopkgtest [19:06:41]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 318s Get:1 http://ftpmaster.internal/ubuntu noble/universe wsl-pro-service 0.1.2 (dsc) [1420 B] 318s Get:2 http://ftpmaster.internal/ubuntu noble/universe wsl-pro-service 0.1.2 (tar) [1746 kB] 318s gpgv: Signature made Thu Feb 29 15:15:37 2024 UTC 318s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 318s gpgv: Can't check signature: No public key 318s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.2.dsc: no acceptable signature found 319s autopkgtest [19:06:44]: testing package wsl-pro-service version 0.1.2 319s autopkgtest [19:06:44]: build not needed 323s autopkgtest [19:06:48]: test command1: preparing testbed 328s Reading package lists... 328s Building dependency tree... 328s Reading state information... 328s Starting pkgProblemResolver with broken count: 0 328s Starting 2 pkgProblemResolver with broken count: 0 328s Done 328s The following additional packages will be installed: 328s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 328s cpp-13-powerpc64le-linux-gnu cpp-powerpc64le-linux-gnu debhelper debugedit 328s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 328s g++-13-powerpc64le-linux-gnu g++-powerpc64le-linux-gnu gcc gcc-13 328s gcc-13-powerpc64le-linux-gnu gcc-powerpc64le-linux-gnu gettext 328s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 328s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 328s libcrypt-dev libdebhelper-perl libdw1 libfile-stripnondeterminism-perl 328s libgcc-13-dev libgomp1 libisl23 libitm1 liblsan0 libmpc3 libquadmath0 328s libstdc++-13-dev libsub-override-perl libtool libtsan2 libubsan1 328s linux-libc-dev m4 po-debconf rpcsvc-proto 328s Suggested packages: 328s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 328s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 328s gcc-doc gdb-powerpc64le-linux-gnu gettext-doc libasprintf-dev 328s libgettextpo-dev bzr | brz git mercurial subversion glibc-doc 328s libstdc++-13-doc libtool-doc gfortran | fortran95-compiler gcj-jdk m4-doc 328s libmail-box-perl 328s Recommended packages: 328s pkg-config manpages manpages-dev libc-devtools libarchive-cpio-perl 328s libltdl-dev libmail-sendmail-perl 328s The following NEW packages will be installed: 328s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 328s cpp cpp-13 cpp-13-powerpc64le-linux-gnu cpp-powerpc64le-linux-gnu debhelper 328s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 328s g++-13 g++-13-powerpc64le-linux-gnu g++-powerpc64le-linux-gnu gcc gcc-13 328s gcc-13-powerpc64le-linux-gnu gcc-powerpc64le-linux-gnu gettext 328s golang-1.22-go golang-1.22-src golang-go golang-src intltool-debian 328s libarchive-zip-perl libasan8 libatomic1 libc-dev-bin libc6-dev libcc1-0 328s libcrypt-dev libdebhelper-perl libdw1 libfile-stripnondeterminism-perl 328s libgcc-13-dev libgomp1 libisl23 libitm1 liblsan0 libmpc3 libquadmath0 328s libstdc++-13-dev libsub-override-perl libtool libtsan2 libubsan1 328s linux-libc-dev m4 po-debconf rpcsvc-proto 328s 0 upgraded, 57 newly installed, 0 to remove and 0 not upgraded. 328s Need to get 110 MB/110 MB of archives. 328s After this operation, 483 MB of additional disk space will be used. 328s Get:1 /tmp/autopkgtest.xOPpTv/1-autopkgtest-satdep.deb autopkgtest-satdep ppc64el 0 [764 B] 329s Get:2 http://ftpmaster.internal/ubuntu noble/main ppc64el m4 ppc64el 1.4.19-4 [275 kB] 329s Get:3 http://ftpmaster.internal/ubuntu noble/main ppc64el autoconf all 2.71-3 [339 kB] 329s Get:4 http://ftpmaster.internal/ubuntu noble/main ppc64el autotools-dev all 20220109.1 [44.9 kB] 329s Get:5 http://ftpmaster.internal/ubuntu noble/main ppc64el automake all 1:1.16.5-1.3ubuntu1 [558 kB] 329s Get:6 http://ftpmaster.internal/ubuntu noble/main ppc64el autopoint all 0.21-14ubuntu1 [422 kB] 329s Get:7 http://ftpmaster.internal/ubuntu noble/main ppc64el libc-dev-bin ppc64el 2.39-0ubuntu6 [21.3 kB] 329s Get:8 http://ftpmaster.internal/ubuntu noble/main ppc64el linux-libc-dev ppc64el 6.8.0-11.11 [1585 kB] 329s Get:9 http://ftpmaster.internal/ubuntu noble/main ppc64el libcrypt-dev ppc64el 1:4.4.36-4 [167 kB] 329s Get:10 http://ftpmaster.internal/ubuntu noble/main ppc64el rpcsvc-proto ppc64el 1.4.2-0ubuntu6 [82.3 kB] 329s Get:11 http://ftpmaster.internal/ubuntu noble/main ppc64el libc6-dev ppc64el 2.39-0ubuntu6 [2102 kB] 329s Get:12 http://ftpmaster.internal/ubuntu noble/main ppc64el libisl23 ppc64el 0.26-3 [864 kB] 330s Get:13 http://ftpmaster.internal/ubuntu noble/main ppc64el libmpc3 ppc64el 1.3.1-1 [61.2 kB] 330s Get:14 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [10.7 MB] 330s Get:15 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-13 ppc64el 13.2.0-17ubuntu2 [1038 B] 330s Get:16 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [5330 B] 330s Get:17 http://ftpmaster.internal/ubuntu noble/main ppc64el cpp ppc64el 4:13.2.0-7ubuntu1 [22.5 kB] 330s Get:18 http://ftpmaster.internal/ubuntu noble/main ppc64el libcc1-0 ppc64el 14-20240303-1ubuntu1 [48.1 kB] 330s Get:19 http://ftpmaster.internal/ubuntu noble/main ppc64el libgomp1 ppc64el 14-20240303-1ubuntu1 [161 kB] 330s Get:20 http://ftpmaster.internal/ubuntu noble/main ppc64el libitm1 ppc64el 14-20240303-1ubuntu1 [32.4 kB] 330s Get:21 http://ftpmaster.internal/ubuntu noble/main ppc64el libatomic1 ppc64el 14-20240303-1ubuntu1 [10.7 kB] 330s Get:22 http://ftpmaster.internal/ubuntu noble/main ppc64el libasan8 ppc64el 14-20240303-1ubuntu1 [2973 kB] 330s Get:23 http://ftpmaster.internal/ubuntu noble/main ppc64el liblsan0 ppc64el 14-20240303-1ubuntu1 [1325 kB] 330s Get:24 http://ftpmaster.internal/ubuntu noble/main ppc64el libtsan2 ppc64el 14-20240303-1ubuntu1 [2734 kB] 331s Get:25 http://ftpmaster.internal/ubuntu noble/main ppc64el libubsan1 ppc64el 14-20240303-1ubuntu1 [1194 kB] 331s Get:26 http://ftpmaster.internal/ubuntu noble/main ppc64el libquadmath0 ppc64el 14-20240303-1ubuntu1 [158 kB] 331s Get:27 http://ftpmaster.internal/ubuntu noble/main ppc64el libgcc-13-dev ppc64el 13.2.0-17ubuntu2 [1581 kB] 331s Get:28 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [20.6 MB] 331s Get:29 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-13 ppc64el 13.2.0-17ubuntu2 [477 kB] 331s Get:30 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [1224 B] 331s Get:31 http://ftpmaster.internal/ubuntu noble/main ppc64el gcc ppc64el 4:13.2.0-7ubuntu1 [5022 B] 331s Get:32 http://ftpmaster.internal/ubuntu noble/main ppc64el libstdc++-13-dev ppc64el 13.2.0-17ubuntu2 [2445 kB] 331s Get:33 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13-powerpc64le-linux-gnu ppc64el 13.2.0-17ubuntu2 [12.2 MB] 332s Get:34 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-13 ppc64el 13.2.0-17ubuntu2 [14.5 kB] 332s Get:35 http://ftpmaster.internal/ubuntu noble/main ppc64el g++-powerpc64le-linux-gnu ppc64el 4:13.2.0-7ubuntu1 [968 B] 332s Get:36 http://ftpmaster.internal/ubuntu noble/main ppc64el g++ ppc64el 4:13.2.0-7ubuntu1 [1086 B] 332s Get:37 http://ftpmaster.internal/ubuntu noble/main ppc64el build-essential ppc64el 12.10ubuntu1 [4936 B] 332s Get:38 http://ftpmaster.internal/ubuntu noble/main ppc64el libdebhelper-perl all 13.14.1ubuntu1 [89.5 kB] 332s Get:39 http://ftpmaster.internal/ubuntu noble/main ppc64el libtool all 2.4.7-7 [166 kB] 332s Get:40 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-autoreconf all 20 [16.1 kB] 332s Get:41 http://ftpmaster.internal/ubuntu noble/main ppc64el libarchive-zip-perl all 1.68-1 [90.2 kB] 332s Get:42 http://ftpmaster.internal/ubuntu noble/main ppc64el libsub-override-perl all 0.10-1 [10.0 kB] 332s Get:43 http://ftpmaster.internal/ubuntu noble/main ppc64el libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 332s Get:44 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-strip-nondeterminism all 1.13.1-1 [5362 B] 332s Get:45 http://ftpmaster.internal/ubuntu noble/main ppc64el libdw1 ppc64el 0.190-1 [294 kB] 332s Get:46 http://ftpmaster.internal/ubuntu noble/main ppc64el debugedit ppc64el 1:5.0-5 [51.1 kB] 332s Get:47 http://ftpmaster.internal/ubuntu noble/main ppc64el dwz ppc64el 0.15-1 [139 kB] 332s Get:48 http://ftpmaster.internal/ubuntu noble/main ppc64el gettext ppc64el 0.21-14ubuntu1 [979 kB] 332s Get:49 http://ftpmaster.internal/ubuntu noble/main ppc64el intltool-debian all 0.35.0+20060710.6 [23.2 kB] 332s Get:50 http://ftpmaster.internal/ubuntu noble/main ppc64el po-debconf all 1.0.21+nmu1 [233 kB] 332s Get:51 http://ftpmaster.internal/ubuntu noble/main ppc64el debhelper all 13.14.1ubuntu1 [869 kB] 332s Get:52 http://ftpmaster.internal/ubuntu noble/universe ppc64el dh-apport all 2.28.0-0ubuntu1 [16.9 kB] 332s Get:53 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-1.22-src all 1.22.1-1 [19.7 MB] 332s Get:54 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-1.22-go ppc64el 1.22.1-1 [23.5 MB] 333s Get:55 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-src all 2:1.22~2 [4992 B] 333s Get:56 http://ftpmaster.internal/ubuntu noble/main ppc64el golang-go ppc64el 2:1.22~2 [43.9 kB] 333s Get:57 http://ftpmaster.internal/ubuntu noble/main ppc64el dh-golang all 1.62 [25.2 kB] 334s Fetched 110 MB in 5s (23.1 MB/s) 334s Selecting previously unselected package m4. 334s (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 ... 69734 files and directories currently installed.) 334s Preparing to unpack .../00-m4_1.4.19-4_ppc64el.deb ... 334s Unpacking m4 (1.4.19-4) ... 334s Selecting previously unselected package autoconf. 334s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 334s Unpacking autoconf (2.71-3) ... 334s Selecting previously unselected package autotools-dev. 334s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 334s Unpacking autotools-dev (20220109.1) ... 334s Selecting previously unselected package automake. 334s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 334s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 334s Selecting previously unselected package autopoint. 334s Preparing to unpack .../04-autopoint_0.21-14ubuntu1_all.deb ... 334s Unpacking autopoint (0.21-14ubuntu1) ... 334s Selecting previously unselected package libc-dev-bin. 334s Preparing to unpack .../05-libc-dev-bin_2.39-0ubuntu6_ppc64el.deb ... 334s Unpacking libc-dev-bin (2.39-0ubuntu6) ... 334s Selecting previously unselected package linux-libc-dev:ppc64el. 334s Preparing to unpack .../06-linux-libc-dev_6.8.0-11.11_ppc64el.deb ... 334s Unpacking linux-libc-dev:ppc64el (6.8.0-11.11) ... 334s Selecting previously unselected package libcrypt-dev:ppc64el. 334s Preparing to unpack .../07-libcrypt-dev_1%3a4.4.36-4_ppc64el.deb ... 334s Unpacking libcrypt-dev:ppc64el (1:4.4.36-4) ... 334s Selecting previously unselected package rpcsvc-proto. 334s Preparing to unpack .../08-rpcsvc-proto_1.4.2-0ubuntu6_ppc64el.deb ... 334s Unpacking rpcsvc-proto (1.4.2-0ubuntu6) ... 334s Selecting previously unselected package libc6-dev:ppc64el. 334s Preparing to unpack .../09-libc6-dev_2.39-0ubuntu6_ppc64el.deb ... 334s Unpacking libc6-dev:ppc64el (2.39-0ubuntu6) ... 334s Selecting previously unselected package libisl23:ppc64el. 334s Preparing to unpack .../10-libisl23_0.26-3_ppc64el.deb ... 334s Unpacking libisl23:ppc64el (0.26-3) ... 334s Selecting previously unselected package libmpc3:ppc64el. 334s Preparing to unpack .../11-libmpc3_1.3.1-1_ppc64el.deb ... 334s Unpacking libmpc3:ppc64el (1.3.1-1) ... 334s Selecting previously unselected package cpp-13-powerpc64le-linux-gnu. 334s Preparing to unpack .../12-cpp-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 334s Unpacking cpp-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 335s Selecting previously unselected package cpp-13. 335s Preparing to unpack .../13-cpp-13_13.2.0-17ubuntu2_ppc64el.deb ... 335s Unpacking cpp-13 (13.2.0-17ubuntu2) ... 335s Selecting previously unselected package cpp-powerpc64le-linux-gnu. 335s Preparing to unpack .../14-cpp-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 335s Unpacking cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 335s Selecting previously unselected package cpp. 335s Preparing to unpack .../15-cpp_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 335s Unpacking cpp (4:13.2.0-7ubuntu1) ... 335s Selecting previously unselected package libcc1-0:ppc64el. 335s Preparing to unpack .../16-libcc1-0_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libcc1-0:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libgomp1:ppc64el. 335s Preparing to unpack .../17-libgomp1_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libgomp1:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libitm1:ppc64el. 335s Preparing to unpack .../18-libitm1_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libitm1:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libatomic1:ppc64el. 335s Preparing to unpack .../19-libatomic1_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libatomic1:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libasan8:ppc64el. 335s Preparing to unpack .../20-libasan8_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libasan8:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package liblsan0:ppc64el. 335s Preparing to unpack .../21-liblsan0_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking liblsan0:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libtsan2:ppc64el. 335s Preparing to unpack .../22-libtsan2_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libtsan2:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libubsan1:ppc64el. 335s Preparing to unpack .../23-libubsan1_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libubsan1:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libquadmath0:ppc64el. 335s Preparing to unpack .../24-libquadmath0_14-20240303-1ubuntu1_ppc64el.deb ... 335s Unpacking libquadmath0:ppc64el (14-20240303-1ubuntu1) ... 335s Selecting previously unselected package libgcc-13-dev:ppc64el. 335s Preparing to unpack .../25-libgcc-13-dev_13.2.0-17ubuntu2_ppc64el.deb ... 335s Unpacking libgcc-13-dev:ppc64el (13.2.0-17ubuntu2) ... 335s Selecting previously unselected package gcc-13-powerpc64le-linux-gnu. 335s Preparing to unpack .../26-gcc-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 335s Unpacking gcc-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 336s Selecting previously unselected package gcc-13. 336s Preparing to unpack .../27-gcc-13_13.2.0-17ubuntu2_ppc64el.deb ... 336s Unpacking gcc-13 (13.2.0-17ubuntu2) ... 336s Selecting previously unselected package gcc-powerpc64le-linux-gnu. 336s Preparing to unpack .../28-gcc-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 336s Unpacking gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 336s Selecting previously unselected package gcc. 336s Preparing to unpack .../29-gcc_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 336s Unpacking gcc (4:13.2.0-7ubuntu1) ... 336s Selecting previously unselected package libstdc++-13-dev:ppc64el. 336s Preparing to unpack .../30-libstdc++-13-dev_13.2.0-17ubuntu2_ppc64el.deb ... 336s Unpacking libstdc++-13-dev:ppc64el (13.2.0-17ubuntu2) ... 336s Selecting previously unselected package g++-13-powerpc64le-linux-gnu. 336s Preparing to unpack .../31-g++-13-powerpc64le-linux-gnu_13.2.0-17ubuntu2_ppc64el.deb ... 336s Unpacking g++-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 336s Selecting previously unselected package g++-13. 336s Preparing to unpack .../32-g++-13_13.2.0-17ubuntu2_ppc64el.deb ... 336s Unpacking g++-13 (13.2.0-17ubuntu2) ... 336s Selecting previously unselected package g++-powerpc64le-linux-gnu. 336s Preparing to unpack .../33-g++-powerpc64le-linux-gnu_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 336s Unpacking g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 336s Selecting previously unselected package g++. 336s Preparing to unpack .../34-g++_4%3a13.2.0-7ubuntu1_ppc64el.deb ... 336s Unpacking g++ (4:13.2.0-7ubuntu1) ... 336s Selecting previously unselected package build-essential. 336s Preparing to unpack .../35-build-essential_12.10ubuntu1_ppc64el.deb ... 336s Unpacking build-essential (12.10ubuntu1) ... 336s Selecting previously unselected package libdebhelper-perl. 336s Preparing to unpack .../36-libdebhelper-perl_13.14.1ubuntu1_all.deb ... 336s Unpacking libdebhelper-perl (13.14.1ubuntu1) ... 336s Selecting previously unselected package libtool. 336s Preparing to unpack .../37-libtool_2.4.7-7_all.deb ... 336s Unpacking libtool (2.4.7-7) ... 336s Selecting previously unselected package dh-autoreconf. 336s Preparing to unpack .../38-dh-autoreconf_20_all.deb ... 336s Unpacking dh-autoreconf (20) ... 336s Selecting previously unselected package libarchive-zip-perl. 336s Preparing to unpack .../39-libarchive-zip-perl_1.68-1_all.deb ... 336s Unpacking libarchive-zip-perl (1.68-1) ... 336s Selecting previously unselected package libsub-override-perl. 336s Preparing to unpack .../40-libsub-override-perl_0.10-1_all.deb ... 336s Unpacking libsub-override-perl (0.10-1) ... 336s Selecting previously unselected package libfile-stripnondeterminism-perl. 336s Preparing to unpack .../41-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 336s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 336s Selecting previously unselected package dh-strip-nondeterminism. 336s Preparing to unpack .../42-dh-strip-nondeterminism_1.13.1-1_all.deb ... 336s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 336s Selecting previously unselected package libdw1:ppc64el. 336s Preparing to unpack .../43-libdw1_0.190-1_ppc64el.deb ... 336s Unpacking libdw1:ppc64el (0.190-1) ... 336s Selecting previously unselected package debugedit. 336s Preparing to unpack .../44-debugedit_1%3a5.0-5_ppc64el.deb ... 336s Unpacking debugedit (1:5.0-5) ... 336s Selecting previously unselected package dwz. 336s Preparing to unpack .../45-dwz_0.15-1_ppc64el.deb ... 336s Unpacking dwz (0.15-1) ... 336s Selecting previously unselected package gettext. 336s Preparing to unpack .../46-gettext_0.21-14ubuntu1_ppc64el.deb ... 336s Unpacking gettext (0.21-14ubuntu1) ... 336s Selecting previously unselected package intltool-debian. 336s Preparing to unpack .../47-intltool-debian_0.35.0+20060710.6_all.deb ... 336s Unpacking intltool-debian (0.35.0+20060710.6) ... 336s Selecting previously unselected package po-debconf. 336s Preparing to unpack .../48-po-debconf_1.0.21+nmu1_all.deb ... 336s Unpacking po-debconf (1.0.21+nmu1) ... 337s Selecting previously unselected package debhelper. 337s Preparing to unpack .../49-debhelper_13.14.1ubuntu1_all.deb ... 337s Unpacking debhelper (13.14.1ubuntu1) ... 337s Selecting previously unselected package dh-apport. 337s Preparing to unpack .../50-dh-apport_2.28.0-0ubuntu1_all.deb ... 337s Unpacking dh-apport (2.28.0-0ubuntu1) ... 337s Selecting previously unselected package golang-1.22-src. 337s Preparing to unpack .../51-golang-1.22-src_1.22.1-1_all.deb ... 337s Unpacking golang-1.22-src (1.22.1-1) ... 339s Selecting previously unselected package golang-1.22-go. 339s Preparing to unpack .../52-golang-1.22-go_1.22.1-1_ppc64el.deb ... 339s Unpacking golang-1.22-go (1.22.1-1) ... 340s Selecting previously unselected package golang-src. 340s Preparing to unpack .../53-golang-src_2%3a1.22~2_all.deb ... 340s Unpacking golang-src (2:1.22~2) ... 340s Selecting previously unselected package golang-go:ppc64el. 340s Preparing to unpack .../54-golang-go_2%3a1.22~2_ppc64el.deb ... 340s Unpacking golang-go:ppc64el (2:1.22~2) ... 340s Selecting previously unselected package dh-golang. 340s Preparing to unpack .../55-dh-golang_1.62_all.deb ... 340s Unpacking dh-golang (1.62) ... 340s Selecting previously unselected package autopkgtest-satdep. 340s Preparing to unpack .../56-1-autopkgtest-satdep.deb ... 340s Unpacking autopkgtest-satdep (0) ... 340s Setting up libdw1:ppc64el (0.190-1) ... 340s Setting up libarchive-zip-perl (1.68-1) ... 340s Setting up libdebhelper-perl (13.14.1ubuntu1) ... 340s Setting up linux-libc-dev:ppc64el (6.8.0-11.11) ... 340s Setting up m4 (1.4.19-4) ... 340s Setting up libgomp1:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up dh-apport (2.28.0-0ubuntu1) ... 340s Setting up autotools-dev (20220109.1) ... 340s Setting up rpcsvc-proto (1.4.2-0ubuntu6) ... 340s Setting up golang-1.22-src (1.22.1-1) ... 340s Setting up libquadmath0:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up libmpc3:ppc64el (1.3.1-1) ... 340s Setting up libatomic1:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up autopoint (0.21-14ubuntu1) ... 340s Setting up autoconf (2.71-3) ... 340s Setting up libubsan1:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up dwz (0.15-1) ... 340s Setting up libcrypt-dev:ppc64el (1:4.4.36-4) ... 340s Setting up libasan8:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up debugedit (1:5.0-5) ... 340s Setting up libsub-override-perl (0.10-1) ... 340s Setting up libtsan2:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up libisl23:ppc64el (0.26-3) ... 340s Setting up libc-dev-bin (2.39-0ubuntu6) ... 340s Setting up cpp-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 340s Setting up golang-src (2:1.22~2) ... 340s Setting up libcc1-0:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up liblsan0:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up libitm1:ppc64el (14-20240303-1ubuntu1) ... 340s Setting up cpp-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 340s Setting up automake (1:1.16.5-1.3ubuntu1) ... 340s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 340s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 340s Setting up gettext (0.21-14ubuntu1) ... 340s Setting up cpp-13 (13.2.0-17ubuntu2) ... 340s Setting up golang-1.22-go (1.22.1-1) ... 340s Setting up intltool-debian (0.35.0+20060710.6) ... 340s Setting up dh-strip-nondeterminism (1.13.1-1) ... 340s Setting up libgcc-13-dev:ppc64el (13.2.0-17ubuntu2) ... 340s Setting up cpp (4:13.2.0-7ubuntu1) ... 340s Setting up libc6-dev:ppc64el (2.39-0ubuntu6) ... 340s Setting up libstdc++-13-dev:ppc64el (13.2.0-17ubuntu2) ... 340s Setting up golang-go:ppc64el (2:1.22~2) ... 340s Setting up po-debconf (1.0.21+nmu1) ... 340s Setting up gcc-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 340s Setting up gcc-13 (13.2.0-17ubuntu2) ... 340s Setting up libtool (2.4.7-7) ... 340s Setting up g++-13-powerpc64le-linux-gnu (13.2.0-17ubuntu2) ... 340s Setting up dh-autoreconf (20) ... 340s Setting up gcc-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 340s Setting up g++-powerpc64le-linux-gnu (4:13.2.0-7ubuntu1) ... 340s Setting up g++-13 (13.2.0-17ubuntu2) ... 340s Setting up debhelper (13.14.1ubuntu1) ... 340s Setting up gcc (4:13.2.0-7ubuntu1) ... 340s Setting up g++ (4:13.2.0-7ubuntu1) ... 340s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 340s Setting up build-essential (12.10ubuntu1) ... 340s Setting up dh-golang (1.62) ... 340s Setting up autopkgtest-satdep (0) ... 340s Processing triggers for man-db (2.12.0-3) ... 342s Processing triggers for install-info (7.1-3) ... 342s Processing triggers for libc-bin (2.39-0ubuntu6) ... 344s (Reading database ... 87932 files and directories currently installed.) 344s Removing autopkgtest-satdep (0) ... 345s autopkgtest [19:07:10]: test command1: ./debian/tests/test 345s autopkgtest [19:07:10]: test command1: [----------------------- 413s === RUN TestRunSignal 413s === RUN TestRunSignal/Send_SIGTERM_exits 413s INFO Starting WSL Pro Service version Dev 413s === RUN TestRunSignal/Send_SIGINT_exits 413s INFO Starting WSL Pro Service version Dev 413s --- PASS: TestRunSignal (0.20s) 413s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 413s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 413s === RUN TestRun 413s === PAUSE TestRun 413s === CONT TestRun 413s === RUN TestRun/Run_and_return_usage_error 413s === PAUSE TestRun/Run_and_return_usage_error 413s === RUN TestRun/Run_and_usage_error_only_does_not_fail 413s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 413s === RUN TestRun/Run_and_exit_successfully 413s === PAUSE TestRun/Run_and_exit_successfully 413s === RUN TestRun/Run_and_return_error 413s === PAUSE TestRun/Run_and_return_error 413s === CONT TestRun/Run_and_return_usage_error 413s INFO Starting WSL Pro Service version Dev 413s ERROR context.Background Error requested 413s === CONT TestRun/Run_and_return_error 413s INFO Starting WSL Pro Service version Dev 413s ERROR context.Background Error requested 413s === CONT TestRun/Run_and_exit_successfully 413s INFO Starting WSL Pro Service version Dev 413s === CONT TestRun/Run_and_usage_error_only_does_not_fail 413s INFO Starting WSL Pro Service version Dev 413s --- PASS: TestRun (0.00s) 413s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 413s --- PASS: TestRun/Run_and_return_error (0.10s) 413s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 413s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 413s PASS 413s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.610s 414s === RUN TestHelp 414s --- PASS: TestHelp (0.00s) 414s === RUN TestCompletion 414s --- PASS: TestCompletion (0.00s) 414s === RUN TestVersion 414s --- PASS: TestVersion (0.00s) 414s === RUN TestNoUsageError 414s --- PASS: TestNoUsageError (0.00s) 414s === RUN TestUsageError 414s === PAUSE TestUsageError 414s === RUN TestCanQuitWhenExecute 415s === PAUSE TestCanQuitWhenExecute 415s === RUN TestCanQuitTwice 415s === PAUSE TestCanQuitTwice 415s === RUN TestAppCanQuitWithoutExecute 415s === PAUSE TestAppCanQuitWithoutExecute 415s === RUN TestAppRunFailsOnComponentsCreationAndQuit 415s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 415s === RUN TestAppGetRootCmd 415s === PAUSE TestAppGetRootCmd 415s === RUN TestWithProMock 415s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 415s --- SKIP: TestWithProMock (0.00s) 415s === RUN TestWithWslPathMock 415s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 415s --- SKIP: TestWithWslPathMock (0.00s) 415s === RUN TestWithWslInfoMock 415s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 415s --- SKIP: TestWithWslInfoMock (0.00s) 415s === RUN TestWithCmdExeMock 415s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 415s --- SKIP: TestWithCmdExeMock (0.00s) 415s === CONT TestUsageError 415s --- PASS: TestUsageError (0.00s) 415s === CONT TestAppGetRootCmd 415s --- PASS: TestAppGetRootCmd (0.00s) 415s === CONT TestAppRunFailsOnComponentsCreationAndQuit 418s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (3.68s) 418s === CONT TestAppCanQuitWithoutExecute 418s service_test.go:137: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 418s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 418s === CONT TestCanQuitTwice 418s time="2024-03-25T19:08:23Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/cmd/wsl-pro-service/service/service.go:67 New.func1() Debug mode is enabled" 418s time="2024-03-25T19:08:23Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:63 New() Building new daemon" 418s time="2024-03-25T19:08:23Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:80 MockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:43485\"" 421s time="2024-03-25T19:08:25Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:256 (*Daemon).Quit() Stopping daemon requested." 421s time="2024-03-25T19:08:25Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:265 (*Daemon).Quit() Waiting for active requests to close." 422s time="2024-03-25T19:08:27Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/controlstream/session.go:25 newSession() Connecting to control stream at \"127.0.0.1:43485\"" 422s time="2024-03-25T19:08:27Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/controlstream/controlstream.go:75 (*ControlStream).Connect() Control stream: starting handshake" 422s time="2024-03-25T19:08:27Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:134 (*wslInstanceMockService).Connected() wslInstanceMockService: Received incoming connection" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:148 (*wslInstanceMockService).Connected() wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:176 (*wslInstanceMockService).Connected() wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 42271" 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/controlstream/controlstream.go:82 (*ControlStream).Connect() Control stream: completed handshake" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:176 (*Daemon).serveOnce() Connected to control stream" 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/wslinstanceservice/wslinstanceservice.go:44 (*Service).RegisterGRPCService() Registering gRPC WSL instance service" 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:223 (*Daemon).serve() Starting to serve gRPC requests" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:233 (*Daemon).serve() Serving gRPC requests on localhost:42271" 423s time="2024-03-25T19:08:28Z" level=error msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:142 (*Daemon).Serve() Serve error: WSL Pro Service stopped serving: grpc error: grpc: the server has been stopped" 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:267 (*Daemon).Quit() All connections have now ended." 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:256 (*Daemon).Quit() Stopping daemon requested." 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:265 (*Daemon).Quit() Waiting for active requests to close." 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:267 (*Daemon).Quit() All connections have now ended." 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:256 (*Daemon).Quit() Stopping daemon requested." 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:265 (*Daemon).Quit() Waiting for active requests to close." 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:267 (*Daemon).Quit() All connections have now ended." 423s --- PASS: TestCanQuitTwice (4.76s) 423s === CONT TestCanQuitWhenExecute 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/cmd/wsl-pro-service/service/service.go:67 New.func1() Debug mode is enabled" 423s time="2024-03-25T19:08:28Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:63 New() Building new daemon" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:89 MockWindowsAgent.func1() MockWindowsAgent: Remove address file returned an error: remove /tmp/TestCanQuitTwice3085269071/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 423s time="2024-03-25T19:08:28Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/testutils/mock_agent.go:80 MockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:40681\"" 427s time="2024-03-25T19:08:32Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:256 (*Daemon).Quit() Stopping daemon requested." 427s time="2024-03-25T19:08:32Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:265 (*Daemon).Quit() Waiting for active requests to close." 427s time="2024-03-25T19:08:32Z" level=error msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:142 (*Daemon).Serve() Serve error: could not connect to Windows Agent via the control stream: could not get address: could not read agent port file \"/tmp/TestCanQuitWhenExecute2502566337/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestCanQuitWhenExecute2502566337/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 427s time="2024-03-25T19:08:32Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:267 (*Daemon).Quit() All connections have now ended." 427s time="2024-03-25T19:08:32Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:256 (*Daemon).Quit() Stopping daemon requested." 427s time="2024-03-25T19:08:32Z" level=info msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:265 (*Daemon).Quit() Waiting for active requests to close." 427s time="2024-03-25T19:08:32Z" level=debug msg="/tmp/autopkgtest.xOPpTv/build.Nb2/src/internal/daemon/daemon.go:267 (*Daemon).Quit() All connections have now ended." 427s --- PASS: TestCanQuitWhenExecute (3.93s) 427s PASS 427s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 12.386s 427s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 427s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 428s === RUN TestNew 428s === PAUSE TestNew 428s === RUN TestConnect 428s === PAUSE TestConnect 428s === RUN TestSend 428s === PAUSE TestSend 428s === RUN TestReconnection 428s === PAUSE TestReconnection 428s === RUN TestWithProMock 428s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 428s --- SKIP: TestWithProMock (0.00s) 428s === RUN TestWithWslPathMock 428s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 428s --- SKIP: TestWithWslPathMock (0.00s) 428s === RUN TestWithWslInfoMock 428s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 428s --- SKIP: TestWithWslInfoMock (0.00s) 428s === RUN TestWithCmdExeMock 428s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 428s --- SKIP: TestWithCmdExeMock (0.00s) 428s === CONT TestNew 428s === RUN TestNew/Error_when_WslPath_returns_error 428s === PAUSE TestNew/Error_when_WslPath_returns_error 428s === RUN TestNew/Success 428s === PAUSE TestNew/Success 428s === RUN TestNew/Error_when_the_context_is_cancelled 428s === PAUSE TestNew/Error_when_the_context_is_cancelled 428s === CONT TestNew/Error_when_WslPath_returns_error 430s === CONT TestReconnection 430s === RUN TestReconnection/Success_connecting_after_failing_to_connect 430s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 430s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 430s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 430s === CONT TestSend 430s time="2024-03-25T19:08:35Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:40357\"" 433s time="2024-03-25T19:08:38Z" level=info msg="Connecting to control stream at \"127.0.0.1:40357\"" 433s time="2024-03-25T19:08:38Z" level=debug msg="Control stream: starting handshake" 433s time="2024-03-25T19:08:38Z" level=info msg="wslInstanceMockService: Received incoming connection" 434s time="2024-03-25T19:08:39Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 434s time="2024-03-25T19:08:39Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 39507" 434s time="2024-03-25T19:08:39Z" level=debug msg="Control stream: completed handshake" 439s time="2024-03-25T19:08:44Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": connected back via reserved port" 439s time="2024-03-25T19:08:44Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 439s time="2024-03-25T19:08:44Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\" ended: rpc error: code = Canceled desc = context canceled" 439s time="2024-03-25T19:08:44Z" level=info msg="wslInstanceMockService: dropped connection" 439s --- PASS: TestSend (9.23s) 439s === CONT TestConnect 439s === RUN TestConnect/Error_because_WindowsForwardedLocalhost_returns_error 439s === PAUSE TestConnect/Error_because_WindowsForwardedLocalhost_returns_error 439s === RUN TestConnect/Incomplete_handshake_because_Agent_never_receives 439s === PAUSE TestConnect/Incomplete_handshake_because_Agent_never_receives 439s === RUN TestConnect/Incomplete_handshake_because_Agent_never_sends_a_port 439s === PAUSE TestConnect/Incomplete_handshake_because_Agent_never_sends_a_port 439s === RUN TestConnect/No_connection_because_port_file_does_not_exist 439s === PAUSE TestConnect/No_connection_because_port_file_does_not_exist 439s === RUN TestConnect/No_connection_because_of_unreadable_port_file 439s === PAUSE TestConnect/No_connection_because_of_unreadable_port_file 439s === RUN TestConnect/No_connection_because_of_empty_port_file 439s === PAUSE TestConnect/No_connection_because_of_empty_port_file 439s === RUN TestConnect/No_connection_because_of_port_file_with_invalid_contents 439s === PAUSE TestConnect/No_connection_because_of_port_file_with_invalid_contents 439s === RUN TestConnect/No_connection_because_of_port_file_contains_the_wrong_port 439s === PAUSE TestConnect/No_connection_because_of_port_file_contains_the_wrong_port 439s === RUN TestConnect/Incomplete_handshake_because_Agent_sends_port_:0 439s === PAUSE TestConnect/Incomplete_handshake_because_Agent_sends_port_:0 439s === RUN TestConnect/Success 439s === PAUSE TestConnect/Success 439s === RUN TestConnect/Error_when_system_cannot_retrieve_the_WSL_distro_name 439s === PAUSE TestConnect/Error_when_system_cannot_retrieve_the_WSL_distro_name 439s time="2024-03-25T19:08:44Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestSend247389691/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 439s === CONT TestNew/Error_when_the_context_is_cancelled 439s === CONT TestNew/Success 441s --- PASS: TestNew (0.00s) 441s --- PASS: TestNew/Error_when_WslPath_returns_error (2.15s) 441s --- PASS: TestNew/Error_when_the_context_is_cancelled (0.00s) 441s --- PASS: TestNew/Success (2.11s) 441s === CONT TestReconnection/Success_connecting_after_failing_to_connect 444s time="2024-03-25T19:08:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:35051\"" 445s time="2024-03-25T19:08:50Z" level=info msg="Connecting to control stream at \"127.0.0.1:35051\"" 445s time="2024-03-25T19:08:50Z" level=debug msg="Control stream: starting handshake" 445s time="2024-03-25T19:08:50Z" level=info msg="wslInstanceMockService: Received incoming connection" 446s time="2024-03-25T19:08:51Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 446s time="2024-03-25T19:08:51Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 41471" 446s time="2024-03-25T19:08:51Z" level=debug msg="Control stream: completed handshake" 446s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 448s time="2024-03-25T19:08:53Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:42471\"" 449s time="2024-03-25T19:08:54Z" level=info msg="Connecting to control stream at \"127.0.0.1:42471\"" 449s time="2024-03-25T19:08:54Z" level=debug msg="Control stream: starting handshake" 449s time="2024-03-25T19:08:54Z" level=info msg="wslInstanceMockService: Received incoming connection" 451s time="2024-03-25T19:08:55Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 451s time="2024-03-25T19:08:55Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 45545" 451s time="2024-03-25T19:08:55Z" level=debug msg="Control stream: completed handshake" 451s time="2024-03-25T19:08:56Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:38607\"" 452s time="2024-03-25T19:08:57Z" level=info msg="Connecting to control stream at \"127.0.0.1:38607\"" 452s time="2024-03-25T19:08:57Z" level=debug msg="Control stream: starting handshake" 452s time="2024-03-25T19:08:57Z" level=info msg="wslInstanceMockService: Received incoming connection" 453s time="2024-03-25T19:08:58Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 453s time="2024-03-25T19:08:58Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 41935" 453s time="2024-03-25T19:08:58Z" level=debug msg="Control stream: completed handshake" 453s --- PASS: TestReconnection (0.00s) 453s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (5.30s) 453s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (6.50s) 453s === CONT TestConnect/Error_because_WindowsForwardedLocalhost_returns_error 453s time="2024-03-25T19:08:58Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:40649\"" 456s time="2024-03-25T19:09:01Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectError_because_WindowsForwardedLocalhost_returns_error1140777639/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 456s === CONT TestConnect/Error_when_system_cannot_retrieve_the_WSL_distro_name 456s time="2024-03-25T19:09:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:39113\"" 460s time="2024-03-25T19:09:05Z" level=warning msg="Controlstream: assigning arbitrary connection ID because of error: could not obtain WSL distro name: could not get distro root path: exit status 1. Stdout: " 460s time="2024-03-25T19:09:05Z" level=info msg="Connecting to control stream at \"127.0.0.1:39113\"" 460s time="2024-03-25T19:09:05Z" level=debug msg="Control stream: starting handshake" 460s time="2024-03-25T19:09:05Z" level=info msg="wslInstanceMockService: Received incoming connection" 461s time="2024-03-25T19:09:06Z" level=warning msg="wslInstanceMockService: dropped connection: new connection: did not receive info from WSL distro: rpc error: code = Canceled desc = context canceled" 461s === CONT TestConnect/Success 461s time="2024-03-25T19:09:06Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectError_when_system_cannot_retrieve_the_WSL_distro_name1010176933/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 461s time="2024-03-25T19:09:06Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:33121\"" 465s time="2024-03-25T19:09:10Z" level=info msg="Connecting to control stream at \"127.0.0.1:33121\"" 465s time="2024-03-25T19:09:10Z" level=debug msg="Control stream: starting handshake" 465s time="2024-03-25T19:09:10Z" level=info msg="wslInstanceMockService: Received incoming connection" 466s time="2024-03-25T19:09:11Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 466s time="2024-03-25T19:09:11Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 39859" 466s time="2024-03-25T19:09:11Z" level=debug msg="Control stream: completed handshake" 467s === CONT TestConnect/Incomplete_handshake_because_Agent_sends_port_:0 467s time="2024-03-25T19:09:12Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectSuccess696594941/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 467s time="2024-03-25T19:09:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:43091\"" 470s time="2024-03-25T19:09:15Z" level=info msg="Connecting to control stream at \"127.0.0.1:43091\"" 470s time="2024-03-25T19:09:15Z" level=debug msg="Control stream: starting handshake" 470s time="2024-03-25T19:09:15Z" level=info msg="wslInstanceMockService: Received incoming connection" 471s time="2024-03-25T19:09:16Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 471s time="2024-03-25T19:09:16Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Sending bad port 0" 471s === CONT TestConnect/No_connection_because_of_port_file_contains_the_wrong_port 471s time="2024-03-25T19:09:16Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectIncomplete_handshake_because_Agent_sends_port_0477016679/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 471s time="2024-03-25T19:09:16Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:41387\"" 471s time="2024-03-25T19:09:16Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:41471: connect: connection refused" 474s time="2024-03-25T19:09:19Z" level=info msg="Connecting to control stream at \"127.0.0.1:36051\"" 474s === CONT TestConnect/No_connection_because_of_port_file_with_invalid_contents 474s time="2024-03-25T19:09:19Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectNo_connection_because_of_port_file_contains_the_wrong_port926827832/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 474s time="2024-03-25T19:09:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:41275\"" 476s time="2024-03-25T19:09:20Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:45545: connect: connection refused" 477s === CONT TestConnect/No_connection_because_of_empty_port_file 477s time="2024-03-25T19:09:22Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectNo_connection_because_of_port_file_with_invalid_contents3443621986/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 477s time="2024-03-25T19:09:22Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:36489\"" 478s time="2024-03-25T19:09:23Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:41935: connect: connection refused" 480s === CONT TestConnect/No_connection_because_of_unreadable_port_file 480s time="2024-03-25T19:09:25Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectNo_connection_because_of_empty_port_file677309897/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 480s time="2024-03-25T19:09:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:45395\"" 484s === CONT TestConnect/No_connection_because_port_file_does_not_exist 484s time="2024-03-25T19:09:29Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectNo_connection_because_of_unreadable_port_file1988107017/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 484s time="2024-03-25T19:09:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:42559\"" 487s === CONT TestConnect/Incomplete_handshake_because_Agent_never_sends_a_port 487s time="2024-03-25T19:09:32Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectNo_connection_because_port_file_does_not_exist2340275705/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 487s time="2024-03-25T19:09:32Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:35733\"" 490s time="2024-03-25T19:09:35Z" level=info msg="Connecting to control stream at \"127.0.0.1:35733\"" 490s time="2024-03-25T19:09:35Z" level=debug msg="Control stream: starting handshake" 490s time="2024-03-25T19:09:35Z" level=info msg="wslInstanceMockService: Received incoming connection" 491s time="2024-03-25T19:09:36Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 491s time="2024-03-25T19:09:36Z" level=info msg="connection with \"TEST_DISTRO\": mock error: dropping stream before sending port" 491s time="2024-03-25T19:09:36Z" level=info msg="wslInstanceMockService: dropped connection" 491s === CONT TestConnect/Incomplete_handshake_because_Agent_never_receives 491s time="2024-03-25T19:09:36Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectIncomplete_handshake_because_Agent_never_sends_a_port1125071519/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 491s time="2024-03-25T19:09:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:33729\"" 491s time="2024-03-25T19:09:36Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:39859: connect: connection refused" 494s time="2024-03-25T19:09:39Z" level=info msg="Connecting to control stream at \"127.0.0.1:33729\"" 494s time="2024-03-25T19:09:39Z" level=debug msg="Control stream: starting handshake" 494s time="2024-03-25T19:09:39Z" level=info msg="wslInstanceMockService: Received incoming connection" 494s time="2024-03-25T19:09:39Z" level=info msg="wslInstanceMockService: mock error: dropping stream before first Recv" 494s time="2024-03-25T19:09:39Z" level=info msg="wslInstanceMockService: dropped connection" 495s time="2024-03-25T19:09:40Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestConnectIncomplete_handshake_because_Agent_never_receives1380222672/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 495s --- PASS: TestConnect (0.00s) 495s --- PASS: TestConnect/Error_because_WindowsForwardedLocalhost_returns_error (3.22s) 495s --- PASS: TestConnect/Error_when_system_cannot_retrieve_the_WSL_distro_name (5.42s) 495s --- PASS: TestConnect/Success (5.43s) 495s --- PASS: TestConnect/Incomplete_handshake_because_Agent_sends_port_:0 (4.32s) 495s --- PASS: TestConnect/No_connection_because_of_port_file_contains_the_wrong_port (3.05s) 495s --- PASS: TestConnect/No_connection_because_of_port_file_with_invalid_contents (3.09s) 495s --- PASS: TestConnect/No_connection_because_of_empty_port_file (3.09s) 495s --- PASS: TestConnect/No_connection_because_of_unreadable_port_file (3.26s) 495s --- PASS: TestConnect/No_connection_because_port_file_does_not_exist (3.12s) 495s --- PASS: TestConnect/Incomplete_handshake_because_Agent_never_sends_a_port (3.97s) 495s --- PASS: TestConnect/Incomplete_handshake_because_Agent_never_receives (4.17s) 495s PASS 495s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/controlstream 67.451s 496s === RUN TestNew 496s === PAUSE TestNew 496s === RUN TestServe 496s === PAUSE TestServe 496s === RUN TestServeAndQuit 496s === PAUSE TestServeAndQuit 496s === RUN TestReconnection 496s === PAUSE TestReconnection 496s === RUN TestWithProMock 496s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 496s --- SKIP: TestWithProMock (0.00s) 496s === RUN TestWithWslPathMock 496s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 496s --- SKIP: TestWithWslPathMock (0.00s) 496s === RUN TestWithWslInfoMock 496s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 496s --- SKIP: TestWithWslInfoMock (0.00s) 496s === RUN TestWithCmdExeMock 496s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 496s --- SKIP: TestWithCmdExeMock (0.00s) 496s === CONT TestNew 496s === RUN TestNew/Success 496s === PAUSE TestNew/Success 496s === RUN TestNew/Error_when_WslPath_returns_error 496s === PAUSE TestNew/Error_when_WslPath_returns_error 496s === CONT TestNew/Success 496s time="2024-03-25T19:09:41Z" level=debug msg="Building new daemon" 498s === CONT TestReconnection 498s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 498s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 498s === RUN TestReconnection/Success_connecting_after_failing_to_connect 498s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 498s === CONT TestServeAndQuit 498s === RUN TestServeAndQuit/Success_with_graceful_quit 498s === PAUSE TestServeAndQuit/Success_with_graceful_quit 498s === RUN TestServeAndQuit/Success_with_forceful_quit 498s === PAUSE TestServeAndQuit/Success_with_forceful_quit 498s === RUN TestServeAndQuit/Success_with_double_quit 498s === PAUSE TestServeAndQuit/Success_with_double_quit 498s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 498s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 498s === CONT TestServe 498s === RUN TestServe/No_connection_because_port_file_does_not_exist 498s === PAUSE TestServe/No_connection_because_port_file_does_not_exist 498s === RUN TestServe/No_connection_because_of_faulty_agent 498s === PAUSE TestServe/No_connection_because_of_faulty_agent 498s === RUN TestServe/Error_because_of_notifier_returning_error 498s === PAUSE TestServe/Error_because_of_notifier_returning_error 498s === RUN TestServe/Error_because_WindowsHostAddress_returns_error 498s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_error 498s === RUN TestServe/Error_because_of_context_cancelled 498s === PAUSE TestServe/Error_because_of_context_cancelled 498s === RUN TestServe/Success 498s === PAUSE TestServe/Success 498s === RUN TestServe/Success_with_systemd_notifier_returning_true 498s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 498s === CONT TestNew/Error_when_WslPath_returns_error 498s time="2024-03-25T19:09:43Z" level=debug msg="Building new daemon" 500s --- PASS: TestNew (0.00s) 500s --- PASS: TestNew/Success (2.14s) 500s --- PASS: TestNew/Error_when_WslPath_returns_error (2.13s) 500s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 500s time="2024-03-25T19:09:45Z" level=debug msg="Building new daemon" 502s time="2024-03-25T19:09:47Z" level=debug msg="Ready state sent to systemd" 502s time="2024-03-25T19:09:47Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:33513\"" 503s time="2024-03-25T19:09:48Z" level=info msg="Connecting to control stream at \"127.0.0.1:33513\"" 503s time="2024-03-25T19:09:48Z" level=debug msg="Control stream: starting handshake" 503s time="2024-03-25T19:09:48Z" level=info msg="wslInstanceMockService: Received incoming connection" 506s time="2024-03-25T19:09:49Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 506s time="2024-03-25T19:09:49Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 42277" 506s time="2024-03-25T19:09:49Z" level=debug msg="Control stream: completed handshake" 506s time="2024-03-25T19:09:49Z" level=info msg="Connected to control stream" 506s time="2024-03-25T19:09:49Z" level=debug msg="Starting to serve gRPC requests" 506s time="2024-03-25T19:09:49Z" level=info msg="Serving gRPC requests on localhost:42277" 506s time="2024-03-25T19:09:49Z" level=debug msg="Updated systemd status to \"Serving\"" 506s time="2024-03-25T19:09:50Z" level=error msg="Serve error: lost connection to Windows Agent" 506s time="2024-03-25T19:09:50Z" level=debug msg="Updated systemd status to \"Not serving: waiting to retry\"" 506s time="2024-03-25T19:09:50Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:38499\"" 507s time="2024-03-25T19:09:52Z" level=info msg="Retrying connection to control stream" 507s time="2024-03-25T19:09:52Z" level=debug msg="Updated systemd status to \"Not serving: retrying\"" 508s time="2024-03-25T19:09:53Z" level=info msg="Connecting to control stream at \"127.0.0.1:38499\"" 508s time="2024-03-25T19:09:53Z" level=debug msg="Control stream: starting handshake" 508s time="2024-03-25T19:09:53Z" level=info msg="wslInstanceMockService: Received incoming connection" 510s time="2024-03-25T19:09:55Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 510s time="2024-03-25T19:09:55Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 41911" 510s time="2024-03-25T19:09:55Z" level=debug msg="Control stream: completed handshake" 510s time="2024-03-25T19:09:55Z" level=info msg="Connected to control stream" 510s time="2024-03-25T19:09:55Z" level=debug msg="Starting to serve gRPC requests" 510s time="2024-03-25T19:09:55Z" level=info msg="Serving gRPC requests on localhost:41911" 510s time="2024-03-25T19:09:55Z" level=debug msg="Updated systemd status to \"Serving\"" 515s time="2024-03-25T19:10:00Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": connected back via reserved port" 515s time="2024-03-25T19:10:00Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\" ended: rpc error: code = Canceled desc = context canceled" 515s time="2024-03-25T19:10:00Z" level=info msg="wslInstanceMockService: dropped connection" 515s time="2024-03-25T19:10:00Z" level=info msg="Stopping daemon requested." 515s time="2024-03-25T19:10:00Z" level=error msg="Serve error: lost connection to Windows Agent" 515s time="2024-03-25T19:10:00Z" level=debug msg="Updated systemd status to \"Not serving: waiting to retry\"" 515s time="2024-03-25T19:10:00Z" level=debug msg="Updated systemd status to \"Stopped\"" 515s === CONT TestReconnection/Success_connecting_after_failing_to_connect 515s time="2024-03-25T19:10:00Z" level=debug msg="Building new daemon" 517s time="2024-03-25T19:10:02Z" level=debug msg="Ready state sent to systemd" 519s time="2024-03-25T19:10:03Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3702455866/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3702455866/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 519s time="2024-03-25T19:10:03Z" level=debug msg="Updated systemd status to \"Not serving: waiting to retry\"" 519s time="2024-03-25T19:10:04Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:41539\"" 520s time="2024-03-25T19:10:05Z" level=info msg="Retrying connection to control stream" 520s time="2024-03-25T19:10:05Z" level=debug msg="Updated systemd status to \"Not serving: retrying\"" 522s time="2024-03-25T19:10:07Z" level=info msg="Connecting to control stream at \"127.0.0.1:41539\"" 522s time="2024-03-25T19:10:07Z" level=debug msg="Control stream: starting handshake" 522s time="2024-03-25T19:10:07Z" level=info msg="wslInstanceMockService: Received incoming connection" 523s time="2024-03-25T19:10:08Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 523s time="2024-03-25T19:10:08Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 33175" 523s time="2024-03-25T19:10:08Z" level=debug msg="Control stream: completed handshake" 523s time="2024-03-25T19:10:08Z" level=info msg="Connected to control stream" 523s time="2024-03-25T19:10:08Z" level=debug msg="Starting to serve gRPC requests" 523s time="2024-03-25T19:10:08Z" level=info msg="Serving gRPC requests on localhost:33175" 523s time="2024-03-25T19:10:08Z" level=debug msg="Updated systemd status to \"Serving\"" 528s time="2024-03-25T19:10:13Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": connected back via reserved port" 529s time="2024-03-25T19:10:14Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\" ended: rpc error: code = Canceled desc = context canceled" 529s time="2024-03-25T19:10:14Z" level=info msg="wslInstanceMockService: dropped connection" 529s time="2024-03-25T19:10:14Z" level=info msg="Stopping daemon requested." 529s time="2024-03-25T19:10:14Z" level=error msg="Serve error: lost connection to Windows Agent" 529s time="2024-03-25T19:10:14Z" level=debug msg="Updated systemd status to \"Not serving: waiting to retry\"" 529s time="2024-03-25T19:10:14Z" level=debug msg="Updated systemd status to \"Stopped\"" 529s --- PASS: TestReconnection (0.00s) 529s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (15.22s) 529s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (13.26s) 529s === CONT TestServeAndQuit/Success_with_graceful_quit 529s time="2024-03-25T19:10:14Z" level=debug msg="Building new daemon" 529s time="2024-03-25T19:10:14Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:46473\"" 529s time="2024-03-25T19:10:14Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:42277: connect: connection refused" 531s time="2024-03-25T19:10:16Z" level=debug msg="Ready state sent to systemd" 532s time="2024-03-25T19:10:17Z" level=info msg="Connecting to control stream at \"127.0.0.1:46473\"" 532s time="2024-03-25T19:10:17Z" level=debug msg="Control stream: starting handshake" 532s time="2024-03-25T19:10:17Z" level=info msg="wslInstanceMockService: Received incoming connection" 533s time="2024-03-25T19:10:18Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 533s time="2024-03-25T19:10:18Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 40565" 533s time="2024-03-25T19:10:18Z" level=debug msg="Control stream: completed handshake" 533s time="2024-03-25T19:10:18Z" level=info msg="Connected to control stream" 533s time="2024-03-25T19:10:18Z" level=debug msg="Starting to serve gRPC requests" 533s time="2024-03-25T19:10:18Z" level=info msg="Serving gRPC requests on localhost:40565" 533s time="2024-03-25T19:10:18Z" level=debug msg="Updated systemd status to \"Serving\"" 534s time="2024-03-25T19:10:19Z" level=info msg="Stopping daemon requested." 534s time="2024-03-25T19:10:19Z" level=info msg="Waiting for active requests to close." 534s time="2024-03-25T19:10:19Z" level=debug msg="Updated systemd status to \"Stopped\"" 534s time="2024-03-25T19:10:19Z" level=debug msg="All connections have now ended." 534s time="2024-03-25T19:10:19Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeAndQuitSuccess_with_graceful_quit4119109612/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 534s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 534s time="2024-03-25T19:10:19Z" level=debug msg="Building new daemon" 534s time="2024-03-25T19:10:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:40891\"" 536s time="2024-03-25T19:10:21Z" level=debug msg="Updated systemd status to \"Stopped\"" 536s === CONT TestServeAndQuit/Success_with_double_quit 536s time="2024-03-25T19:10:21Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeAndQuitError_due_to_quitting_before_serving4129209884/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 536s time="2024-03-25T19:10:21Z" level=debug msg="Building new daemon" 536s time="2024-03-25T19:10:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:46493\"" 538s time="2024-03-25T19:10:23Z" level=debug msg="Ready state sent to systemd" 539s time="2024-03-25T19:10:24Z" level=info msg="Connecting to control stream at \"127.0.0.1:46493\"" 539s time="2024-03-25T19:10:24Z" level=debug msg="Control stream: starting handshake" 539s time="2024-03-25T19:10:24Z" level=info msg="wslInstanceMockService: Received incoming connection" 541s time="2024-03-25T19:10:26Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 541s time="2024-03-25T19:10:26Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 41483" 541s time="2024-03-25T19:10:26Z" level=debug msg="Control stream: completed handshake" 541s time="2024-03-25T19:10:26Z" level=info msg="Connected to control stream" 541s time="2024-03-25T19:10:26Z" level=debug msg="Starting to serve gRPC requests" 541s time="2024-03-25T19:10:26Z" level=info msg="Serving gRPC requests on localhost:41483" 541s time="2024-03-25T19:10:26Z" level=debug msg="Updated systemd status to \"Serving\"" 541s time="2024-03-25T19:10:26Z" level=info msg="Stopping daemon requested." 541s time="2024-03-25T19:10:26Z" level=info msg="Waiting for active requests to close." 541s time="2024-03-25T19:10:26Z" level=debug msg="Updated systemd status to \"Stopped\"" 541s time="2024-03-25T19:10:26Z" level=debug msg="All connections have now ended." 541s time="2024-03-25T19:10:26Z" level=info msg="Stopping daemon requested." 541s time="2024-03-25T19:10:26Z" level=info msg="Waiting for active requests to close." 541s time="2024-03-25T19:10:26Z" level=debug msg="All connections have now ended." 541s === CONT TestServeAndQuit/Success_with_forceful_quit 541s time="2024-03-25T19:10:26Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeAndQuitSuccess_with_double_quit3147658434/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 541s time="2024-03-25T19:10:26Z" level=debug msg="Building new daemon" 541s time="2024-03-25T19:10:26Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:46869\"" 543s time="2024-03-25T19:10:28Z" level=debug msg="Ready state sent to systemd" 544s time="2024-03-25T19:10:29Z" level=info msg="Connecting to control stream at \"127.0.0.1:46869\"" 544s time="2024-03-25T19:10:29Z" level=debug msg="Control stream: starting handshake" 544s time="2024-03-25T19:10:29Z" level=info msg="wslInstanceMockService: Received incoming connection" 545s time="2024-03-25T19:10:30Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 545s time="2024-03-25T19:10:30Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 41275" 545s time="2024-03-25T19:10:30Z" level=debug msg="Control stream: completed handshake" 545s time="2024-03-25T19:10:30Z" level=info msg="Connected to control stream" 545s time="2024-03-25T19:10:30Z" level=debug msg="Starting to serve gRPC requests" 545s time="2024-03-25T19:10:30Z" level=info msg="Serving gRPC requests on localhost:41275" 545s time="2024-03-25T19:10:30Z" level=debug msg="Updated systemd status to \"Serving\"" 546s time="2024-03-25T19:10:30Z" level=info msg="Stopping daemon requested." 546s time="2024-03-25T19:10:30Z" level=debug msg="Updated systemd status to \"Stopped\"" 546s --- PASS: TestServeAndQuit (0.00s) 546s --- PASS: TestServeAndQuit/Success_with_graceful_quit (5.11s) 546s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (2.14s) 546s --- PASS: TestServeAndQuit/Success_with_double_quit (5.37s) 546s --- PASS: TestServeAndQuit/Success_with_forceful_quit (4.33s) 546s time="2024-03-25T19:10:30Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeAndQuitSuccess_with_forceful_quit1797610825/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 546s === CONT TestServe/No_connection_because_port_file_does_not_exist 546s time="2024-03-25T19:10:30Z" level=debug msg="Building new daemon" 546s time="2024-03-25T19:10:30Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:44445\"" 549s time="2024-03-25T19:10:34Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 551s time="2024-03-25T19:10:36Z" level=info msg="Retrying connection to control stream" 552s time="2024-03-25T19:10:37Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 556s time="2024-03-25T19:10:41Z" level=info msg="Retrying connection to control stream" 557s time="2024-03-25T19:10:42Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 558s time="2024-03-25T19:10:43Z" level=info msg="Stopping daemon requested." 558s time="2024-03-25T19:10:43Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeNo_connection_because_port_file_does_not_exist1248697988/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 558s === CONT TestServe/Success_with_systemd_notifier_returning_true 558s time="2024-03-25T19:10:43Z" level=debug msg="Building new daemon" 558s time="2024-03-25T19:10:43Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:34179\"" 558s time="2024-03-25T19:10:43Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:40565: connect: connection refused" 560s time="2024-03-25T19:10:45Z" level=debug msg="Ready state sent to systemd" 561s time="2024-03-25T19:10:46Z" level=info msg="Connecting to control stream at \"127.0.0.1:34179\"" 561s time="2024-03-25T19:10:46Z" level=debug msg="Control stream: starting handshake" 561s time="2024-03-25T19:10:46Z" level=info msg="wslInstanceMockService: Received incoming connection" 562s time="2024-03-25T19:10:47Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 562s time="2024-03-25T19:10:47Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 33521" 562s time="2024-03-25T19:10:47Z" level=debug msg="Control stream: completed handshake" 562s time="2024-03-25T19:10:47Z" level=info msg="Connected to control stream" 562s time="2024-03-25T19:10:47Z" level=debug msg="Starting to serve gRPC requests" 562s time="2024-03-25T19:10:47Z" level=info msg="Serving gRPC requests on localhost:33521" 562s time="2024-03-25T19:10:47Z" level=debug msg="Updated systemd status to \"Serving\"" 566s time="2024-03-25T19:10:51Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:41483: connect: connection refused" 567s time="2024-03-25T19:10:52Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": connected back via reserved port" 570s time="2024-03-25T19:10:55Z" level=info msg="Stopping daemon requested." 570s time="2024-03-25T19:10:55Z" level=warning msg="wslInstanceMockService: dropped connection: wslInstanceMockService: could not dial \"TEST_DISTRO\": dial tcp4 127.0.0.1:41275: connect: connection refused" 687s time="2024-03-25T19:12:52Z" level=debug msg="Updated systemd status to \"Stopped\"" 687s time="2024-03-25T19:12:52Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\" ended: rpc error: code = Canceled desc = context canceled" 687s time="2024-03-25T19:12:52Z" level=info msg="wslInstanceMockService: dropped connection" 687s === CONT TestServe/Success 687s time="2024-03-25T19:12:52Z" level=debug msg="Building new daemon" 687s time="2024-03-25T19:12:52Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeSuccess_with_systemd_notifier_returning_true2759352856/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 687s time="2024-03-25T19:12:52Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:44081\"" 690s time="2024-03-25T19:12:55Z" level=info msg="Connecting to control stream at \"127.0.0.1:44081\"" 690s time="2024-03-25T19:12:55Z" level=debug msg="Control stream: starting handshake" 690s time="2024-03-25T19:12:55Z" level=info msg="wslInstanceMockService: Received incoming connection" 691s time="2024-03-25T19:12:56Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": received info: wsl_name:\"TEST_DISTRO\" id:\"ubuntu\" version_id:\"22.04\" pretty_name:\"Ubuntu 22.04.1 LTS\" hostname:\"TEST_DISTRO_HOSTNAME\"" 691s time="2024-03-25T19:12:56Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": Reserved port 39037" 691s time="2024-03-25T19:12:56Z" level=debug msg="Control stream: completed handshake" 691s time="2024-03-25T19:12:56Z" level=info msg="Connected to control stream" 691s time="2024-03-25T19:12:56Z" level=debug msg="Starting to serve gRPC requests" 691s time="2024-03-25T19:12:56Z" level=info msg="Serving gRPC requests on localhost:39037" 696s time="2024-03-25T19:13:01Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\": connected back via reserved port" 699s time="2024-03-25T19:13:04Z" level=info msg="Stopping daemon requested." 816s time="2024-03-25T19:15:01Z" level=info msg="wslInstanceMockService: Connection with \"TEST_DISTRO\" ended: rpc error: code = Canceled desc = context canceled" 816s time="2024-03-25T19:15:01Z" level=info msg="wslInstanceMockService: dropped connection" 816s === CONT TestServe/Error_because_of_context_cancelled 816s time="2024-03-25T19:15:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:35957\"" 816s time="2024-03-25T19:15:01Z" level=debug msg="Building new daemon" 819s === CONT TestServe/Error_because_WindowsHostAddress_returns_error 819s time="2024-03-25T19:15:04Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeError_because_of_context_cancelled3483797798/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 819s time="2024-03-25T19:15:04Z" level=debug msg="Building new daemon" 819s time="2024-03-25T19:15:04Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:36239\"" 822s === CONT TestServe/Error_because_of_notifier_returning_error 822s time="2024-03-25T19:15:07Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeError_because_WindowsHostAddress_returns_error2315229257/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 822s time="2024-03-25T19:15:07Z" level=debug msg="Building new daemon" 822s time="2024-03-25T19:15:07Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:33717\"" 824s time="2024-03-25T19:15:09Z" level=warning msg="Could not change systemd status: couldn't update status to systemd: mock error" 824s === CONT TestServe/No_connection_because_of_faulty_agent 824s time="2024-03-25T19:15:09Z" level=info msg="MockWindowsAgent: Remove address file returned an error: remove /tmp/TestServeError_because_of_notifier_returning_error1880092509/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 824s time="2024-03-25T19:15:09Z" level=debug msg="Building new daemon" 824s time="2024-03-25T19:15:09Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on \"127.0.0.1:36863\"" 827s time="2024-03-25T19:15:12Z" level=info msg="Connecting to control stream at \"127.0.0.1:36863\"" 827s time="2024-03-25T19:15:12Z" level=debug msg="Control stream: starting handshake" 827s time="2024-03-25T19:15:12Z" level=info msg="wslInstanceMockService: Received incoming connection" 827s time="2024-03-25T19:15:12Z" level=info msg="wslInstanceMockService: mock error: dropping stream before first Recv" 827s time="2024-03-25T19:15:12Z" level=info msg="wslInstanceMockService: dropped connection" 828s time="2024-03-25T19:15:13Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not complete handshake: could not send system info: EOF" 830s time="2024-03-25T19:15:15Z" level=info msg="Retrying connection to control stream" 831s time="2024-03-25T19:15:16Z" level=info msg="Stopping daemon requested." 831s time="2024-03-25T19:15:16Z" level=info msg="Connecting to control stream at \"127.0.0.1:36863\"" 831s time="2024-03-25T19:15:16Z" level=debug msg="Control stream: starting handshake" 831s time="2024-03-25T19:15:16Z" level=info msg="wslInstanceMockService: Received incoming connection" 831s time="2024-03-25T19:15:16Z" level=info msg="wslInstanceMockService: mock error: dropping stream before first Recv" 831s time="2024-03-25T19:15:16Z" level=info msg="wslInstanceMockService: dropped connection" 833s time="2024-03-25T19:15:17Z" level=error msg="Serve error: could not connect to Windows Agent via the control stream: could not complete handshake: could not send system info: EOF" 834s time="2024-03-25T19:15:19Z" level=info msg="Stopping daemon requested." 836s time="2024-03-25T19:15:21Z" level=info msg="Stopping daemon requested." 836s --- PASS: TestServe (0.00s) 836s --- PASS: TestServe/No_connection_because_port_file_does_not_exist (12.12s) 836s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (129.49s) 836s --- PASS: TestServe/Success (129.33s) 836s --- PASS: TestServe/Error_because_of_context_cancelled (2.15s) 836s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_error (3.12s) 836s --- PASS: TestServe/Error_because_of_notifier_returning_error (2.25s) 836s --- PASS: TestServe/No_connection_because_of_faulty_agent (12.27s) 836s PASS 836s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 340.441s 837s === RUN TestInfo 837s === PAUSE TestInfo 837s === RUN TestWslDistroName 837s === PAUSE TestWslDistroName 837s === RUN TestUserProfileDir 837s === PAUSE TestUserProfileDir 837s === RUN TestProStatus 837s === PAUSE TestProStatus 837s === RUN TestProAttach 837s === PAUSE TestProAttach 837s === RUN TestProDetach 837s === PAUSE TestProDetach 837s === RUN TestLandscapeEnable 837s === PAUSE TestLandscapeEnable 837s === RUN TestWindowsHostAddress 837s === PAUSE TestWindowsHostAddress 837s === RUN TestLandscapeDisable 837s === PAUSE TestLandscapeDisable 837s === RUN TestWithProMock 837s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 837s --- SKIP: TestWithProMock (0.00s) 837s === RUN TestWithLandscapeConfigMock 837s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 837s --- SKIP: TestWithLandscapeConfigMock (0.00s) 837s === RUN TestWithWslPathMock 837s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 837s --- SKIP: TestWithWslPathMock (0.00s) 837s === RUN TestWithWslInfoMock 837s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 837s --- SKIP: TestWithWslInfoMock (0.00s) 837s === RUN TestWithCmdExeMock 837s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 837s --- SKIP: TestWithCmdExeMock (0.00s) 837s === CONT TestInfo 837s === RUN TestInfo/Success 837s === PAUSE TestInfo/Success 837s === RUN TestInfo/Error_when_WslDistroName_fails 837s === PAUSE TestInfo/Error_when_WslDistroName_fails 837s === RUN TestInfo/Error_when_pro_status_command_fails 837s === PAUSE TestInfo/Error_when_pro_status_command_fails 837s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 837s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 837s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 837s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 837s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 837s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 837s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 837s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 837s === CONT TestInfo/Success 839s === CONT TestLandscapeDisable 839s === RUN TestLandscapeDisable/Success 839s === PAUSE TestLandscapeDisable/Success 839s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 839s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 839s === CONT TestWindowsHostAddress 839s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 839s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 839s === RUN TestWindowsHostAddress/Success_without_NAT 839s === PAUSE TestWindowsHostAddress/Success_without_NAT 839s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 839s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 839s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 839s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 839s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 839s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 839s === CONT TestLandscapeEnable 839s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 839s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 839s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 839s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 839s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 839s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 839s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 839s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 839s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 839s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 839s === RUN TestLandscapeEnable/Success 839s === PAUSE TestLandscapeEnable/Success 839s === RUN TestLandscapeEnable/Success_overriding_computer_title 839s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 839s === CONT TestProDetach 839s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 839s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 839s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 839s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 839s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 839s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 839s === RUN TestProDetach/success_on_unattached_distro 839s === PAUSE TestProDetach/success_on_unattached_distro 839s === RUN TestProDetach/success_on_attached_distro 839s === PAUSE TestProDetach/success_on_attached_distro 839s === CONT TestProAttach 839s === RUN TestProAttach/success 839s === PAUSE TestProAttach/success 839s === RUN TestProAttach/error_on_'pro_attach'_error 839s === PAUSE TestProAttach/error_on_'pro_attach'_error 839s === CONT TestProStatus 839s === RUN TestProStatus/success_on_attached_distro 839s === PAUSE TestProStatus/success_on_attached_distro 839s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 839s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 839s === RUN TestProStatus/error_on_'pro_attach'_error 839s === PAUSE TestProStatus/error_on_'pro_attach'_error 839s === RUN TestProStatus/success_on_unattached_distro 839s === PAUSE TestProStatus/success_on_unattached_distro 839s === CONT TestUserProfileDir 839s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 839s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 839s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 839s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 839s === RUN TestUserProfileDir/Error_on_wslpath_error 839s === PAUSE TestUserProfileDir/Error_on_wslpath_error 839s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 839s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 839s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 839s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 839s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 839s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 839s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 839s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 839s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 839s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 839s === RUN TestUserProfileDir/Error_on_cmd.exe_error 839s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 839s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 839s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 839s === CONT TestWslDistroName 839s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 839s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 839s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 839s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 839s === RUN TestWslDistroName/Success_using_wslpath 839s === PAUSE TestWslDistroName/Success_using_wslpath 839s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 839s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 839s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 840s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 842s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 842s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 843s === CONT TestInfo/Error_when_pro_status_command_fails 845s === CONT TestInfo/Error_when_WslDistroName_fails 845s --- PASS: TestInfo (0.00s) 845s --- PASS: TestInfo/Success (1.19s) 845s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (1.18s) 845s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (1.06s) 845s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (1.20s) 845s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (1.13s) 845s --- PASS: TestInfo/Error_when_pro_status_command_fails (1.06s) 845s --- PASS: TestInfo/Error_when_WslDistroName_fails (1.28s) 845s === CONT TestLandscapeDisable/Success 847s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 848s --- PASS: TestLandscapeDisable (0.00s) 848s --- PASS: TestLandscapeDisable/Success (1.31s) 848s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (1.16s) 848s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 849s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 851s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 851s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 853s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 854s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 855s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 856s === CONT TestWindowsHostAddress/Success_without_NAT 857s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 858s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 859s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 860s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 861s --- PASS: TestWindowsHostAddress (0.00s) 861s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (1.08s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (1.13s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (1.10s) 861s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (1.12s) 861s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (1.10s) 861s --- PASS: TestWindowsHostAddress/Success_without_NAT (1.09s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (1.16s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (1.11s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (1.02s) 861s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (1.01s) 861s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 862s === CONT TestLandscapeEnable/Success_overriding_computer_title 862s time="2024-03-25T19:15:47Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden with TEST_DISTRO" 863s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 863s === CONT TestLandscapeEnable/Success 864s system_test.go:456: testdata/TestLandscapeEnable/golden/success 864s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 865s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 867s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 867s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 867s --- PASS: TestLandscapeEnable (0.00s) 867s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (2.39s) 867s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (1.05s) 867s --- PASS: TestLandscapeEnable/Success (1.06s) 867s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (1.14s) 867s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (1.04s) 867s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 867s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 867s === CONT TestProAttach/success 868s === CONT TestProDetach/success_on_attached_distro 869s === CONT TestProDetach/success_on_unattached_distro 870s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 871s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 872s --- PASS: TestProDetach (0.00s) 872s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (0.99s) 872s --- PASS: TestProDetach/success_on_attached_distro (1.01s) 872s --- PASS: TestProDetach/success_on_unattached_distro (1.15s) 872s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (1.12s) 872s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (1.15s) 872s === CONT TestProStatus/success_on_attached_distro 873s === CONT TestProAttach/error_on_'pro_attach'_error 874s --- PASS: TestProAttach (0.00s) 874s --- PASS: TestProAttach/success (1.00s) 874s --- PASS: TestProAttach/error_on_'pro_attach'_error (0.98s) 874s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 876s === CONT TestProStatus/success_on_unattached_distro 877s === CONT TestProStatus/error_on_'pro_attach'_error 878s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 879s --- PASS: TestProStatus (0.00s) 879s --- PASS: TestProStatus/success_on_attached_distro (1.05s) 879s --- PASS: TestProStatus/success_on_unattached_distro (1.12s) 879s --- PASS: TestProStatus/error_on_'pro_attach'_error (1.01s) 879s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (0.98s) 879s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 880s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 882s === CONT TestUserProfileDir/Error_on_cmd.exe_error 884s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 884s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 884s system_test.go:209: Removing default proc/mounts 884s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 884s system_test.go:209: Removing default proc/mounts 884s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 886s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 888s === CONT TestUserProfileDir/Error_on_wslpath_error 890s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 892s --- PASS: TestUserProfileDir (0.00s) 892s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (2.10s) 892s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (2.14s) 892s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (1.19s) 892s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 892s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.01s) 892s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 892s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (2.20s) 892s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (2.04s) 892s --- PASS: TestUserProfileDir/Error_on_wslpath_error (2.07s) 892s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (2.13s) 892s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 893s === CONT TestWslDistroName/Success_using_wslpath 894s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 894s --- PASS: TestWslDistroName (0.00s) 894s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (1.04s) 894s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (1.09s) 894s --- PASS: TestWslDistroName/Success_using_wslpath (1.00s) 894s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 894s PASS 894s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 56.774s 894s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 895s === RUN TestApplyProToken 895s === PAUSE TestApplyProToken 895s === RUN TestApplyLandscapeConfig 895s === PAUSE TestApplyLandscapeConfig 895s === RUN TestWithProMock 895s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 895s --- SKIP: TestWithProMock (0.00s) 895s === RUN TestWithLandscapeConfigMock 895s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 895s --- SKIP: TestWithLandscapeConfigMock (0.00s) 895s === RUN TestWithWslPathMock 895s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 895s --- SKIP: TestWithWslPathMock (0.00s) 895s === RUN TestWithWslInfoMock 895s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 895s --- SKIP: TestWithWslInfoMock (0.00s) 895s === RUN TestWithCmdExeMock 895s mock_executables.go:576: Skipped because it is not a real test, but rather a mocked executable 895s --- SKIP: TestWithCmdExeMock (0.00s) 895s === CONT TestApplyProToken 895s === RUN TestApplyProToken/success_attaching_attached_machine 895s === PAUSE TestApplyProToken/success_attaching_attached_machine 895s === RUN TestApplyProToken/Error_calling_pro_attach 895s === PAUSE TestApplyProToken/Error_calling_pro_attach 895s === RUN TestApplyProToken/Error_calling_pro_status 895s === PAUSE TestApplyProToken/Error_calling_pro_status 895s === RUN TestApplyProToken/Error_getting_system_info 895s === PAUSE TestApplyProToken/Error_getting_system_info 895s === RUN TestApplyProToken/Error_cannot_send_info_to_stream 895s === PAUSE TestApplyProToken/Error_cannot_send_info_to_stream 895s === RUN TestApplyProToken/success_attaching_non-attached_machine 895s === PAUSE TestApplyProToken/success_attaching_non-attached_machine 895s === RUN TestApplyProToken/success_detaching_attached_machine 895s === PAUSE TestApplyProToken/success_detaching_attached_machine 895s === RUN TestApplyProToken/success_detaching_non-attached_machine 895s === PAUSE TestApplyProToken/success_detaching_non-attached_machine 895s === RUN TestApplyProToken/Error_detaching_pro 895s === PAUSE TestApplyProToken/Error_detaching_pro 895s === CONT TestApplyProToken/success_attaching_attached_machine 895s time="2024-03-25T19:16:20Z" level=debug msg="Registering gRPC WSL instance service" 895s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:38283 895s wslinstanceservice_test.go:108: Client connected to WslInstanceService 895s time="2024-03-25T19:16:20Z" level=info msg="ApplyProToken: Received token \"***\": attaching" 898s === CONT TestApplyLandscapeConfig 898s === RUN TestApplyLandscapeConfig/Success_disabling 898s === PAUSE TestApplyLandscapeConfig/Success_disabling 898s === RUN TestApplyLandscapeConfig/Error_enabling_when_landscape-config_fails 898s === PAUSE TestApplyLandscapeConfig/Error_enabling_when_landscape-config_fails 898s === RUN TestApplyLandscapeConfig/Error_disabling_when_landscape-config_--disable_fails 898s === PAUSE TestApplyLandscapeConfig/Error_disabling_when_landscape-config_--disable_fails 898s === RUN TestApplyLandscapeConfig/Success_enabling 898s === PAUSE TestApplyLandscapeConfig/Success_enabling 898s === CONT TestApplyProToken/Error_detaching_pro 898s time="2024-03-25T19:16:23Z" level=debug msg="Registering gRPC WSL instance service" 898s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:42017 898s wslinstanceservice_test.go:108: Client connected to WslInstanceService 898s time="2024-03-25T19:16:23Z" level=info msg="ApplyProToken: Received empty token: detaching" 900s === CONT TestApplyProToken/success_detaching_non-attached_machine 900s time="2024-03-25T19:16:25Z" level=debug msg="Registering gRPC WSL instance service" 900s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:45959 900s wslinstanceservice_test.go:108: Client connected to WslInstanceService 900s time="2024-03-25T19:16:25Z" level=info msg="ApplyProToken: Received empty token: detaching" 902s === CONT TestApplyProToken/success_detaching_attached_machine 902s time="2024-03-25T19:16:27Z" level=debug msg="Registering gRPC WSL instance service" 902s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:32779 902s wslinstanceservice_test.go:108: Client connected to WslInstanceService 902s time="2024-03-25T19:16:27Z" level=info msg="ApplyProToken: Received empty token: detaching" 904s === CONT TestApplyProToken/success_attaching_non-attached_machine 904s time="2024-03-25T19:16:29Z" level=debug msg="Registering gRPC WSL instance service" 904s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:41747 904s wslinstanceservice_test.go:108: Client connected to WslInstanceService 904s time="2024-03-25T19:16:29Z" level=info msg="ApplyProToken: Received token \"***\": attaching" 907s === CONT TestApplyProToken/Error_cannot_send_info_to_stream 907s time="2024-03-25T19:16:32Z" level=debug msg="Registering gRPC WSL instance service" 907s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:42367 907s wslinstanceservice_test.go:108: Client connected to WslInstanceService 907s time="2024-03-25T19:16:32Z" level=info msg="ApplyProToken: Received empty token: detaching" 909s time="2024-03-25T19:16:34Z" level=warning msg="ApplyProToken: could not send update via control stream: could not send system info: test error" 909s === CONT TestApplyProToken/Error_getting_system_info 909s time="2024-03-25T19:16:34Z" level=debug msg="Registering gRPC WSL instance service" 909s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:36539 909s wslinstanceservice_test.go:108: Client connected to WslInstanceService 909s time="2024-03-25T19:16:34Z" level=info msg="ApplyProToken: Received empty token: detaching" 912s time="2024-03-25T19:16:37Z" level=warning msg="ApplyProToken: could not send update via control stream: could not gather system info: could not read /etc/os-release: open /tmp/TestApplyProTokenError_getting_system_info3358110269/001/etc/os-release: no such file or directory" 912s === CONT TestApplyProToken/Error_calling_pro_status 912s time="2024-03-25T19:16:37Z" level=debug msg="Registering gRPC WSL instance service" 912s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:38143 912s wslinstanceservice_test.go:108: Client connected to WslInstanceService 912s time="2024-03-25T19:16:37Z" level=info msg="ApplyProToken: Received empty token: detaching" 914s time="2024-03-25T19:16:39Z" level=warning msg="ApplyProToken: could not send update via control stream: could not gather system info: could not obtain pro status: pro status: command returned error: exit status 1\nStdout:" 914s === CONT TestApplyProToken/Error_calling_pro_attach 914s time="2024-03-25T19:16:39Z" level=debug msg="Registering gRPC WSL instance service" 914s wslinstanceservice_test.go:108: Serving WslInstanceService on 127.0.0.1:35627 914s wslinstanceservice_test.go:108: Client connected to WslInstanceService 914s time="2024-03-25T19:16:39Z" level=info msg="ApplyProToken: Received token \"***\": attaching" 917s --- PASS: TestApplyProToken (0.00s) 917s --- PASS: TestApplyProToken/success_attaching_attached_machine (3.01s) 917s --- PASS: TestApplyProToken/Error_detaching_pro (1.96s) 917s --- PASS: TestApplyProToken/success_detaching_non-attached_machine (2.15s) 917s --- PASS: TestApplyProToken/success_detaching_attached_machine (2.24s) 917s --- PASS: TestApplyProToken/success_attaching_non-attached_machine (3.13s) 917s --- PASS: TestApplyProToken/Error_cannot_send_info_to_stream (2.18s) 917s --- PASS: TestApplyProToken/Error_getting_system_info (2.15s) 917s --- PASS: TestApplyProToken/Error_calling_pro_status (2.03s) 917s --- PASS: TestApplyProToken/Error_calling_pro_attach (3.14s) 917s === CONT TestApplyLandscapeConfig/Success_disabling 917s time="2024-03-25T19:16:42Z" level=debug msg="Registering gRPC WSL instance service" 917s wslinstanceservice_test.go:167: Serving WslInstanceService on 127.0.0.1:46687 917s wslinstanceservice_test.go:167: Client connected to WslInstanceService 917s time="2024-03-25T19:16:42Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 918s === CONT TestApplyLandscapeConfig/Success_enabling 918s time="2024-03-25T19:16:43Z" level=debug msg="Registering gRPC WSL instance service" 918s wslinstanceservice_test.go:167: Serving WslInstanceService on 127.0.0.1:38001 918s wslinstanceservice_test.go:167: Client connected to WslInstanceService 918s time="2024-03-25T19:16:43Z" level=info msg="ApplyLandscapeConfig: received config: registering" 919s wslinstanceservice_test.go:192: testdata/TestApplyLandscapeConfig/golden/success_enabling 919s === CONT TestApplyLandscapeConfig/Error_disabling_when_landscape-config_--disable_fails 919s time="2024-03-25T19:16:44Z" level=debug msg="Registering gRPC WSL instance service" 919s wslinstanceservice_test.go:167: Serving WslInstanceService on 127.0.0.1:44083 919s wslinstanceservice_test.go:167: Client connected to WslInstanceService 919s time="2024-03-25T19:16:44Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 920s === CONT TestApplyLandscapeConfig/Error_enabling_when_landscape-config_fails 920s time="2024-03-25T19:16:45Z" level=debug msg="Registering gRPC WSL instance service" 920s wslinstanceservice_test.go:167: Serving WslInstanceService on 127.0.0.1:32789 920s wslinstanceservice_test.go:167: Client connected to WslInstanceService 920s time="2024-03-25T19:16:45Z" level=info msg="ApplyLandscapeConfig: received config: registering" 921s --- PASS: TestApplyLandscapeConfig (0.00s) 921s --- PASS: TestApplyLandscapeConfig/Success_disabling (1.07s) 921s --- PASS: TestApplyLandscapeConfig/Success_enabling (1.11s) 921s --- PASS: TestApplyLandscapeConfig/Error_disabling_when_landscape-config_--disable_fails (1.05s) 921s --- PASS: TestApplyLandscapeConfig/Error_enabling_when_landscape-config_fails (1.00s) 921s PASS 921s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/wslinstanceservice 26.225s 921s autopkgtest [19:16:46]: test command1: -----------------------] 922s autopkgtest [19:16:47]: test command1: - - - - - - - - - - results - - - - - - - - - - 922s command1 PASS 923s autopkgtest [19:16:48]: @@@@@@@@@@@@@@@@@@@@ summary 923s command1 PASS 934s Creating nova instance adt-noble-ppc64el-wsl-pro-service-20240325-190124-juju-7f2275-prod-proposed-migration-environment-3 from image adt/ubuntu-noble-ppc64el-server-20240325.img (UUID ce50e202-ac12-4562-879d-419903f0141e)...