0s autopkgtest [08:24:57]: starting date and time: 2024-04-19 08:24:57+0000 0s autopkgtest [08:24:57]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 0s autopkgtest [08:24:57]: host juju-7f2275-prod-proposed-migration-environment-3; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.xnr8fd12/out --timeout-copy=6000 --setup-commands /home/ubuntu/autopkgtest-cloud/worker-config-production/setup-canonical.sh --apt-pocket=proposed=src:wsl-pro-service --apt-upgrade wsl-pro-service --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=wsl-pro-service/0.1.4 -- ssh -s /home/ubuntu/autopkgtest/ssh-setup/nova -- --flavor autopkgtest --security-groups autopkgtest-juju-7f2275-prod-proposed-migration-environment-3@bos03-arm64-9.secgroup --name adt-noble-arm64-wsl-pro-service-20240419-082457-juju-7f2275-prod-proposed-migration-environment-3-b57fbb3c-5d31-435c-a201-b9f96391c1dc --image adt/ubuntu-noble-arm64-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/ 73s autopkgtest [08:26:10]: testbed dpkg architecture: arm64 74s autopkgtest [08:26:11]: testbed apt version: 2.7.14build2 74s autopkgtest [08:26:11]: @@@@@@@@@@@@@@@@@@@@ test bed setup 74s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 74s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [297 kB] 75s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [55.6 kB] 75s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [12.3 kB] 75s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 75s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 Packages [134 kB] 75s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main arm64 c-n-f Metadata [3144 B] 75s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 Packages [102 kB] 75s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted arm64 c-n-f Metadata [116 B] 75s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 Packages [422 kB] 76s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe arm64 c-n-f Metadata [8528 B] 76s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse arm64 c-n-f Metadata [116 B] 77s Fetched 1153 kB in 2s (595 kB/s) 77s Reading package lists... 79s Reading package lists...Setting LLMNR support level "yes" for "2", but the global support level is "no". 80s 80s Building dependency tree... 80s Reading state information... 80s Calculating upgrade... 81s The following packages will be upgraded: 81s apport apport-core-dump-handler initramfs-tools initramfs-tools-bin 81s initramfs-tools-core libkeyutils1 libnetplan1 libnuma1 libunwind8 make 81s man-db netcat-openbsd netplan-generator netplan.io numactl python3-apport 81s python3-netplan python3-problem-report 81s 18 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 81s Need to get 2142 kB of archives. 81s After this operation, 1024 B of additional disk space will be used. 81s Get:1 http://ftpmaster.internal/ubuntu noble/main arm64 python3-problem-report all 2.28.1-0ubuntu1 [23.8 kB] 81s Get:2 http://ftpmaster.internal/ubuntu noble/main arm64 python3-apport all 2.28.1-0ubuntu1 [92.1 kB] 81s Get:3 http://ftpmaster.internal/ubuntu noble/main arm64 apport-core-dump-handler all 2.28.1-0ubuntu1 [16.8 kB] 81s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 apport all 2.28.1-0ubuntu1 [83.5 kB] 81s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 libkeyutils1 arm64 1.6.3-3build1 [9654 B] 81s Get:6 http://ftpmaster.internal/ubuntu noble/main arm64 netplan-generator arm64 1.0-2ubuntu1 [58.9 kB] 81s Get:7 http://ftpmaster.internal/ubuntu noble/main arm64 python3-netplan arm64 1.0-2ubuntu1 [21.5 kB] 81s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 initramfs-tools all 0.142ubuntu25 [9054 B] 81s Get:9 http://ftpmaster.internal/ubuntu noble/main arm64 initramfs-tools-core all 0.142ubuntu25 [50.1 kB] 81s Get:10 http://ftpmaster.internal/ubuntu noble/main arm64 initramfs-tools-bin arm64 0.142ubuntu25 [20.7 kB] 81s Get:11 http://ftpmaster.internal/ubuntu noble/main arm64 netplan.io arm64 1.0-2ubuntu1 [65.8 kB] 81s Get:12 http://ftpmaster.internal/ubuntu noble/main arm64 libnetplan1 arm64 1.0-2ubuntu1 [119 kB] 82s Get:13 http://ftpmaster.internal/ubuntu noble/main arm64 netcat-openbsd arm64 1.226-1ubuntu2 [43.8 kB] 82s Get:14 http://ftpmaster.internal/ubuntu noble/main arm64 libnuma1 arm64 2.0.18-1build1 [23.6 kB] 82s Get:15 http://ftpmaster.internal/ubuntu noble/main arm64 man-db arm64 2.12.0-4build2 [1232 kB] 82s Get:16 http://ftpmaster.internal/ubuntu noble/main arm64 libunwind8 arm64 1.6.2-3build1 [53.5 kB] 82s Get:17 http://ftpmaster.internal/ubuntu noble/main arm64 make arm64 4.3-4.1build2 [178 kB] 82s Get:18 http://ftpmaster.internal/ubuntu noble/main arm64 numactl arm64 2.0.18-1build1 [39.5 kB] 83s Preconfiguring packages ... 83s Fetched 2142 kB in 2s (1242 kB/s) 83s (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 ... 112118 files and directories currently installed.) 83s Preparing to unpack .../00-python3-problem-report_2.28.1-0ubuntu1_all.deb ... 83s Unpacking python3-problem-report (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 83s Preparing to unpack .../01-python3-apport_2.28.1-0ubuntu1_all.deb ... 83s Unpacking python3-apport (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 84s Preparing to unpack .../02-apport-core-dump-handler_2.28.1-0ubuntu1_all.deb ... 84s Unpacking apport-core-dump-handler (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 84s Preparing to unpack .../03-apport_2.28.1-0ubuntu1_all.deb ... 84s Unpacking apport (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 84s Preparing to unpack .../04-libkeyutils1_1.6.3-3build1_arm64.deb ... 84s Unpacking libkeyutils1:arm64 (1.6.3-3build1) over (1.6.3-3) ... 84s Preparing to unpack .../05-netplan-generator_1.0-2ubuntu1_arm64.deb ... 84s Adding 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 84s Unpacking netplan-generator (1.0-2ubuntu1) over (1.0-2build1) ... 84s Preparing to unpack .../06-python3-netplan_1.0-2ubuntu1_arm64.deb ... 84s Unpacking python3-netplan (1.0-2ubuntu1) over (1.0-2build1) ... 84s Preparing to unpack .../07-initramfs-tools_0.142ubuntu25_all.deb ... 84s Unpacking initramfs-tools (0.142ubuntu25) over (0.142ubuntu24) ... 84s Preparing to unpack .../08-initramfs-tools-core_0.142ubuntu25_all.deb ... 84s Unpacking initramfs-tools-core (0.142ubuntu25) over (0.142ubuntu24) ... 84s Preparing to unpack .../09-initramfs-tools-bin_0.142ubuntu25_arm64.deb ... 84s Unpacking initramfs-tools-bin (0.142ubuntu25) over (0.142ubuntu24) ... 84s Preparing to unpack .../10-netplan.io_1.0-2ubuntu1_arm64.deb ... 84s Unpacking netplan.io (1.0-2ubuntu1) over (1.0-2build1) ... 84s Preparing to unpack .../11-libnetplan1_1.0-2ubuntu1_arm64.deb ... 84s Unpacking libnetplan1:arm64 (1.0-2ubuntu1) over (1.0-2build1) ... 84s Preparing to unpack .../12-netcat-openbsd_1.226-1ubuntu2_arm64.deb ... 84s Unpacking netcat-openbsd (1.226-1ubuntu2) over (1.226-1ubuntu1) ... 84s Preparing to unpack .../13-libnuma1_2.0.18-1build1_arm64.deb ... 84s Unpacking libnuma1:arm64 (2.0.18-1build1) over (2.0.18-1) ... 84s Preparing to unpack .../14-man-db_2.12.0-4build2_arm64.deb ... 84s Unpacking man-db (2.12.0-4build2) over (2.12.0-4build1) ... 84s Preparing to unpack .../15-libunwind8_1.6.2-3build1_arm64.deb ... 84s Unpacking libunwind8:arm64 (1.6.2-3build1) over (1.6.2-3) ... 84s Preparing to unpack .../16-make_4.3-4.1build2_arm64.deb ... 84s Unpacking make (4.3-4.1build2) over (4.3-4.1build1) ... 84s Preparing to unpack .../17-numactl_2.0.18-1build1_arm64.deb ... 84s Unpacking numactl (2.0.18-1build1) over (2.0.18-1) ... 84s Setting up libkeyutils1:arm64 (1.6.3-3build1) ... 84s Setting up python3-problem-report (2.28.1-0ubuntu1) ... 85s Setting up netcat-openbsd (1.226-1ubuntu2) ... 85s Setting up libnetplan1:arm64 (1.0-2ubuntu1) ... 85s Setting up man-db (2.12.0-4build2) ... 85s Updating database of manual pages ... 87s man-db.service is a disabled or a static unit not running, not starting it. 87s Setting up libunwind8:arm64 (1.6.2-3build1) ... 87s Setting up python3-apport (2.28.1-0ubuntu1) ... 87s Setting up make (4.3-4.1build2) ... 87s Setting up libnuma1:arm64 (2.0.18-1build1) ... 87s Setting up python3-netplan (1.0-2ubuntu1) ... 87s Setting up netplan-generator (1.0-2ubuntu1) ... 87s Removing 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 87s Setting up initramfs-tools-bin (0.142ubuntu25) ... 87s Setting up numactl (2.0.18-1build1) ... 87s Setting up netplan.io (1.0-2ubuntu1) ... 87s Setting up initramfs-tools-core (0.142ubuntu25) ... 87s Setting up initramfs-tools (0.142ubuntu25) ... 87s update-initramfs: deferring update (trigger activated) 87s Setting up apport-core-dump-handler (2.28.1-0ubuntu1) ... 88s Setting up apport (2.28.1-0ubuntu1) ... 88s Installing new version of config file /etc/apport/crashdb.conf ... 89s apport-autoreport.service is a disabled or a static unit not running, not starting it. 89s Processing triggers for dbus (1.14.10-4ubuntu4) ... 89s Processing triggers for libc-bin (2.39-0ubuntu8) ... 89s Processing triggers for initramfs-tools (0.142ubuntu25) ... 89s update-initramfs: Generating /boot/initrd.img-6.8.0-22-generic 89s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 102s System running in EFI mode, skipping. 103s Reading package lists... 103s Building dependency tree... 103s Reading state information... 103s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 104s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 104s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 104s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 105s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 106s Reading package lists... 106s Reading package lists... 106s Building dependency tree... 106s Reading state information... 106s Calculating upgrade... 107s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 107s Reading package lists... 107s Building dependency tree... 107s Reading state information... 108s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 109s autopkgtest [08:26:46]: rebooting testbed after setup commands that affected boot 267s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 274s autopkgtest [08:29:31]: testbed running kernel: Linux 6.8.0-22-generic #22-Ubuntu SMP PREEMPT_DYNAMIC Fri Apr 5 02:52:09 UTC 2024 278s autopkgtest [08:29:35]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 282s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/universe wsl-pro-service 0.1.4 (dsc) [1420 B] 282s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe wsl-pro-service 0.1.4 (tar) [1762 kB] 282s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 282s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 282s gpgv: Can't check signature: No public key 282s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 283s autopkgtest [08:29:40]: testing package wsl-pro-service version 0.1.4 283s autopkgtest [08:29:40]: build not needed 374s autopkgtest [08:31:11]: test command1: preparing testbed 376s Reading package lists... 376s Building dependency tree... 376s Reading state information... 377s Starting pkgProblemResolver with broken count: 0 377s Starting 2 pkgProblemResolver with broken count: 0 377s Done 378s The following additional packages will be installed: 378s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 378s cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu debhelper debugedit dh-apport 378s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 378s g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13 378s gcc-13-aarch64-linux-gnu gcc-aarch64-linux-gnu gettext golang-1.22-go 378s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 378s libasan8 libatomic1 libcc1-0 libdebhelper-perl 378s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libhwasan0 libisl23 378s libitm1 liblsan0 libmpc3 libstdc++-13-dev libsub-override-perl libtool 378s libtsan2 libubsan1 m4 po-debconf 378s Suggested packages: 378s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 378s cpp-13-doc dh-make gcc-13-doc gcc-multilib manpages-dev flex bison gdb 378s gcc-doc gdb-aarch64-linux-gnu gettext-doc libasprintf-dev libgettextpo-dev 378s bzr | brz git mercurial subversion libstdc++-13-doc libtool-doc gfortran 378s | fortran95-compiler gcj-jdk m4-doc libmail-box-perl 378s Recommended packages: 378s pkg-config libarchive-cpio-perl libltdl-dev libmail-sendmail-perl 378s The following NEW packages will be installed: 378s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 378s cpp cpp-13 cpp-13-aarch64-linux-gnu cpp-aarch64-linux-gnu debhelper 378s debugedit dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ 378s g++-13 g++-13-aarch64-linux-gnu g++-aarch64-linux-gnu gcc gcc-13 378s gcc-13-aarch64-linux-gnu gcc-aarch64-linux-gnu gettext golang-1.22-go 378s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 378s libasan8 libatomic1 libcc1-0 libdebhelper-perl 378s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libhwasan0 libisl23 378s libitm1 liblsan0 libmpc3 libstdc++-13-dev libsub-override-perl libtool 378s libtsan2 libubsan1 m4 po-debconf 378s 0 upgraded, 51 newly installed, 0 to remove and 0 not upgraded. 378s Need to get 106 MB/106 MB of archives. 378s After this operation, 441 MB of additional disk space will be used. 378s Get:1 /tmp/autopkgtest.vEIyWy/1-autopkgtest-satdep.deb autopkgtest-satdep arm64 0 [764 B] 379s Get:2 http://ftpmaster.internal/ubuntu noble/main arm64 m4 arm64 1.4.19-4build1 [240 kB] 379s Get:3 http://ftpmaster.internal/ubuntu noble/main arm64 autoconf all 2.71-3 [339 kB] 379s Get:4 http://ftpmaster.internal/ubuntu noble/main arm64 autotools-dev all 20220109.1 [44.9 kB] 379s Get:5 http://ftpmaster.internal/ubuntu noble/main arm64 automake all 1:1.16.5-1.3ubuntu1 [558 kB] 380s Get:6 http://ftpmaster.internal/ubuntu noble/main arm64 autopoint all 0.21-14ubuntu2 [422 kB] 380s Get:7 http://ftpmaster.internal/ubuntu noble/main arm64 libisl23 arm64 0.26-3build1 [669 kB] 380s Get:8 http://ftpmaster.internal/ubuntu noble/main arm64 libmpc3 arm64 1.3.1-1build1 [56.4 kB] 380s Get:9 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [10.3 MB] 383s Get:10 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-13 arm64 13.2.0-23ubuntu4 [1032 B] 383s Get:11 http://ftpmaster.internal/ubuntu noble/main arm64 cpp-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [5316 B] 383s Get:12 http://ftpmaster.internal/ubuntu noble/main arm64 cpp arm64 4:13.2.0-7ubuntu1 [22.4 kB] 383s Get:13 http://ftpmaster.internal/ubuntu noble/main arm64 libcc1-0 arm64 14-20240412-0ubuntu1 [44.7 kB] 383s Get:14 http://ftpmaster.internal/ubuntu noble/main arm64 libgomp1 arm64 14-20240412-0ubuntu1 [144 kB] 383s Get:15 http://ftpmaster.internal/ubuntu noble/main arm64 libitm1 arm64 14-20240412-0ubuntu1 [27.9 kB] 383s Get:16 http://ftpmaster.internal/ubuntu noble/main arm64 libatomic1 arm64 14-20240412-0ubuntu1 [11.4 kB] 383s Get:17 http://ftpmaster.internal/ubuntu noble/main arm64 libasan8 arm64 14-20240412-0ubuntu1 [2921 kB] 383s Get:18 http://ftpmaster.internal/ubuntu noble/main arm64 liblsan0 arm64 14-20240412-0ubuntu1 [1286 kB] 383s Get:19 http://ftpmaster.internal/ubuntu noble/main arm64 libtsan2 arm64 14-20240412-0ubuntu1 [2692 kB] 383s Get:20 http://ftpmaster.internal/ubuntu noble/main arm64 libubsan1 arm64 14-20240412-0ubuntu1 [1155 kB] 383s Get:21 http://ftpmaster.internal/ubuntu noble/main arm64 libhwasan0 arm64 14-20240412-0ubuntu1 [1604 kB] 384s Get:22 http://ftpmaster.internal/ubuntu noble/main arm64 libgcc-13-dev arm64 13.2.0-23ubuntu4 [2470 kB] 384s Get:23 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [20.1 MB] 385s Get:24 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-13 arm64 13.2.0-23ubuntu4 [472 kB] 385s Get:25 http://ftpmaster.internal/ubuntu noble/main arm64 gcc-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [1198 B] 385s Get:26 http://ftpmaster.internal/ubuntu noble/main arm64 gcc arm64 4:13.2.0-7ubuntu1 [5018 B] 385s Get:27 http://ftpmaster.internal/ubuntu noble/main arm64 libstdc++-13-dev arm64 13.2.0-23ubuntu4 [2379 kB] 385s Get:28 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13-aarch64-linux-gnu arm64 13.2.0-23ubuntu4 [11.7 MB] 385s Get:29 http://ftpmaster.internal/ubuntu noble/main arm64 g++-13 arm64 13.2.0-23ubuntu4 [14.5 kB] 385s Get:30 http://ftpmaster.internal/ubuntu noble/main arm64 g++-aarch64-linux-gnu arm64 4:13.2.0-7ubuntu1 [962 B] 385s Get:31 http://ftpmaster.internal/ubuntu noble/main arm64 g++ arm64 4:13.2.0-7ubuntu1 [1082 B] 385s Get:32 http://ftpmaster.internal/ubuntu noble/main arm64 build-essential arm64 12.10ubuntu1 [4932 B] 385s Get:33 http://ftpmaster.internal/ubuntu noble/main arm64 libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 385s Get:34 http://ftpmaster.internal/ubuntu noble/main arm64 libtool all 2.4.7-7build1 [166 kB] 385s Get:35 http://ftpmaster.internal/ubuntu noble/main arm64 dh-autoreconf all 20 [16.1 kB] 385s Get:36 http://ftpmaster.internal/ubuntu noble/main arm64 libarchive-zip-perl all 1.68-1 [90.2 kB] 385s Get:37 http://ftpmaster.internal/ubuntu noble/main arm64 libsub-override-perl all 0.10-1 [10.0 kB] 385s Get:38 http://ftpmaster.internal/ubuntu noble/main arm64 libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 385s Get:39 http://ftpmaster.internal/ubuntu noble/main arm64 dh-strip-nondeterminism all 1.13.1-1 [5362 B] 385s Get:40 http://ftpmaster.internal/ubuntu noble/main arm64 debugedit arm64 1:5.0-5build2 [45.3 kB] 385s Get:41 http://ftpmaster.internal/ubuntu noble/main arm64 dwz arm64 0.15-1build6 [113 kB] 385s Get:42 http://ftpmaster.internal/ubuntu noble/main arm64 gettext arm64 0.21-14ubuntu2 [845 kB] 385s Get:43 http://ftpmaster.internal/ubuntu noble/main arm64 intltool-debian all 0.35.0+20060710.6 [23.2 kB] 385s Get:44 http://ftpmaster.internal/ubuntu noble/main arm64 po-debconf all 1.0.21+nmu1 [233 kB] 385s Get:45 http://ftpmaster.internal/ubuntu noble/main arm64 debhelper all 13.14.1ubuntu5 [869 kB] 385s Get:46 http://ftpmaster.internal/ubuntu noble/universe arm64 dh-apport all 2.28.1-0ubuntu1 [17.1 kB] 385s Get:47 http://ftpmaster.internal/ubuntu noble/main arm64 golang-1.22-src all 1.22.2-2 [19.7 MB] 386s Get:48 http://ftpmaster.internal/ubuntu noble/main arm64 golang-1.22-go arm64 1.22.2-2 [23.6 MB] 387s Get:49 http://ftpmaster.internal/ubuntu noble/main arm64 golang-src all 2:1.22~2build1 [5078 B] 387s Get:50 http://ftpmaster.internal/ubuntu noble/main arm64 golang-go arm64 2:1.22~2build1 [43.9 kB] 387s Get:51 http://ftpmaster.internal/ubuntu noble/main arm64 dh-golang all 1.62 [25.2 kB] 388s Fetched 106 MB in 9s (12.1 MB/s) 388s Selecting previously unselected package m4. 388s (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 ... 112117 files and directories currently installed.) 388s Preparing to unpack .../00-m4_1.4.19-4build1_arm64.deb ... 388s Unpacking m4 (1.4.19-4build1) ... 388s Selecting previously unselected package autoconf. 388s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 388s Unpacking autoconf (2.71-3) ... 388s Selecting previously unselected package autotools-dev. 388s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 388s Unpacking autotools-dev (20220109.1) ... 388s Selecting previously unselected package automake. 388s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 388s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 388s Selecting previously unselected package autopoint. 388s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 388s Unpacking autopoint (0.21-14ubuntu2) ... 388s Selecting previously unselected package libisl23:arm64. 388s Preparing to unpack .../05-libisl23_0.26-3build1_arm64.deb ... 388s Unpacking libisl23:arm64 (0.26-3build1) ... 388s Selecting previously unselected package libmpc3:arm64. 388s Preparing to unpack .../06-libmpc3_1.3.1-1build1_arm64.deb ... 388s Unpacking libmpc3:arm64 (1.3.1-1build1) ... 388s Selecting previously unselected package cpp-13-aarch64-linux-gnu. 388s Preparing to unpack .../07-cpp-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 388s Unpacking cpp-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 389s Selecting previously unselected package cpp-13. 389s Preparing to unpack .../08-cpp-13_13.2.0-23ubuntu4_arm64.deb ... 389s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 389s Selecting previously unselected package cpp-aarch64-linux-gnu. 389s Preparing to unpack .../09-cpp-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 389s Unpacking cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 389s Selecting previously unselected package cpp. 389s Preparing to unpack .../10-cpp_4%3a13.2.0-7ubuntu1_arm64.deb ... 389s Unpacking cpp (4:13.2.0-7ubuntu1) ... 389s Selecting previously unselected package libcc1-0:arm64. 389s Preparing to unpack .../11-libcc1-0_14-20240412-0ubuntu1_arm64.deb ... 389s Unpacking libcc1-0:arm64 (14-20240412-0ubuntu1) ... 389s Selecting previously unselected package libgomp1:arm64. 389s Preparing to unpack .../12-libgomp1_14-20240412-0ubuntu1_arm64.deb ... 389s Unpacking libgomp1:arm64 (14-20240412-0ubuntu1) ... 389s Selecting previously unselected package libitm1:arm64. 389s Preparing to unpack .../13-libitm1_14-20240412-0ubuntu1_arm64.deb ... 389s Unpacking libitm1:arm64 (14-20240412-0ubuntu1) ... 389s Selecting previously unselected package libatomic1:arm64. 389s Preparing to unpack .../14-libatomic1_14-20240412-0ubuntu1_arm64.deb ... 389s Unpacking libatomic1:arm64 (14-20240412-0ubuntu1) ... 389s Selecting previously unselected package libasan8:arm64. 389s Preparing to unpack .../15-libasan8_14-20240412-0ubuntu1_arm64.deb ... 389s Unpacking libasan8:arm64 (14-20240412-0ubuntu1) ... 389s Selecting previously unselected package liblsan0:arm64. 390s Preparing to unpack .../16-liblsan0_14-20240412-0ubuntu1_arm64.deb ... 390s Unpacking liblsan0:arm64 (14-20240412-0ubuntu1) ... 390s Selecting previously unselected package libtsan2:arm64. 390s Preparing to unpack .../17-libtsan2_14-20240412-0ubuntu1_arm64.deb ... 390s Unpacking libtsan2:arm64 (14-20240412-0ubuntu1) ... 390s Selecting previously unselected package libubsan1:arm64. 390s Preparing to unpack .../18-libubsan1_14-20240412-0ubuntu1_arm64.deb ... 390s Unpacking libubsan1:arm64 (14-20240412-0ubuntu1) ... 390s Selecting previously unselected package libhwasan0:arm64. 390s Preparing to unpack .../19-libhwasan0_14-20240412-0ubuntu1_arm64.deb ... 390s Unpacking libhwasan0:arm64 (14-20240412-0ubuntu1) ... 390s Selecting previously unselected package libgcc-13-dev:arm64. 390s Preparing to unpack .../20-libgcc-13-dev_13.2.0-23ubuntu4_arm64.deb ... 390s Unpacking libgcc-13-dev:arm64 (13.2.0-23ubuntu4) ... 390s Selecting previously unselected package gcc-13-aarch64-linux-gnu. 390s Preparing to unpack .../21-gcc-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 390s Unpacking gcc-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 390s Selecting previously unselected package gcc-13. 390s Preparing to unpack .../22-gcc-13_13.2.0-23ubuntu4_arm64.deb ... 390s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 390s Selecting previously unselected package gcc-aarch64-linux-gnu. 390s Preparing to unpack .../23-gcc-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 391s Unpacking gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 391s Selecting previously unselected package gcc. 391s Preparing to unpack .../24-gcc_4%3a13.2.0-7ubuntu1_arm64.deb ... 391s Unpacking gcc (4:13.2.0-7ubuntu1) ... 391s Selecting previously unselected package libstdc++-13-dev:arm64. 391s Preparing to unpack .../25-libstdc++-13-dev_13.2.0-23ubuntu4_arm64.deb ... 391s Unpacking libstdc++-13-dev:arm64 (13.2.0-23ubuntu4) ... 391s Selecting previously unselected package g++-13-aarch64-linux-gnu. 391s Preparing to unpack .../26-g++-13-aarch64-linux-gnu_13.2.0-23ubuntu4_arm64.deb ... 391s Unpacking g++-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 391s Selecting previously unselected package g++-13. 391s Preparing to unpack .../27-g++-13_13.2.0-23ubuntu4_arm64.deb ... 391s Unpacking g++-13 (13.2.0-23ubuntu4) ... 391s Selecting previously unselected package g++-aarch64-linux-gnu. 391s Preparing to unpack .../28-g++-aarch64-linux-gnu_4%3a13.2.0-7ubuntu1_arm64.deb ... 391s Unpacking g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 391s Selecting previously unselected package g++. 391s Preparing to unpack .../29-g++_4%3a13.2.0-7ubuntu1_arm64.deb ... 391s Unpacking g++ (4:13.2.0-7ubuntu1) ... 391s Selecting previously unselected package build-essential. 392s Preparing to unpack .../30-build-essential_12.10ubuntu1_arm64.deb ... 392s Unpacking build-essential (12.10ubuntu1) ... 392s Selecting previously unselected package libdebhelper-perl. 392s Preparing to unpack .../31-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 392s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 392s Selecting previously unselected package libtool. 392s Preparing to unpack .../32-libtool_2.4.7-7build1_all.deb ... 392s Unpacking libtool (2.4.7-7build1) ... 392s Selecting previously unselected package dh-autoreconf. 392s Preparing to unpack .../33-dh-autoreconf_20_all.deb ... 392s Unpacking dh-autoreconf (20) ... 392s Selecting previously unselected package libarchive-zip-perl. 392s Preparing to unpack .../34-libarchive-zip-perl_1.68-1_all.deb ... 392s Unpacking libarchive-zip-perl (1.68-1) ... 392s Selecting previously unselected package libsub-override-perl. 392s Preparing to unpack .../35-libsub-override-perl_0.10-1_all.deb ... 392s Unpacking libsub-override-perl (0.10-1) ... 392s Selecting previously unselected package libfile-stripnondeterminism-perl. 392s Preparing to unpack .../36-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 392s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 392s Selecting previously unselected package dh-strip-nondeterminism. 392s Preparing to unpack .../37-dh-strip-nondeterminism_1.13.1-1_all.deb ... 392s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 392s Selecting previously unselected package debugedit. 392s Preparing to unpack .../38-debugedit_1%3a5.0-5build2_arm64.deb ... 392s Unpacking debugedit (1:5.0-5build2) ... 392s Selecting previously unselected package dwz. 392s Preparing to unpack .../39-dwz_0.15-1build6_arm64.deb ... 392s Unpacking dwz (0.15-1build6) ... 392s Selecting previously unselected package gettext. 392s Preparing to unpack .../40-gettext_0.21-14ubuntu2_arm64.deb ... 392s Unpacking gettext (0.21-14ubuntu2) ... 392s Selecting previously unselected package intltool-debian. 392s Preparing to unpack .../41-intltool-debian_0.35.0+20060710.6_all.deb ... 392s Unpacking intltool-debian (0.35.0+20060710.6) ... 392s Selecting previously unselected package po-debconf. 392s Preparing to unpack .../42-po-debconf_1.0.21+nmu1_all.deb ... 392s Unpacking po-debconf (1.0.21+nmu1) ... 393s Selecting previously unselected package debhelper. 393s Preparing to unpack .../43-debhelper_13.14.1ubuntu5_all.deb ... 393s Unpacking debhelper (13.14.1ubuntu5) ... 393s Selecting previously unselected package dh-apport. 393s Preparing to unpack .../44-dh-apport_2.28.1-0ubuntu1_all.deb ... 393s Unpacking dh-apport (2.28.1-0ubuntu1) ... 393s Selecting previously unselected package golang-1.22-src. 393s Preparing to unpack .../45-golang-1.22-src_1.22.2-2_all.deb ... 393s Unpacking golang-1.22-src (1.22.2-2) ... 395s Selecting previously unselected package golang-1.22-go. 395s Preparing to unpack .../46-golang-1.22-go_1.22.2-2_arm64.deb ... 395s Unpacking golang-1.22-go (1.22.2-2) ... 395s Selecting previously unselected package golang-src. 395s Preparing to unpack .../47-golang-src_2%3a1.22~2build1_all.deb ... 395s Unpacking golang-src (2:1.22~2build1) ... 395s Selecting previously unselected package golang-go:arm64. 395s Preparing to unpack .../48-golang-go_2%3a1.22~2build1_arm64.deb ... 395s Unpacking golang-go:arm64 (2:1.22~2build1) ... 395s Selecting previously unselected package dh-golang. 395s Preparing to unpack .../49-dh-golang_1.62_all.deb ... 395s Unpacking dh-golang (1.62) ... 395s Selecting previously unselected package autopkgtest-satdep. 395s Preparing to unpack .../50-1-autopkgtest-satdep.deb ... 395s Unpacking autopkgtest-satdep (0) ... 395s Setting up libarchive-zip-perl (1.68-1) ... 395s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 395s Setting up m4 (1.4.19-4build1) ... 395s Setting up libgomp1:arm64 (14-20240412-0ubuntu1) ... 395s Setting up dh-apport (2.28.1-0ubuntu1) ... 395s Setting up autotools-dev (20220109.1) ... 395s Setting up golang-1.22-src (1.22.2-2) ... 395s Setting up libmpc3:arm64 (1.3.1-1build1) ... 395s Setting up libatomic1:arm64 (14-20240412-0ubuntu1) ... 395s Setting up autopoint (0.21-14ubuntu2) ... 395s Setting up autoconf (2.71-3) ... 395s Setting up libubsan1:arm64 (14-20240412-0ubuntu1) ... 395s Setting up dwz (0.15-1build6) ... 395s Setting up libhwasan0:arm64 (14-20240412-0ubuntu1) ... 395s Setting up libasan8:arm64 (14-20240412-0ubuntu1) ... 396s Setting up debugedit (1:5.0-5build2) ... 396s Setting up libsub-override-perl (0.10-1) ... 396s Setting up libtsan2:arm64 (14-20240412-0ubuntu1) ... 396s Setting up libisl23:arm64 (0.26-3build1) ... 396s Setting up golang-src (2:1.22~2build1) ... 396s Setting up libcc1-0:arm64 (14-20240412-0ubuntu1) ... 396s Setting up liblsan0:arm64 (14-20240412-0ubuntu1) ... 396s Setting up libitm1:arm64 (14-20240412-0ubuntu1) ... 396s Setting up automake (1:1.16.5-1.3ubuntu1) ... 396s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 396s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 396s Setting up gettext (0.21-14ubuntu2) ... 396s Setting up cpp-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 396s Setting up golang-1.22-go (1.22.2-2) ... 396s Setting up intltool-debian (0.35.0+20060710.6) ... 396s Setting up cpp-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 396s Setting up dh-strip-nondeterminism (1.13.1-1) ... 396s Setting up libgcc-13-dev:arm64 (13.2.0-23ubuntu4) ... 396s Setting up libstdc++-13-dev:arm64 (13.2.0-23ubuntu4) ... 396s Setting up cpp-13 (13.2.0-23ubuntu4) ... 396s Setting up golang-go:arm64 (2:1.22~2build1) ... 396s Setting up po-debconf (1.0.21+nmu1) ... 396s Setting up gcc-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 396s Setting up gcc-13 (13.2.0-23ubuntu4) ... 396s Setting up cpp (4:13.2.0-7ubuntu1) ... 396s Setting up g++-13-aarch64-linux-gnu (13.2.0-23ubuntu4) ... 396s Setting up gcc-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 396s Setting up g++-13 (13.2.0-23ubuntu4) ... 396s Setting up libtool (2.4.7-7build1) ... 396s Setting up gcc (4:13.2.0-7ubuntu1) ... 396s Setting up dh-autoreconf (20) ... 396s Setting up g++-aarch64-linux-gnu (4:13.2.0-7ubuntu1) ... 396s Setting up debhelper (13.14.1ubuntu5) ... 396s Setting up g++ (4:13.2.0-7ubuntu1) ... 396s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 396s Setting up build-essential (12.10ubuntu1) ... 396s Setting up dh-golang (1.62) ... 396s Setting up autopkgtest-satdep (0) ... 396s Processing triggers for man-db (2.12.0-4build2) ... 396s Processing triggers for install-info (7.1-3build2) ... 397s Processing triggers for libc-bin (2.39-0ubuntu8) ... 401s (Reading database ... 128681 files and directories currently installed.) 401s Removing autopkgtest-satdep (0) ... 402s autopkgtest [08:31:39]: test command1: ./debian/tests/test 402s autopkgtest [08:31:39]: test command1: [----------------------- 448s === RUN TestRunSignal 448s === RUN TestRunSignal/Send_SIGINT_exits 448s INFO Starting WSL Pro Service version Dev 448s === RUN TestRunSignal/Send_SIGTERM_exits 448s INFO Starting WSL Pro Service version Dev 448s --- PASS: TestRunSignal (0.27s) 448s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 448s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.11s) 448s === RUN TestRun 448s === PAUSE TestRun 448s === CONT TestRun 448s === RUN TestRun/Run_and_exit_successfully 448s === PAUSE TestRun/Run_and_exit_successfully 448s === RUN TestRun/Run_and_return_error 448s === PAUSE TestRun/Run_and_return_error 448s === RUN TestRun/Run_and_return_usage_error 448s === PAUSE TestRun/Run_and_return_usage_error 448s === RUN TestRun/Run_and_usage_error_only_does_not_fail 448s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 448s === CONT TestRun/Run_and_exit_successfully 448s INFO Starting WSL Pro Service version Dev 448s === CONT TestRun/Run_and_usage_error_only_does_not_fail 448s INFO Starting WSL Pro Service version Dev 448s === CONT TestRun/Run_and_return_usage_error 448s INFO Starting WSL Pro Service version Dev 448s === CONT TestRun/Run_and_return_error 448s INFO Starting WSL Pro Service version Dev 448s ERROR context.Background Error requested 448s ERROR context.Background Error requested 448s --- PASS: TestRun (0.00s) 448s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 448s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 448s --- PASS: TestRun/Run_and_return_usage_error (0.54s) 448s --- PASS: TestRun/Run_and_return_error (0.54s) 448s PASS 448s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 4.806s 449s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 465s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 465s === RUN TestHelp 465s --- PASS: TestHelp (0.02s) 465s === RUN TestCompletion 465s --- PASS: TestCompletion (0.00s) 465s === RUN TestVersion 465s --- PASS: TestVersion (0.00s) 465s === RUN TestNoUsageError 465s --- PASS: TestNoUsageError (0.00s) 465s === RUN TestUsageError 465s === PAUSE TestUsageError 465s === RUN TestCanQuitWhenExecute 465s === PAUSE TestCanQuitWhenExecute 465s === RUN TestCanQuitTwice 465s === PAUSE TestCanQuitTwice 465s === RUN TestAppCanQuitWithoutExecute 465s === PAUSE TestAppCanQuitWithoutExecute 465s === RUN TestAppRunFailsOnComponentsCreationAndQuit 465s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 465s === RUN TestAppGetRootCmd 465s === PAUSE TestAppGetRootCmd 465s === RUN TestWithProMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithProMock (0.00s) 465s === RUN TestWithWslPathMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithWslPathMock (0.00s) 465s === RUN TestWithWslInfoMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithWslInfoMock (0.00s) 465s === RUN TestWithCmdExeMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithCmdExeMock (0.00s) 465s === CONT TestUsageError 465s --- PASS: TestUsageError (0.00s) 465s === CONT TestAppGetRootCmd 465s --- PASS: TestAppGetRootCmd (0.00s) 465s === CONT TestAppRunFailsOnComponentsCreationAndQuit 465s === CONT TestCanQuitTwice 465s time="2024-04-19T08:32:24Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 465s time="2024-04-19T08:32:24Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:75 New() Building new daemon" 465s time="2024-04-19T08:32:32Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 465s time="2024-04-19T08:32:32Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 465s time="2024-04-19T08:32:32Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:32Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:35Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:40669" 465s time="2024-04-19T08:32:35Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 465s time="2024-04-19T08:32:35Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 465s time="2024-04-19T08:32:35Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 465s time="2024-04-19T08:32:35Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:35Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:35Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (10.86s) 465s === CONT TestCanQuitWhenExecute 465s time="2024-04-19T08:32:35Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41505" 465s time="2024-04-19T08:32:35Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 465s time="2024-04-19T08:32:35Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:75 New() Building new daemon" 465s time="2024-04-19T08:32:38Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 465s time="2024-04-19T08:32:38Z" level=warning msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: serve error: could not receive ProAttachCmd: context canceled\ncould not receive ProAttachCmd: context canceled" 465s time="2024-04-19T08:32:38Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 465s time="2024-04-19T08:32:38Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s time="2024-04-19T08:32:38Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:38Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:38Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s time="2024-04-19T08:32:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.vEIyWy/build.m2C/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 465s time="2024-04-19T08:32:38Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:38Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:38Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s --- PASS: TestCanQuitTwice (14.12s) 465s === CONT TestAppCanQuitWithoutExecute 465s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 465s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 465s time="2024-04-19T08:32:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.vEIyWy/build.m2C/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 465s time="2024-04-19T08:32:38Z" level=warning msg="context.Background rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.vEIyWy/build.m2C/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 465s time="2024-04-19T08:32:41Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:41505" 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 465s time="2024-04-19T08:32:42Z" level=warning msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:184 (*Daemon).Serve.func1() Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:41505: connect: connection refused\"" 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 465s time="2024-04-19T08:32:42Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 465s time="2024-04-19T08:32:42Z" level=info msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 465s time="2024-04-19T08:32:42Z" level=debug msg="/tmp/autopkgtest.vEIyWy/build.m2C/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 465s --- PASS: TestCanQuitWhenExecute (7.12s) 465s PASS 465s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 20.103s 465s === RUN TestApplyProToken 465s === PAUSE TestApplyProToken 465s === RUN TestApplyLandscapeConfig 465s === PAUSE TestApplyLandscapeConfig 465s === RUN TestWithProMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithProMock (0.00s) 465s === RUN TestWithLandscapeConfigMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithLandscapeConfigMock (0.00s) 465s === RUN TestWithWslPathMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithWslPathMock (0.00s) 465s === RUN TestWithWslInfoMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithWslInfoMock (0.00s) 465s === RUN TestWithCmdExeMock 465s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 465s --- SKIP: TestWithCmdExeMock (0.00s) 465s === CONT TestApplyProToken 465s === RUN TestApplyProToken/Error_calling_pro_detach 465s === PAUSE TestApplyProToken/Error_calling_pro_detach 465s === RUN TestApplyProToken/Error_calling_pro_attach 465s === PAUSE TestApplyProToken/Error_calling_pro_attach 465s === RUN TestApplyProToken/Success_attaching 465s === PAUSE TestApplyProToken/Success_attaching 465s === RUN TestApplyProToken/Success_detaching 465s === PAUSE TestApplyProToken/Success_detaching 465s === CONT TestApplyProToken/Error_calling_pro_detach 465s === CONT TestApplyLandscapeConfig 465s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 465s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 465s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 465s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 465s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 465s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 465s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 465s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 465s === CONT TestApplyProToken/Success_detaching 465s time="2024-04-19T08:32:28Z" level=info msg="ApplyProToken: Received empty token: detaching" 465s time="2024-04-19T08:32:28Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 465s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 465s time="2024-04-19T08:32:32Z" level=info msg="ApplyLandscapeConfig: received config: registering" 465s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 465s time="2024-04-19T08:32:32Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 465s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 465s time="2024-04-19T08:32:35Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 465s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 465s time="2024-04-19T08:32:35Z" level=info msg="ApplyLandscapeConfig: received config: registering" 465s === CONT TestApplyProToken/Success_attaching 465s time="2024-04-19T08:32:38Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 465s --- PASS: TestApplyLandscapeConfig (0.00s) 465s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (2.45s) 465s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (2.84s) 465s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (2.93s) 465s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (2.82s) 465s === CONT TestApplyProToken/Error_calling_pro_attach 465s time="2024-04-19T08:32:38Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 465s --- PASS: TestApplyProToken (0.00s) 465s --- PASS: TestApplyProToken/Success_detaching (4.10s) 465s --- PASS: TestApplyProToken/Error_calling_pro_detach (4.38s) 465s --- PASS: TestApplyProToken/Success_attaching (3.94s) 465s --- PASS: TestApplyProToken/Error_calling_pro_attach (4.11s) 465s PASS 465s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 14.280s 581s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 641s === RUN TestNew 641s === PAUSE TestNew 641s === RUN TestServe 641s === PAUSE TestServe 641s === RUN TestServeAndQuit 641s === PAUSE TestServeAndQuit 641s === RUN TestReconnection 641s === PAUSE TestReconnection 641s === RUN TestWithProMock 641s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 641s --- SKIP: TestWithProMock (0.00s) 641s === RUN TestWithWslPathMock 641s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 641s --- SKIP: TestWithWslPathMock (0.00s) 641s === RUN TestWithWslInfoMock 641s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 641s --- SKIP: TestWithWslInfoMock (0.00s) 641s === RUN TestWithCmdExeMock 641s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 641s --- SKIP: TestWithCmdExeMock (0.00s) 641s === CONT TestNew 641s === RUN TestNew/Success 641s === CONT TestServeAndQuit 641s === RUN TestServeAndQuit/Success_with_graceful_quit 641s === PAUSE TestServeAndQuit/Success_with_graceful_quit 641s === RUN TestServeAndQuit/Success_with_forceful_quit 641s === PAUSE TestServeAndQuit/Success_with_forceful_quit 641s === RUN TestServeAndQuit/Success_with_double_quit 641s === PAUSE TestServeAndQuit/Success_with_double_quit 641s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 641s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 641s === CONT TestServeAndQuit/Success_with_graceful_quit 641s === PAUSE TestNew/Success 641s === RUN TestNew/Error_when_WslPath_returns_error 641s === PAUSE TestNew/Error_when_WslPath_returns_error 641s === CONT TestNew/Success 641s time="2024-04-19T08:32:43Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:32:43Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45359" 641s time="2024-04-19T08:32:43Z" level=debug msg="Building new daemon" 641s === CONT TestServe 641s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 641s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 641s === RUN TestServe/Success_with_systemd_notifier_returning_true 641s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 641s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 641s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 641s === RUN TestServe/No_connection_because_the_port_file_has_port_0 641s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 641s === RUN TestServe/No_connection_because_there_is_no_server 641s === PAUSE TestServe/No_connection_because_there_is_no_server 641s === RUN TestServe/No_connection_because_there_are_no_certificates 641s === PAUSE TestServe/No_connection_because_there_are_no_certificates 641s === RUN TestServe/Error_because_the_context_is_pre-cancelled 641s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 641s === RUN TestServe/Error_because_the_notifier_returns_an_error 641s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 641s === RUN TestServe/Success 641s === PAUSE TestServe/Success 641s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 641s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 641s === RUN TestServe/No_connection_because_the_port_file_is_empty 641s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 641s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 641s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 641s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 641s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 641s === CONT TestNew/Error_when_WslPath_returns_error 641s time="2024-04-19T08:32:48Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:32:48Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:32:48Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:32:48Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:32:50Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:45359" 641s time="2024-04-19T08:32:50Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:32:50Z" level=debug msg="Updated systemd status to \"Connected\"" 641s time="2024-04-19T08:32:50Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:32:50Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s === CONT TestReconnection 641s === RUN TestReconnection/Success_connecting_after_failing_to_connect 641s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 641s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 641s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 641s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 641s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 641s --- PASS: TestNew (0.00s) 641s --- PASS: TestNew/Success (4.97s) 641s --- PASS: TestNew/Error_when_WslPath_returns_error (5.98s) 641s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 641s time="2024-04-19T08:32:54Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:32:54Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:32:54Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:32:54Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:32:54Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33787" 641s time="2024-04-19T08:32:54Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:32:54Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:32:54Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:32:54Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:32:54Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:32:54Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:32:54Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:32:54Z" level=debug msg="All connections have now ended." 641s time="2024-04-19T08:32:54Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:32:54Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:32:54Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s === CONT TestServeAndQuit/Success_with_double_quit 641s time="2024-04-19T08:32:54Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46577" 641s time="2024-04-19T08:32:54Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:03Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:03Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:03Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:03Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:03Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:33:03Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:33:03Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:03Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s === CONT TestServeAndQuit/Success_with_forceful_quit 641s time="2024-04-19T08:33:03Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46723" 641s time="2024-04-19T08:33:03Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:04Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46577" 641s time="2024-04-19T08:33:04Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:33:04Z" level=debug msg="Updated systemd status to \"Connected\"" 641s time="2024-04-19T08:33:04Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:33:04Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s time="2024-04-19T08:33:05Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:33:05Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:33:05Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:33:05Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:33:06Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:06Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:06Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:33:06Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:06Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:33:06Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:33:06Z" level=debug msg="All connections have now ended." 641s time="2024-04-19T08:33:06Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:06Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:06Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:06Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:33:06Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:06Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:33:06Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:06Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:06Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 641s time="2024-04-19T08:33:06Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41145" 641s time="2024-04-19T08:33:06Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:07Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46723" 641s time="2024-04-19T08:33:07Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:33:07Z" level=debug msg="Updated systemd status to \"Connected\"" 641s time="2024-04-19T08:33:07Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:33:07Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s time="2024-04-19T08:33:08Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:33:08Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:33:08Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:33:08Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:33:08Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:08Z" level=info msg="Stopping active requests." 641s time="2024-04-19T08:33:08Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:33:08Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:08Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:33:08Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:33:08Z" level=debug msg="All connections have now ended." 641s time="2024-04-19T08:33:08Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:08Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:08Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:08Z" level=info msg="Daemon: connecting to Windows Agent" 641s --- PASS: TestServeAndQuit (0.00s) 641s --- PASS: TestServeAndQuit/Success_with_graceful_quit (11.29s) 641s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (8.81s) 641s --- PASS: TestServeAndQuit/Success_with_double_quit (11.46s) 641s --- PASS: TestServeAndQuit/Success_with_forceful_quit (5.77s) 641s === CONT TestServe/Error_because_the_notifier_returns_an_error 641s time="2024-04-19T08:33:08Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39161" 641s time="2024-04-19T08:33:08Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:10Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:10Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:10Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 641s time="2024-04-19T08:33:10Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35509" 641s time="2024-04-19T08:33:10Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:12Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 641s time="2024-04-19T08:33:12Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:12Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:12Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 641s time="2024-04-19T08:33:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33443" 641s time="2024-04-19T08:33:12Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:13Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:14Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35509" 641s time="2024-04-19T08:33:14Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file1134337975/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 641s time="2024-04-19T08:33:14Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:15Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:15Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:-5\": port cannot be negative" 641s time="2024-04-19T08:33:15Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:15Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:15Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:15Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_the_port_file_is_empty 641s time="2024-04-19T08:33:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44949" 641s time="2024-04-19T08:33:15Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:16Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:16Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:-5\": port cannot be negative" 641s time="2024-04-19T08:33:16Z" level=info msg="Reconnecting to Windows host in 2 seconds" 641s time="2024-04-19T08:33:16Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:16Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:16Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 641s time="2024-04-19T08:33:16Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45597" 641s time="2024-04-19T08:33:16Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:22Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:22Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"\": could not split address: missing port in address" 641s time="2024-04-19T08:33:22Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:23Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:23Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:23Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/Success 641s time="2024-04-19T08:33:23Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38619" 641s time="2024-04-19T08:33:23Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:25Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:25Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_the_port_file_does_not_exist828081748/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist828081748/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 641s time="2024-04-19T08:33:25Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:26Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:26Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestServeNo_connection_because_the_port_file_does_not_exist828081748/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist828081748/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 641s time="2024-04-19T08:33:26Z" level=info msg="Reconnecting to Windows host in 2 seconds" 641s time="2024-04-19T08:33:26Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:26Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:26Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_there_is_no_server 641s time="2024-04-19T08:33:26Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:37355" 641s time="2024-04-19T08:33:26Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:30Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:31Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:32Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38619" 641s time="2024-04-19T08:33:32Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:33:32Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s time="2024-04-19T08:33:32Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:33:34Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:37355" 641s time="2024-04-19T08:33:34Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:33:34Z" level=warning msg="Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:37355: connect: connection refused\"" 641s time="2024-04-19T08:33:34Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:34Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:34Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:34Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/Error_because_the_context_is_pre-cancelled 641s time="2024-04-19T08:33:34Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41883" 641s time="2024-04-19T08:33:34Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:35Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:33:35Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:33:35Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:33:35Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:33:36Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:36Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:36Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:33:36Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:36Z" level=debug msg="All connections have now ended." 641s time="2024-04-19T08:33:36Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:36Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:33:36Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s === CONT TestServe/No_connection_because_there_are_no_certificates 641s time="2024-04-19T08:33:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44177" 641s time="2024-04-19T08:33:36Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:42Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:42Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:42Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 641s time="2024-04-19T08:33:42Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42877" 641s time="2024-04-19T08:33:42Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:45Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:47Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:47Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:portyMcPortface\": could not parse port as an integer: strconv.Atoi: parsing \"portyMcPortface\": invalid syntax" 641s time="2024-04-19T08:33:47Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:47Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44177" 641s time="2024-04-19T08:33:47Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates2264674956/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 641s time="2024-04-19T08:33:47Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:48Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:48Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:48Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/No_connection_because_the_port_file_has_port_0 641s time="2024-04-19T08:33:48Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43695" 641s time="2024-04-19T08:33:48Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:48Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:48Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:48Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:48Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:portyMcPortface\": could not parse port as an integer: strconv.Atoi: parsing \"portyMcPortface\": invalid syntax" 641s time="2024-04-19T08:33:48Z" level=info msg="Reconnecting to Windows host in 2 seconds" 641s time="2024-04-19T08:33:48Z" level=debug msg="All connections have now ended." 641s === CONT TestServe/Success_with_systemd_notifier_returning_true 641s time="2024-04-19T08:33:48Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38301" 641s time="2024-04-19T08:33:48Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:52Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:52Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:0\": port cannot be zero" 641s time="2024-04-19T08:33:52Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:33:53Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:33:53Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:33:53Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:33:53Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:0\": port cannot be zero" 641s time="2024-04-19T08:33:53Z" level=info msg="Reconnecting to Windows host in 2 seconds" 641s time="2024-04-19T08:33:53Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:33:53Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:33:53Z" level=debug msg="All connections have now ended." 641s === CONT TestReconnection/Success_connecting_after_failing_to_connect 641s time="2024-04-19T08:33:53Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:33:58Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38301" 641s time="2024-04-19T08:33:58Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:33:58Z" level=debug msg="Updated systemd status to \"Connected\"" 641s time="2024-04-19T08:33:58Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:33:58Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s time="2024-04-19T08:34:01Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:34:01Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:34:01Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:34:01Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_failing_to_connect1892852174/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect1892852174/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 641s time="2024-04-19T08:34:01Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:34:01Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:34:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35223" 641s time="2024-04-19T08:34:01Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:34:01Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:34:01Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:34:01Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:34:02Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:34:02Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:34:03Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:34:03Z" level=info msg="Waiting for active requests to close." 641s time="2024-04-19T08:34:03Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:34:03Z" level=info msg="Reconnecting to Windows host in 1 seconds" 641s time="2024-04-19T08:34:03Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:34:03Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:34:03Z" level=debug msg="All connections have now ended." 641s time="2024-04-19T08:34:03Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:34:03Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:34:03Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s --- PASS: TestServe (0.00s) 641s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (4.31s) 641s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (3.44s) 641s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (5.33s) 641s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (3.68s) 641s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (7.74s) 641s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (10.49s) 641s --- PASS: TestServe/No_connection_because_there_is_no_server (8.20s) 641s --- PASS: TestServe/Success (12.79s) 641s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (7.37s) 641s --- PASS: TestServe/No_connection_because_there_are_no_certificates (11.91s) 641s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (6.51s) 641s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (5.76s) 641s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (15.06s) 641s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 641s time="2024-04-19T08:34:03Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:34:05Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35223" 641s time="2024-04-19T08:34:05Z" level=info msg="Daemon: completed connection to Windows Agent" 641s time="2024-04-19T08:34:05Z" level=debug msg="Updated systemd status to \"Connected\"" 641s time="2024-04-19T08:34:05Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 641s time="2024-04-19T08:34:05Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 641s time="2024-04-19T08:34:16Z" level=debug msg="Server: sent preface messages to all streams" 641s time="2024-04-19T08:34:16Z" level=info msg="MockWindowsAgent: Connected ready" 641s time="2024-04-19T08:34:16Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 641s time="2024-04-19T08:34:16Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 641s time="2024-04-19T08:34:16Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:34:16Z" level=info msg="Stopping daemon requested." 641s time="2024-04-19T08:34:16Z" level=info msg="Stopping active requests." 641s time="2024-04-19T08:34:16Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:34:16Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 641s time="2024-04-19T08:34:16Z" level=warning msg="Daemon: disconnected from Windows host" 641s time="2024-04-19T08:34:16Z" level=info msg="Reconnecting to Windows host in 2 seconds" 641s time="2024-04-19T08:34:16Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 641s time="2024-04-19T08:34:16Z" level=debug msg="Updated systemd status to \"Stopped\"" 641s time="2024-04-19T08:34:16Z" level=debug msg="All connections have now ended." 641s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 641s time="2024-04-19T08:34:16Z" level=debug msg="Building new daemon" 641s time="2024-04-19T08:34:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36595" 641s time="2024-04-19T08:34:21Z" level=debug msg="Ready state sent to systemd" 641s time="2024-04-19T08:34:21Z" level=info msg="Daemon: connecting to Windows Agent" 641s time="2024-04-19T08:34:21Z" level=debug msg="Updated systemd status to \"Connecting\"" 641s time="2024-04-19T08:34:24Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:36595" 642s time="2024-04-19T08:34:24Z" level=info msg="Daemon: completed connection to Windows Agent" 642s time="2024-04-19T08:34:24Z" level=debug msg="Updated systemd status to \"Connected\"" 642s time="2024-04-19T08:34:24Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 642s time="2024-04-19T08:34:24Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 642s time="2024-04-19T08:34:24Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34331" 642s time="2024-04-19T08:34:24Z" level=debug msg="Ready state sent to systemd" 642s time="2024-04-19T08:34:24Z" level=info msg="Daemon: connecting to Windows Agent" 642s time="2024-04-19T08:34:24Z" level=debug msg="Updated systemd status to \"Connecting\"" 642s time="2024-04-19T08:34:27Z" level=debug msg="Server: sent preface messages to all streams" 642s time="2024-04-19T08:34:27Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s time="2024-04-19T08:34:27Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:34:27Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:34:27Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34331" 642s time="2024-04-19T08:34:27Z" level=info msg="Daemon: completed connection to Windows Agent" 642s time="2024-04-19T08:34:27Z" level=debug msg="Updated systemd status to \"Connected\"" 642s time="2024-04-19T08:34:27Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 642s time="2024-04-19T08:34:27Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 642s time="2024-04-19T08:34:29Z" level=debug msg="Server: sent preface messages to all streams" 642s time="2024-04-19T08:34:29Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s time="2024-04-19T08:34:29Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:34:29Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:34:29Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:29Z" level=warning msg="Daemon: disconnected from Windows host" 642s time="2024-04-19T08:34:29Z" level=info msg="Reconnecting to Windows host in 1 seconds" 642s time="2024-04-19T08:34:29Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 642s time="2024-04-19T08:34:29Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:29Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:29Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34809" 642s time="2024-04-19T08:34:30Z" level=info msg="Daemon: connecting to Windows Agent" 642s time="2024-04-19T08:34:30Z" level=debug msg="Updated systemd status to \"Connecting\"" 642s time="2024-04-19T08:34:32Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34809" 642s time="2024-04-19T08:34:32Z" level=info msg="Daemon: completed connection to Windows Agent" 642s time="2024-04-19T08:34:32Z" level=debug msg="Updated systemd status to \"Connected\"" 642s time="2024-04-19T08:34:32Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 642s time="2024-04-19T08:34:32Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 642s time="2024-04-19T08:34:33Z" level=debug msg="Server: sent preface messages to all streams" 642s time="2024-04-19T08:34:33Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s time="2024-04-19T08:34:33Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:34:33Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:34:33Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:33Z" level=info msg="Stopping daemon requested." 642s time="2024-04-19T08:34:33Z" level=info msg="Stopping active requests." 642s time="2024-04-19T08:34:33Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:33Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:34:33Z" level=warning msg="Daemon: disconnected from Windows host" 642s time="2024-04-19T08:34:33Z" level=info msg="Reconnecting to Windows host in 2 seconds" 642s time="2024-04-19T08:34:33Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 642s time="2024-04-19T08:34:33Z" level=debug msg="Updated systemd status to \"Stopped\"" 642s time="2024-04-19T08:34:33Z" level=debug msg="All connections have now ended." 642s time="2024-04-19T08:35:32Z" level=warning msg="Daemon: disconnected from Windows host" 642s time="2024-04-19T08:35:32Z" level=info msg="Daemon: connecting to Windows Agent" 642s time="2024-04-19T08:35:32Z" level=debug msg="Updated systemd status to \"Connecting\"" 642s time="2024-04-19T08:35:32Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:35:32Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:35:32Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:35:32Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43005" 642s time="2024-04-19T08:35:33Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:36595" 642s time="2024-04-19T08:35:33Z" level=info msg="Daemon: completed connection to Windows Agent" 642s time="2024-04-19T08:35:33Z" level=debug msg="Updated systemd status to \"Connected\"" 642s time="2024-04-19T08:35:33Z" level=warning msg="Daemon: disconnected from Windows host: could not start serving: could not connect: could not connect to GRPC service: rpc error: code = Unavailable desc = connection error: desc = \"transport: Error while dialing: dial tcp 127.0.0.1:36595: connect: connection refused\"" 642s time="2024-04-19T08:35:33Z" level=info msg="Reconnecting to Windows host in 1 seconds" 642s time="2024-04-19T08:35:33Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 642s time="2024-04-19T08:35:34Z" level=info msg="Daemon: connecting to Windows Agent" 642s time="2024-04-19T08:35:34Z" level=debug msg="Updated systemd status to \"Connecting\"" 642s time="2024-04-19T08:35:35Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43005" 642s time="2024-04-19T08:35:35Z" level=info msg="Daemon: completed connection to Windows Agent" 642s time="2024-04-19T08:35:35Z" level=debug msg="Updated systemd status to \"Connected\"" 642s time="2024-04-19T08:35:36Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 642s time="2024-04-19T08:35:36Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 642s time="2024-04-19T08:35:37Z" level=debug msg="Server: sent preface messages to all streams" 642s time="2024-04-19T08:35:37Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s time="2024-04-19T08:35:37Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:35:37Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:35:38Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:35:38Z" level=warning msg="Daemon: disconnected from Windows host" 642s time="2024-04-19T08:35:38Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:35:38Z" level=info msg="Reconnecting to Windows host in 2 seconds" 642s time="2024-04-19T08:35:38Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 642s time="2024-04-19T08:35:38Z" level=info msg="Stopping daemon requested." 642s time="2024-04-19T08:35:38Z" level=info msg="Stopping active requests." 642s time="2024-04-19T08:35:38Z" level=debug msg="Updated systemd status to \"Stopped\"" 642s time="2024-04-19T08:35:38Z" level=debug msg="All connections have now ended." 642s time="2024-04-19T08:35:38Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s --- PASS: TestReconnection (0.01s) 642s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (22.89s) 642s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (17.03s) 642s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (94.32s) 642s PASS 642s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 174.720s 642s === RUN TestConnect 642s === PAUSE TestConnect 642s === RUN TestSendAndRecv 642s --- PASS: TestSendAndRecv (0.41s) 642s === RUN TestServe 642s === PAUSE TestServe 642s === RUN TestStop 642s === PAUSE TestStop 642s === RUN TestWithProMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithProMock (0.00s) 642s === RUN TestWithWslPathMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithWslPathMock (0.00s) 642s === RUN TestWithWslInfoMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithWslInfoMock (0.00s) 642s === RUN TestWithCmdExeMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithCmdExeMock (0.00s) 642s === CONT TestConnect 642s === RUN TestConnect/Success 642s === PAUSE TestConnect/Success 642s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 642s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 642s === CONT TestConnect/Success 642s === CONT TestStop 642s time="2024-04-19T08:32:45Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35933" 642s === CONT TestServe 642s time="2024-04-19T08:32:45Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:32835" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: Connected ready" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 642s time="2024-04-19T08:32:48Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 642s --- PASS: TestServe (10.92s) 642s time="2024-04-19T08:32:56Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:32:56Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:32:56Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 642s time="2024-04-19T08:33:01Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:33:01Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 642s time="2024-04-19T08:33:01Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 642s --- PASS: TestStop (16.88s) 642s --- PASS: TestConnect (0.00s) 642s --- PASS: TestConnect/Success (0.37s) 642s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.07s) 642s PASS 642s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 31.943s 642s === RUN TestInfo 642s === PAUSE TestInfo 642s === RUN TestWslDistroName 642s === PAUSE TestWslDistroName 642s === RUN TestUserProfileDir 642s === PAUSE TestUserProfileDir 642s === RUN TestProStatus 642s === PAUSE TestProStatus 642s === RUN TestProAttach 642s === PAUSE TestProAttach 642s === RUN TestProDetach 642s === PAUSE TestProDetach 642s === RUN TestLandscapeEnable 642s === PAUSE TestLandscapeEnable 642s === RUN TestWindowsHostAddress 642s === PAUSE TestWindowsHostAddress 642s === RUN TestLandscapeDisable 642s === PAUSE TestLandscapeDisable 642s === RUN TestRealBackend 642s === PAUSE TestRealBackend 642s === RUN TestWithProMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithProMock (0.00s) 642s === RUN TestWithLandscapeConfigMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithLandscapeConfigMock (0.00s) 642s === RUN TestWithWslPathMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithWslPathMock (0.00s) 642s === RUN TestWithWslInfoMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithWslInfoMock (0.00s) 642s === RUN TestWithCmdExeMock 642s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 642s --- SKIP: TestWithCmdExeMock (0.00s) 642s === CONT TestInfo 642s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 642s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 642s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 642s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 642s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 642s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 642s === RUN TestInfo/Success 642s === PAUSE TestInfo/Success 642s === RUN TestInfo/Error_when_WslDistroName_fails 642s === PAUSE TestInfo/Error_when_WslDistroName_fails 642s === RUN TestInfo/Error_when_pro_status_command_fails 642s === PAUSE TestInfo/Error_when_pro_status_command_fails 642s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 642s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 642s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 642s === CONT TestUserProfileDir 642s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 642s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 642s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 642s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 642s === RUN TestUserProfileDir/Error_on_wslpath_error 642s === PAUSE TestUserProfileDir/Error_on_wslpath_error 642s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 642s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 642s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 642s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 642s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 642s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 642s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 642s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 642s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 642s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 642s === RUN TestUserProfileDir/Error_on_cmd.exe_error 642s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 642s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 642s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 642s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 642s system_test.go:205: Removing default proc/mounts 642s === CONT TestRealBackend 642s --- PASS: TestRealBackend (0.00s) 642s === CONT TestLandscapeDisable 642s === RUN TestLandscapeDisable/Success 642s === PAUSE TestLandscapeDisable/Success 642s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 642s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 642s === CONT TestWindowsHostAddress 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 642s === RUN TestWindowsHostAddress/Success_without_NAT 642s === PAUSE TestWindowsHostAddress/Success_without_NAT 642s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 642s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 642s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 642s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 642s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 642s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 642s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 642s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 642s === CONT TestLandscapeEnable 642s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 642s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 642s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 642s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 642s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 642s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 642s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 642s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 642s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 642s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 642s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 642s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 642s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 642s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 642s === RUN TestLandscapeEnable/Success 642s === PAUSE TestLandscapeEnable/Success 642s === RUN TestLandscapeEnable/Success_overriding_computer_title 642s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 642s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 642s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 642s === CONT TestProDetach 642s === RUN TestProDetach/success_on_unattached_distro 642s === PAUSE TestProDetach/success_on_unattached_distro 642s === RUN TestProDetach/success_on_attached_distro 642s === PAUSE TestProDetach/success_on_attached_distro 642s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 642s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 642s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 642s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 642s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 642s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 642s === CONT TestProAttach 642s === RUN TestProAttach/success 642s === PAUSE TestProAttach/success 642s === RUN TestProAttach/error_on_'pro_attach'_error 642s === PAUSE TestProAttach/error_on_'pro_attach'_error 642s === CONT TestProStatus 642s === RUN TestProStatus/success_on_unattached_distro 642s === PAUSE TestProStatus/success_on_unattached_distro 642s === RUN TestProStatus/success_on_attached_distro 642s === PAUSE TestProStatus/success_on_attached_distro 642s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 642s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 642s === RUN TestProStatus/error_on_'pro_attach'_error 642s === PAUSE TestProStatus/error_on_'pro_attach'_error 642s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 642s === CONT TestUserProfileDir/Error_on_cmd.exe_error 642s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 642s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 642s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 642s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 642s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 642s === CONT TestUserProfileDir/Error_on_wslpath_error 642s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 642s system_test.go:205: Removing default proc/mounts 642s === CONT TestInfo/Error_when_WslDistroName_fails 642s === CONT TestWslDistroName 642s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 642s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 642s === RUN TestWslDistroName/Success_using_wslpath 642s === PAUSE TestWslDistroName/Success_using_wslpath 642s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 642s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 642s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 642s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 642s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 642s --- PASS: TestUserProfileDir (0.00s) 642s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 642s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (2.23s) 642s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 642s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (5.94s) 642s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (4.73s) 642s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (5.31s) 642s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (4.26s) 642s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 642s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (4.15s) 642s --- PASS: TestUserProfileDir/Error_on_wslpath_error (8.15s) 642s === CONT TestInfo/Error_when_pro_status_command_fails 642s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 642s === CONT TestInfo/Success 642s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 642s === CONT TestLandscapeDisable/Success 642s --- PASS: TestInfo (0.00s) 642s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (3.60s) 642s --- PASS: TestInfo/Error_when_WslDistroName_fails (4.32s) 642s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (3.59s) 642s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (2.14s) 642s --- PASS: TestInfo/Error_when_pro_status_command_fails (2.28s) 642s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (1.59s) 642s --- PASS: TestInfo/Success (1.75s) 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 642s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 642s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 642s --- PASS: TestLandscapeDisable (0.00s) 642s --- PASS: TestLandscapeDisable/Success (2.64s) 642s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (2.04s) 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 642s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 642s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 642s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 642s === CONT TestWindowsHostAddress/Success_without_NAT 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 642s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 642s === CONT TestProDetach/success_on_unattached_distro 642s --- PASS: TestWindowsHostAddress (0.00s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (1.95s) 642s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (4.75s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (5.45s) 642s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (2.51s) 642s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (2.84s) 642s --- PASS: TestWindowsHostAddress/Success_without_NAT (1.96s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (2.28s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (2.86s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (12.31s) 642s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (10.96s) 642s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 642s time="2024-04-19T08:34:16Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 642s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 642s === CONT TestLandscapeEnable/Success_overriding_computer_title 642s time="2024-04-19T08:34:21Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 642s === CONT TestLandscapeEnable/Success 642s === NAME TestLandscapeEnable/Success_overriding_computer_title 642s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 642s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 642s === NAME TestLandscapeEnable/Success 642s system_test.go:456: testdata/TestLandscapeEnable/golden/success 642s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 642s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 642s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 642s time="2024-04-19T08:34:24Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 642s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 642s === NAME TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 642s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 642s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 642s === CONT TestProAttach/success 642s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 642s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 642s === NAME TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 642s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 642s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 642s --- PASS: TestLandscapeEnable (0.00s) 642s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (2.13s) 642s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (4.28s) 642s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (3.22s) 642s --- PASS: TestLandscapeEnable/Success (3.21s) 642s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 642s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.02s) 642s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (2.53s) 642s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (2.65s) 642s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 642s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (3.12s) 642s === CONT TestProDetach/success_on_attached_distro 642s === CONT TestProStatus/success_on_unattached_distro 642s --- PASS: TestProDetach (0.00s) 642s --- PASS: TestProDetach/success_on_unattached_distro (5.19s) 642s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (1.13s) 642s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (1.59s) 642s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (1.89s) 642s --- PASS: TestProDetach/success_on_attached_distro (1.70s) 642s === CONT TestProAttach/error_on_'pro_attach'_error 642s === CONT TestProStatus/error_on_'pro_attach'_error 642s --- PASS: TestProAttach (0.00s) 642s --- PASS: TestProAttach/success (1.79s) 642s --- PASS: TestProAttach/error_on_'pro_attach'_error (1.50s) 642s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 642s === CONT TestProStatus/success_on_attached_distro 642s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 642s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 642s --- PASS: TestProStatus (0.04s) 642s --- PASS: TestProStatus/success_on_unattached_distro (1.75s) 642s --- PASS: TestProStatus/error_on_'pro_attach'_error (1.13s) 642s --- PASS: TestProStatus/success_on_attached_distro (1.34s) 642s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (1.43s) 642s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 642s === CONT TestWslDistroName/Success_using_wslpath 642s --- PASS: TestWslDistroName (0.00s) 642s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 642s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (1.07s) 642s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (1.21s) 642s --- PASS: TestWslDistroName/Success_using_wslpath (0.80s) 642s PASS 642s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 78.083s 642s autopkgtest [08:35:39]: test command1: -----------------------] 643s command1 PASS 643s autopkgtest [08:35:40]: test command1: - - - - - - - - - - results - - - - - - - - - - 644s autopkgtest [08:35:41]: @@@@@@@@@@@@@@@@@@@@ summary 644s command1 PASS 655s Creating nova instance adt-noble-arm64-wsl-pro-service-20240419-082457-juju-7f2275-prod-proposed-migration-environment-3-b57fbb3c-5d31-435c-a201-b9f96391c1dc from image adt/ubuntu-noble-arm64-server-20240418.img (UUID c141647a-22ea-481a-97c5-a98894f31daa)...