0s autopkgtest [08:26:22]: starting date and time: 2024-04-19 08:26:22+0000 0s autopkgtest [08:26:22]: git checkout: 43bc6cdf gitlab-ci: do not include the salsa pipeline 0s autopkgtest [08:26:22]: host juju-7f2275-prod-proposed-migration-environment-2; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.1wsrwihj/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-2@bos01-s390x-18.secgroup --name adt-noble-s390x-wsl-pro-service-20240419-082622-juju-7f2275-prod-proposed-migration-environment-2-df3d246b-01e1-4eba-961d-a780a1f86ec8 --image adt/ubuntu-noble-s390x-server --keyname testbed-juju-7f2275-prod-proposed-migration-environment-2 --net-id=net_prod-proposed-migration -e TERM=linux -e ''"'"'http_proxy=http://squid.internal:3128'"'"'' -e ''"'"'https_proxy=http://squid.internal:3128'"'"'' -e ''"'"'no_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com'"'"'' --mirror=http://us.ports.ubuntu.com/ubuntu-ports/ 138s autopkgtest [08:28:40]: testbed dpkg architecture: s390x 138s autopkgtest [08:28:40]: testbed apt version: 2.7.14build2 138s autopkgtest [08:28:40]: @@@@@@@@@@@@@@@@@@@@ test bed setup 138s Get:1 http://ftpmaster.internal/ubuntu noble-proposed InRelease [117 kB] 139s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/multiverse Sources [2340 B] 139s Get:3 http://ftpmaster.internal/ubuntu noble-proposed/universe Sources [297 kB] 139s Get:4 http://ftpmaster.internal/ubuntu noble-proposed/restricted Sources [12.3 kB] 139s Get:5 http://ftpmaster.internal/ubuntu noble-proposed/main Sources [55.6 kB] 139s Get:6 http://ftpmaster.internal/ubuntu noble-proposed/main s390x Packages [95.3 kB] 139s Get:7 http://ftpmaster.internal/ubuntu noble-proposed/main s390x c-n-f Metadata [3032 B] 139s Get:8 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x Packages [976 B] 139s Get:9 http://ftpmaster.internal/ubuntu noble-proposed/restricted s390x c-n-f Metadata [116 B] 139s Get:10 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x Packages [383 kB] 139s Get:11 http://ftpmaster.internal/ubuntu noble-proposed/universe s390x c-n-f Metadata [7292 B] 139s Get:12 http://ftpmaster.internal/ubuntu noble-proposed/multiverse s390x c-n-f Metadata [116 B] 140s Fetched 974 kB in 1s (1039 kB/s) 140s Reading package lists... 142s sh: 4: dhclient: not found 143s Reading package lists... 143s Building dependency tree... 143s Reading state information... 143s Calculating upgrade... 144s The following packages will be upgraded: 144s apport apport-core-dump-handler initramfs-tools initramfs-tools-bin 144s initramfs-tools-core libkeyutils1 libnetplan1 libnuma1 make man-db 144s netcat-openbsd netplan-generator netplan.io numactl python3-apport 144s python3-netplan python3-problem-report 144s 17 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 144s Need to get 2137 kB of archives. 144s After this operation, 1024 B of additional disk space will be used. 144s Get:1 http://ftpmaster.internal/ubuntu noble/main s390x python3-problem-report all 2.28.1-0ubuntu1 [23.8 kB] 144s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x python3-apport all 2.28.1-0ubuntu1 [92.1 kB] 144s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x apport-core-dump-handler all 2.28.1-0ubuntu1 [16.8 kB] 144s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x apport all 2.28.1-0ubuntu1 [83.5 kB] 144s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x libkeyutils1 s390x 1.6.3-3build1 [9556 B] 144s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x netplan-generator s390x 1.0-2ubuntu1 [59.2 kB] 144s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x python3-netplan s390x 1.0-2ubuntu1 [23.0 kB] 144s Get:8 http://ftpmaster.internal/ubuntu noble/main s390x initramfs-tools all 0.142ubuntu25 [9054 B] 144s Get:9 http://ftpmaster.internal/ubuntu noble/main s390x initramfs-tools-core all 0.142ubuntu25 [50.1 kB] 144s Get:10 http://ftpmaster.internal/ubuntu noble/main s390x initramfs-tools-bin s390x 0.142ubuntu25 [20.6 kB] 144s Get:11 http://ftpmaster.internal/ubuntu noble/main s390x netplan.io s390x 1.0-2ubuntu1 [65.8 kB] 144s Get:12 http://ftpmaster.internal/ubuntu noble/main s390x libnetplan1 s390x 1.0-2ubuntu1 [126 kB] 144s Get:13 http://ftpmaster.internal/ubuntu noble/main s390x netcat-openbsd s390x 1.226-1ubuntu2 [44.0 kB] 144s Get:14 http://ftpmaster.internal/ubuntu noble/main s390x libnuma1 s390x 2.0.18-1build1 [25.1 kB] 144s Get:15 http://ftpmaster.internal/ubuntu noble/main s390x man-db s390x 2.12.0-4build2 [1253 kB] 144s Get:16 http://ftpmaster.internal/ubuntu noble/main s390x make s390x 4.3-4.1build2 [196 kB] 144s Get:17 http://ftpmaster.internal/ubuntu noble/main s390x numactl s390x 2.0.18-1build1 [40.0 kB] 145s Preconfiguring packages ... 145s Fetched 2137 kB in 1s (2815 kB/s) 145s (Reading database ... (Reading database ... 5% (Reading database ... 10% (Reading database ... 15% (Reading database ... 20% (Reading database ... 25% (Reading database ... 30% (Reading database ... 35% (Reading database ... 40% (Reading database ... 45% (Reading database ... 50% (Reading database ... 55% (Reading database ... 60% (Reading database ... 65% (Reading database ... 70% (Reading database ... 75% (Reading database ... 80% (Reading database ... 85% (Reading database ... 90% (Reading database ... 95% (Reading database ... 100% (Reading database ... 78323 files and directories currently installed.) 145s Preparing to unpack .../00-python3-problem-report_2.28.1-0ubuntu1_all.deb ... 145s Unpacking python3-problem-report (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 145s Preparing to unpack .../01-python3-apport_2.28.1-0ubuntu1_all.deb ... 145s Unpacking python3-apport (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 145s Preparing to unpack .../02-apport-core-dump-handler_2.28.1-0ubuntu1_all.deb ... 145s Unpacking apport-core-dump-handler (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 145s Preparing to unpack .../03-apport_2.28.1-0ubuntu1_all.deb ... 145s Unpacking apport (2.28.1-0ubuntu1) over (2.28.0-0ubuntu1) ... 146s Preparing to unpack .../04-libkeyutils1_1.6.3-3build1_s390x.deb ... 146s Unpacking libkeyutils1:s390x (1.6.3-3build1) over (1.6.3-3) ... 146s Preparing to unpack .../05-netplan-generator_1.0-2ubuntu1_s390x.deb ... 146s Adding 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 146s Unpacking netplan-generator (1.0-2ubuntu1) over (1.0-2build1) ... 146s Preparing to unpack .../06-python3-netplan_1.0-2ubuntu1_s390x.deb ... 146s Unpacking python3-netplan (1.0-2ubuntu1) over (1.0-2build1) ... 146s Preparing to unpack .../07-initramfs-tools_0.142ubuntu25_all.deb ... 146s Unpacking initramfs-tools (0.142ubuntu25) over (0.142ubuntu24) ... 146s Preparing to unpack .../08-initramfs-tools-core_0.142ubuntu25_all.deb ... 146s Unpacking initramfs-tools-core (0.142ubuntu25) over (0.142ubuntu24) ... 146s Preparing to unpack .../09-initramfs-tools-bin_0.142ubuntu25_s390x.deb ... 146s Unpacking initramfs-tools-bin (0.142ubuntu25) over (0.142ubuntu24) ... 146s Preparing to unpack .../10-netplan.io_1.0-2ubuntu1_s390x.deb ... 146s Unpacking netplan.io (1.0-2ubuntu1) over (1.0-2build1) ... 146s Preparing to unpack .../11-libnetplan1_1.0-2ubuntu1_s390x.deb ... 146s Unpacking libnetplan1:s390x (1.0-2ubuntu1) over (1.0-2build1) ... 146s Preparing to unpack .../12-netcat-openbsd_1.226-1ubuntu2_s390x.deb ... 146s Unpacking netcat-openbsd (1.226-1ubuntu2) over (1.226-1ubuntu1) ... 146s Preparing to unpack .../13-libnuma1_2.0.18-1build1_s390x.deb ... 146s Unpacking libnuma1:s390x (2.0.18-1build1) over (2.0.18-1) ... 146s Preparing to unpack .../14-man-db_2.12.0-4build2_s390x.deb ... 146s Unpacking man-db (2.12.0-4build2) over (2.12.0-4build1) ... 146s Preparing to unpack .../15-make_4.3-4.1build2_s390x.deb ... 146s Unpacking make (4.3-4.1build2) over (4.3-4.1build1) ... 146s Preparing to unpack .../16-numactl_2.0.18-1build1_s390x.deb ... 146s Unpacking numactl (2.0.18-1build1) over (2.0.18-1) ... 146s Setting up libkeyutils1:s390x (1.6.3-3build1) ... 146s Setting up python3-problem-report (2.28.1-0ubuntu1) ... 146s Setting up netcat-openbsd (1.226-1ubuntu2) ... 146s Setting up libnetplan1:s390x (1.0-2ubuntu1) ... 146s Setting up man-db (2.12.0-4build2) ... 146s Updating database of manual pages ... 148s man-db.service is a disabled or a static unit not running, not starting it. 148s Setting up python3-apport (2.28.1-0ubuntu1) ... 148s Setting up make (4.3-4.1build2) ... 148s Setting up libnuma1:s390x (2.0.18-1build1) ... 148s Setting up python3-netplan (1.0-2ubuntu1) ... 148s Setting up netplan-generator (1.0-2ubuntu1) ... 148s Removing 'diversion of /lib/systemd/system-generators/netplan to /lib/systemd/system-generators/netplan.usr-is-merged by netplan-generator' 148s Setting up initramfs-tools-bin (0.142ubuntu25) ... 148s Setting up numactl (2.0.18-1build1) ... 148s Setting up netplan.io (1.0-2ubuntu1) ... 148s Setting up initramfs-tools-core (0.142ubuntu25) ... 148s Setting up initramfs-tools (0.142ubuntu25) ... 148s update-initramfs: deferring update (trigger activated) 148s Setting up apport-core-dump-handler (2.28.1-0ubuntu1) ... 149s Setting up apport (2.28.1-0ubuntu1) ... 149s Installing new version of config file /etc/apport/crashdb.conf ... 150s apport-autoreport.service is a disabled or a static unit not running, not starting it. 150s Processing triggers for dbus (1.14.10-4ubuntu4) ... 150s Processing triggers for libc-bin (2.39-0ubuntu8) ... 150s Processing triggers for initramfs-tools (0.142ubuntu25) ... 150s update-initramfs: Generating /boot/initrd.img-6.8.0-22-generic 150s W: No lz4 in /usr/bin:/sbin:/bin, using gzip 155s Using config file '/etc/zipl.conf' 155s Building bootmap in '/boot' 155s Adding IPL section 'ubuntu' (default) 155s Preparing boot device for LD-IPL: sda. 155s Done. 155s Reading package lists... 155s Building dependency tree... 155s Reading state information... 156s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 156s Hit:1 http://ftpmaster.internal/ubuntu noble InRelease 156s Hit:2 http://ftpmaster.internal/ubuntu noble-updates InRelease 156s Hit:3 http://ftpmaster.internal/ubuntu noble-security InRelease 156s Hit:4 http://ftpmaster.internal/ubuntu noble-proposed InRelease 158s Reading package lists... 158s Reading package lists... 158s Building dependency tree... 158s Reading state information... 158s Calculating upgrade... 159s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 159s Reading package lists... 159s Building dependency tree... 159s Reading state information... 159s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 160s autopkgtest [08:29:02]: rebooting testbed after setup commands that affected boot 202s autopkgtest-virt-ssh: WARNING: ssh connection failed. Retrying in 3 seconds... 208s autopkgtest [08:29:50]: testbed running kernel: Linux 6.8.0-22-generic #22-Ubuntu SMP Thu Apr 4 21:54:17 UTC 2024 211s autopkgtest [08:29:53]: @@@@@@@@@@@@@@@@@@@@ apt-source wsl-pro-service 214s Get:1 http://ftpmaster.internal/ubuntu noble-proposed/universe wsl-pro-service 0.1.4 (dsc) [1420 B] 214s Get:2 http://ftpmaster.internal/ubuntu noble-proposed/universe wsl-pro-service 0.1.4 (tar) [1762 kB] 214s gpgv: Signature made Fri Apr 19 05:59:17 2024 UTC 214s gpgv: using DSA key DD00EF8F4D23C30D78EC990998B24A9CE4AC208E 214s gpgv: Can't check signature: No public key 214s dpkg-source: warning: cannot verify inline signature for ./wsl-pro-service_0.1.4.dsc: no acceptable signature found 214s autopkgtest [08:29:56]: testing package wsl-pro-service version 0.1.4 215s autopkgtest [08:29:57]: build not needed 323s autopkgtest [08:31:45]: test command1: preparing testbed 324s Reading package lists... 324s Building dependency tree... 324s Reading state information... 324s Starting pkgProblemResolver with broken count: 0 324s Starting 2 pkgProblemResolver with broken count: 0 324s Done 325s The following additional packages will be installed: 325s autoconf automake autopoint autotools-dev build-essential cpp cpp-13 325s cpp-13-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit dh-apport 325s dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 325s g++-13-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-13 gcc-13-base 325s gcc-13-s390x-linux-gnu gcc-s390x-linux-gnu gettext golang-1.22-go 325s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 325s libasan8 libatomic1 libcc1-0 libdebhelper-perl 325s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 325s libmpc3 libstdc++-13-dev libsub-override-perl libtool libubsan1 m4 325s po-debconf 325s Suggested packages: 325s autoconf-archive gnu-standards autoconf-doc cpp-doc gcc-13-locales 325s cpp-13-doc dh-make g++-multilib g++-13-multilib gcc-13-doc gcc-multilib 325s manpages-dev flex bison gdb gcc-doc gcc-13-multilib gdb-s390x-linux-gnu 325s gettext-doc libasprintf-dev libgettextpo-dev bzr | brz git mercurial 325s subversion libstdc++-13-doc libtool-doc gfortran | fortran95-compiler 325s gcj-jdk m4-doc libmail-box-perl 325s Recommended packages: 325s pkg-config libarchive-cpio-perl libltdl-dev libmail-sendmail-perl 325s The following NEW packages will be installed: 325s autoconf automake autopkgtest-satdep autopoint autotools-dev build-essential 325s cpp cpp-13 cpp-13-s390x-linux-gnu cpp-s390x-linux-gnu debhelper debugedit 325s dh-apport dh-autoreconf dh-golang dh-strip-nondeterminism dwz g++ g++-13 325s g++-13-s390x-linux-gnu g++-s390x-linux-gnu gcc gcc-13 gcc-13-base 325s gcc-13-s390x-linux-gnu gcc-s390x-linux-gnu gettext golang-1.22-go 325s golang-1.22-src golang-go golang-src intltool-debian libarchive-zip-perl 325s libasan8 libatomic1 libcc1-0 libdebhelper-perl 325s libfile-stripnondeterminism-perl libgcc-13-dev libgomp1 libisl23 libitm1 325s libmpc3 libstdc++-13-dev libsub-override-perl libtool libubsan1 m4 325s po-debconf 325s 0 upgraded, 49 newly installed, 0 to remove and 0 not upgraded. 325s Need to get 98.4 MB/98.4 MB of archives. 325s After this operation, 410 MB of additional disk space will be used. 325s Get:1 /tmp/autopkgtest.aslIha/1-autopkgtest-satdep.deb autopkgtest-satdep s390x 0 [764 B] 325s Get:2 http://ftpmaster.internal/ubuntu noble/main s390x m4 s390x 1.4.19-4build1 [256 kB] 325s Get:3 http://ftpmaster.internal/ubuntu noble/main s390x autoconf all 2.71-3 [339 kB] 325s Get:4 http://ftpmaster.internal/ubuntu noble/main s390x autotools-dev all 20220109.1 [44.9 kB] 325s Get:5 http://ftpmaster.internal/ubuntu noble/main s390x automake all 1:1.16.5-1.3ubuntu1 [558 kB] 325s Get:6 http://ftpmaster.internal/ubuntu noble/main s390x autopoint all 0.21-14ubuntu2 [422 kB] 325s Get:7 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13-base s390x 13.2.0-23ubuntu4 [48.9 kB] 325s Get:8 http://ftpmaster.internal/ubuntu noble/main s390x libisl23 s390x 0.26-3build1 [713 kB] 326s Get:9 http://ftpmaster.internal/ubuntu noble/main s390x libmpc3 s390x 1.3.1-1build1 [58.4 kB] 326s Get:10 http://ftpmaster.internal/ubuntu noble/main s390x cpp-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [9939 kB] 326s Get:11 http://ftpmaster.internal/ubuntu noble/main s390x cpp-13 s390x 13.2.0-23ubuntu4 [1030 B] 326s Get:12 http://ftpmaster.internal/ubuntu noble/main s390x cpp-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [5308 B] 326s Get:13 http://ftpmaster.internal/ubuntu noble/main s390x cpp s390x 4:13.2.0-7ubuntu1 [22.4 kB] 326s Get:14 http://ftpmaster.internal/ubuntu noble/main s390x libcc1-0 s390x 14-20240412-0ubuntu1 [49.9 kB] 326s Get:15 http://ftpmaster.internal/ubuntu noble/main s390x libgomp1 s390x 14-20240412-0ubuntu1 [151 kB] 326s Get:16 http://ftpmaster.internal/ubuntu noble/main s390x libitm1 s390x 14-20240412-0ubuntu1 [31.1 kB] 326s Get:17 http://ftpmaster.internal/ubuntu noble/main s390x libatomic1 s390x 14-20240412-0ubuntu1 [9398 B] 326s Get:18 http://ftpmaster.internal/ubuntu noble/main s390x libasan8 s390x 14-20240412-0ubuntu1 [3003 kB] 327s Get:19 http://ftpmaster.internal/ubuntu noble/main s390x libubsan1 s390x 14-20240412-0ubuntu1 [1188 kB] 327s Get:20 http://ftpmaster.internal/ubuntu noble/main s390x libgcc-13-dev s390x 13.2.0-23ubuntu4 [1004 kB] 327s Get:21 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [19.1 MB] 328s Get:22 http://ftpmaster.internal/ubuntu noble/main s390x gcc-13 s390x 13.2.0-23ubuntu4 [472 kB] 328s Get:23 http://ftpmaster.internal/ubuntu noble/main s390x gcc-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [1208 B] 328s Get:24 http://ftpmaster.internal/ubuntu noble/main s390x gcc s390x 4:13.2.0-7ubuntu1 [5014 B] 328s Get:25 http://ftpmaster.internal/ubuntu noble/main s390x libstdc++-13-dev s390x 13.2.0-23ubuntu4 [2494 kB] 328s Get:26 http://ftpmaster.internal/ubuntu noble/main s390x g++-13-s390x-linux-gnu s390x 13.2.0-23ubuntu4 [11.3 MB] 329s Get:27 http://ftpmaster.internal/ubuntu noble/main s390x g++-13 s390x 13.2.0-23ubuntu4 [14.5 kB] 329s Get:28 http://ftpmaster.internal/ubuntu noble/main s390x g++-s390x-linux-gnu s390x 4:13.2.0-7ubuntu1 [956 B] 329s Get:29 http://ftpmaster.internal/ubuntu noble/main s390x g++ s390x 4:13.2.0-7ubuntu1 [1096 B] 329s Get:30 http://ftpmaster.internal/ubuntu noble/main s390x build-essential s390x 12.10ubuntu1 [4930 B] 329s Get:31 http://ftpmaster.internal/ubuntu noble/main s390x libdebhelper-perl all 13.14.1ubuntu5 [89.8 kB] 329s Get:32 http://ftpmaster.internal/ubuntu noble/main s390x libtool all 2.4.7-7build1 [166 kB] 329s Get:33 http://ftpmaster.internal/ubuntu noble/main s390x dh-autoreconf all 20 [16.1 kB] 329s Get:34 http://ftpmaster.internal/ubuntu noble/main s390x libarchive-zip-perl all 1.68-1 [90.2 kB] 329s Get:35 http://ftpmaster.internal/ubuntu noble/main s390x libsub-override-perl all 0.10-1 [10.0 kB] 329s Get:36 http://ftpmaster.internal/ubuntu noble/main s390x libfile-stripnondeterminism-perl all 1.13.1-1 [18.1 kB] 329s Get:37 http://ftpmaster.internal/ubuntu noble/main s390x dh-strip-nondeterminism all 1.13.1-1 [5362 B] 329s Get:38 http://ftpmaster.internal/ubuntu noble/main s390x debugedit s390x 1:5.0-5build2 [50.5 kB] 329s Get:39 http://ftpmaster.internal/ubuntu noble/main s390x dwz s390x 0.15-1build6 [122 kB] 329s Get:40 http://ftpmaster.internal/ubuntu noble/main s390x gettext s390x 0.21-14ubuntu2 [915 kB] 329s Get:41 http://ftpmaster.internal/ubuntu noble/main s390x intltool-debian all 0.35.0+20060710.6 [23.2 kB] 329s Get:42 http://ftpmaster.internal/ubuntu noble/main s390x po-debconf all 1.0.21+nmu1 [233 kB] 329s Get:43 http://ftpmaster.internal/ubuntu noble/main s390x debhelper all 13.14.1ubuntu5 [869 kB] 329s Get:44 http://ftpmaster.internal/ubuntu noble/universe s390x dh-apport all 2.28.1-0ubuntu1 [17.1 kB] 329s Get:45 http://ftpmaster.internal/ubuntu noble/main s390x golang-1.22-src all 1.22.2-2 [19.7 MB] 331s Get:46 http://ftpmaster.internal/ubuntu noble/main s390x golang-1.22-go s390x 1.22.2-2 [24.7 MB] 332s Get:47 http://ftpmaster.internal/ubuntu noble/main s390x golang-src all 2:1.22~2build1 [5078 B] 332s Get:48 http://ftpmaster.internal/ubuntu noble/main s390x golang-go s390x 2:1.22~2build1 [44.0 kB] 332s Get:49 http://ftpmaster.internal/ubuntu noble/main s390x dh-golang all 1.62 [25.2 kB] 333s Fetched 98.4 MB in 8s (12.7 MB/s) 333s Selecting previously unselected package m4. 333s (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 ... 78322 files and directories currently installed.) 333s Preparing to unpack .../00-m4_1.4.19-4build1_s390x.deb ... 333s Unpacking m4 (1.4.19-4build1) ... 333s Selecting previously unselected package autoconf. 333s Preparing to unpack .../01-autoconf_2.71-3_all.deb ... 333s Unpacking autoconf (2.71-3) ... 333s Selecting previously unselected package autotools-dev. 333s Preparing to unpack .../02-autotools-dev_20220109.1_all.deb ... 333s Unpacking autotools-dev (20220109.1) ... 333s Selecting previously unselected package automake. 333s Preparing to unpack .../03-automake_1%3a1.16.5-1.3ubuntu1_all.deb ... 333s Unpacking automake (1:1.16.5-1.3ubuntu1) ... 333s Selecting previously unselected package autopoint. 333s Preparing to unpack .../04-autopoint_0.21-14ubuntu2_all.deb ... 333s Unpacking autopoint (0.21-14ubuntu2) ... 333s Selecting previously unselected package gcc-13-base:s390x. 333s Preparing to unpack .../05-gcc-13-base_13.2.0-23ubuntu4_s390x.deb ... 333s Unpacking gcc-13-base:s390x (13.2.0-23ubuntu4) ... 333s Selecting previously unselected package libisl23:s390x. 333s Preparing to unpack .../06-libisl23_0.26-3build1_s390x.deb ... 333s Unpacking libisl23:s390x (0.26-3build1) ... 333s Selecting previously unselected package libmpc3:s390x. 333s Preparing to unpack .../07-libmpc3_1.3.1-1build1_s390x.deb ... 333s Unpacking libmpc3:s390x (1.3.1-1build1) ... 333s Selecting previously unselected package cpp-13-s390x-linux-gnu. 333s Preparing to unpack .../08-cpp-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 333s Unpacking cpp-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 333s Selecting previously unselected package cpp-13. 334s Preparing to unpack .../09-cpp-13_13.2.0-23ubuntu4_s390x.deb ... 334s Unpacking cpp-13 (13.2.0-23ubuntu4) ... 334s Selecting previously unselected package cpp-s390x-linux-gnu. 334s Preparing to unpack .../10-cpp-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 334s Unpacking cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 334s Selecting previously unselected package cpp. 334s Preparing to unpack .../11-cpp_4%3a13.2.0-7ubuntu1_s390x.deb ... 334s Unpacking cpp (4:13.2.0-7ubuntu1) ... 334s Selecting previously unselected package libcc1-0:s390x. 334s Preparing to unpack .../12-libcc1-0_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libcc1-0:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libgomp1:s390x. 334s Preparing to unpack .../13-libgomp1_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libgomp1:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libitm1:s390x. 334s Preparing to unpack .../14-libitm1_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libitm1:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libatomic1:s390x. 334s Preparing to unpack .../15-libatomic1_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libatomic1:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libasan8:s390x. 334s Preparing to unpack .../16-libasan8_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libasan8:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libubsan1:s390x. 334s Preparing to unpack .../17-libubsan1_14-20240412-0ubuntu1_s390x.deb ... 334s Unpacking libubsan1:s390x (14-20240412-0ubuntu1) ... 334s Selecting previously unselected package libgcc-13-dev:s390x. 334s Preparing to unpack .../18-libgcc-13-dev_13.2.0-23ubuntu4_s390x.deb ... 334s Unpacking libgcc-13-dev:s390x (13.2.0-23ubuntu4) ... 334s Selecting previously unselected package gcc-13-s390x-linux-gnu. 334s Preparing to unpack .../19-gcc-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 334s Unpacking gcc-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 334s Selecting previously unselected package gcc-13. 334s Preparing to unpack .../20-gcc-13_13.2.0-23ubuntu4_s390x.deb ... 334s Unpacking gcc-13 (13.2.0-23ubuntu4) ... 334s Selecting previously unselected package gcc-s390x-linux-gnu. 334s Preparing to unpack .../21-gcc-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 334s Unpacking gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 334s Selecting previously unselected package gcc. 334s Preparing to unpack .../22-gcc_4%3a13.2.0-7ubuntu1_s390x.deb ... 334s Unpacking gcc (4:13.2.0-7ubuntu1) ... 334s Selecting previously unselected package libstdc++-13-dev:s390x. 334s Preparing to unpack .../23-libstdc++-13-dev_13.2.0-23ubuntu4_s390x.deb ... 334s Unpacking libstdc++-13-dev:s390x (13.2.0-23ubuntu4) ... 335s Selecting previously unselected package g++-13-s390x-linux-gnu. 335s Preparing to unpack .../24-g++-13-s390x-linux-gnu_13.2.0-23ubuntu4_s390x.deb ... 335s Unpacking g++-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 335s Selecting previously unselected package g++-13. 335s Preparing to unpack .../25-g++-13_13.2.0-23ubuntu4_s390x.deb ... 335s Unpacking g++-13 (13.2.0-23ubuntu4) ... 335s Selecting previously unselected package g++-s390x-linux-gnu. 335s Preparing to unpack .../26-g++-s390x-linux-gnu_4%3a13.2.0-7ubuntu1_s390x.deb ... 335s Unpacking g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 335s Selecting previously unselected package g++. 335s Preparing to unpack .../27-g++_4%3a13.2.0-7ubuntu1_s390x.deb ... 335s Unpacking g++ (4:13.2.0-7ubuntu1) ... 335s Selecting previously unselected package build-essential. 335s Preparing to unpack .../28-build-essential_12.10ubuntu1_s390x.deb ... 335s Unpacking build-essential (12.10ubuntu1) ... 335s Selecting previously unselected package libdebhelper-perl. 335s Preparing to unpack .../29-libdebhelper-perl_13.14.1ubuntu5_all.deb ... 335s Unpacking libdebhelper-perl (13.14.1ubuntu5) ... 335s Selecting previously unselected package libtool. 335s Preparing to unpack .../30-libtool_2.4.7-7build1_all.deb ... 335s Unpacking libtool (2.4.7-7build1) ... 335s Selecting previously unselected package dh-autoreconf. 335s Preparing to unpack .../31-dh-autoreconf_20_all.deb ... 335s Unpacking dh-autoreconf (20) ... 335s Selecting previously unselected package libarchive-zip-perl. 335s Preparing to unpack .../32-libarchive-zip-perl_1.68-1_all.deb ... 335s Unpacking libarchive-zip-perl (1.68-1) ... 335s Selecting previously unselected package libsub-override-perl. 335s Preparing to unpack .../33-libsub-override-perl_0.10-1_all.deb ... 335s Unpacking libsub-override-perl (0.10-1) ... 335s Selecting previously unselected package libfile-stripnondeterminism-perl. 335s Preparing to unpack .../34-libfile-stripnondeterminism-perl_1.13.1-1_all.deb ... 335s Unpacking libfile-stripnondeterminism-perl (1.13.1-1) ... 335s Selecting previously unselected package dh-strip-nondeterminism. 335s Preparing to unpack .../35-dh-strip-nondeterminism_1.13.1-1_all.deb ... 335s Unpacking dh-strip-nondeterminism (1.13.1-1) ... 335s Selecting previously unselected package debugedit. 335s Preparing to unpack .../36-debugedit_1%3a5.0-5build2_s390x.deb ... 335s Unpacking debugedit (1:5.0-5build2) ... 335s Selecting previously unselected package dwz. 335s Preparing to unpack .../37-dwz_0.15-1build6_s390x.deb ... 335s Unpacking dwz (0.15-1build6) ... 335s Selecting previously unselected package gettext. 335s Preparing to unpack .../38-gettext_0.21-14ubuntu2_s390x.deb ... 335s Unpacking gettext (0.21-14ubuntu2) ... 335s Selecting previously unselected package intltool-debian. 335s Preparing to unpack .../39-intltool-debian_0.35.0+20060710.6_all.deb ... 335s Unpacking intltool-debian (0.35.0+20060710.6) ... 335s Selecting previously unselected package po-debconf. 335s Preparing to unpack .../40-po-debconf_1.0.21+nmu1_all.deb ... 335s Unpacking po-debconf (1.0.21+nmu1) ... 335s Selecting previously unselected package debhelper. 335s Preparing to unpack .../41-debhelper_13.14.1ubuntu5_all.deb ... 335s Unpacking debhelper (13.14.1ubuntu5) ... 335s Selecting previously unselected package dh-apport. 335s Preparing to unpack .../42-dh-apport_2.28.1-0ubuntu1_all.deb ... 335s Unpacking dh-apport (2.28.1-0ubuntu1) ... 335s Selecting previously unselected package golang-1.22-src. 335s Preparing to unpack .../43-golang-1.22-src_1.22.2-2_all.deb ... 335s Unpacking golang-1.22-src (1.22.2-2) ... 337s Selecting previously unselected package golang-1.22-go. 337s Preparing to unpack .../44-golang-1.22-go_1.22.2-2_s390x.deb ... 337s Unpacking golang-1.22-go (1.22.2-2) ... 338s Selecting previously unselected package golang-src. 338s Preparing to unpack .../45-golang-src_2%3a1.22~2build1_all.deb ... 338s Unpacking golang-src (2:1.22~2build1) ... 339s Selecting previously unselected package golang-go:s390x. 339s Preparing to unpack .../46-golang-go_2%3a1.22~2build1_s390x.deb ... 339s Unpacking golang-go:s390x (2:1.22~2build1) ... 339s Selecting previously unselected package dh-golang. 339s Preparing to unpack .../47-dh-golang_1.62_all.deb ... 339s Unpacking dh-golang (1.62) ... 339s Selecting previously unselected package autopkgtest-satdep. 339s Preparing to unpack .../48-1-autopkgtest-satdep.deb ... 339s Unpacking autopkgtest-satdep (0) ... 339s Setting up libarchive-zip-perl (1.68-1) ... 339s Setting up libdebhelper-perl (13.14.1ubuntu5) ... 339s Setting up m4 (1.4.19-4build1) ... 339s Setting up libgomp1:s390x (14-20240412-0ubuntu1) ... 339s Setting up dh-apport (2.28.1-0ubuntu1) ... 339s Setting up autotools-dev (20220109.1) ... 339s Setting up gcc-13-base:s390x (13.2.0-23ubuntu4) ... 339s Setting up golang-1.22-src (1.22.2-2) ... 339s Setting up libmpc3:s390x (1.3.1-1build1) ... 339s Setting up libatomic1:s390x (14-20240412-0ubuntu1) ... 339s Setting up autopoint (0.21-14ubuntu2) ... 339s Setting up autoconf (2.71-3) ... 339s Setting up libubsan1:s390x (14-20240412-0ubuntu1) ... 339s Setting up dwz (0.15-1build6) ... 339s Setting up libasan8:s390x (14-20240412-0ubuntu1) ... 339s Setting up debugedit (1:5.0-5build2) ... 339s Setting up libsub-override-perl (0.10-1) ... 339s Setting up libisl23:s390x (0.26-3build1) ... 339s Setting up golang-src (2:1.22~2build1) ... 339s Setting up libcc1-0:s390x (14-20240412-0ubuntu1) ... 339s Setting up libitm1:s390x (14-20240412-0ubuntu1) ... 339s Setting up automake (1:1.16.5-1.3ubuntu1) ... 339s update-alternatives: using /usr/bin/automake-1.16 to provide /usr/bin/automake (automake) in auto mode 339s Setting up libfile-stripnondeterminism-perl (1.13.1-1) ... 339s Setting up gettext (0.21-14ubuntu2) ... 339s Setting up golang-1.22-go (1.22.2-2) ... 339s Setting up intltool-debian (0.35.0+20060710.6) ... 339s Setting up cpp-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 339s Setting up dh-strip-nondeterminism (1.13.1-1) ... 339s Setting up libgcc-13-dev:s390x (13.2.0-23ubuntu4) ... 339s Setting up libstdc++-13-dev:s390x (13.2.0-23ubuntu4) ... 339s Setting up cpp-13 (13.2.0-23ubuntu4) ... 339s Setting up cpp-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 339s Setting up golang-go:s390x (2:1.22~2build1) ... 339s Setting up po-debconf (1.0.21+nmu1) ... 339s Setting up gcc-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 339s Setting up gcc-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 339s Setting up g++-13-s390x-linux-gnu (13.2.0-23ubuntu4) ... 339s Setting up gcc-13 (13.2.0-23ubuntu4) ... 339s Setting up cpp (4:13.2.0-7ubuntu1) ... 339s Setting up g++-13 (13.2.0-23ubuntu4) ... 339s Setting up libtool (2.4.7-7build1) ... 339s Setting up g++-s390x-linux-gnu (4:13.2.0-7ubuntu1) ... 339s Setting up gcc (4:13.2.0-7ubuntu1) ... 339s Setting up dh-autoreconf (20) ... 339s Setting up g++ (4:13.2.0-7ubuntu1) ... 339s update-alternatives: using /usr/bin/g++ to provide /usr/bin/c++ (c++) in auto mode 339s Setting up build-essential (12.10ubuntu1) ... 339s Setting up debhelper (13.14.1ubuntu5) ... 339s Setting up dh-golang (1.62) ... 339s Setting up autopkgtest-satdep (0) ... 339s Processing triggers for man-db (2.12.0-4build2) ... 339s Processing triggers for install-info (7.1-3build2) ... 340s Processing triggers for libc-bin (2.39-0ubuntu8) ... 342s (Reading database ... 94865 files and directories currently installed.) 342s Removing autopkgtest-satdep (0) ... 343s autopkgtest [08:32:05]: test command1: ./debian/tests/test 343s autopkgtest [08:32:05]: test command1: [----------------------- 430s === RUN TestRunSignal 430s === RUN TestRunSignal/Send_SIGINT_exits 430s INFO Starting WSL Pro Service version Dev 430s === RUN TestRunSignal/Send_SIGTERM_exits 430s INFO Starting WSL Pro Service version Dev 431s --- PASS: TestRunSignal (0.20s) 431s --- PASS: TestRunSignal/Send_SIGINT_exits (0.10s) 431s --- PASS: TestRunSignal/Send_SIGTERM_exits (0.10s) 431s === RUN TestRun 431s === PAUSE TestRun 431s === CONT TestRun 431s === RUN TestRun/Run_and_exit_successfully 431s === PAUSE TestRun/Run_and_exit_successfully 431s === RUN TestRun/Run_and_return_error 431s === PAUSE TestRun/Run_and_return_error 431s === RUN TestRun/Run_and_return_usage_error 431s === PAUSE TestRun/Run_and_return_usage_error 431s === RUN TestRun/Run_and_usage_error_only_does_not_fail 431s === PAUSE TestRun/Run_and_usage_error_only_does_not_fail 431s === CONT TestRun/Run_and_exit_successfully 431s INFO Starting WSL Pro Service version Dev 431s === CONT TestRun/Run_and_usage_error_only_does_not_fail 431s INFO Starting WSL Pro Service version Dev 431s === CONT TestRun/Run_and_return_usage_error 431s INFO Starting WSL Pro Service version Dev 431s ERROR context.Background Error requested 431s === CONT TestRun/Run_and_return_error 431s INFO Starting WSL Pro Service version Dev 431s ERROR context.Background Error requested 431s --- PASS: TestRun (0.00s) 431s --- PASS: TestRun/Run_and_exit_successfully (0.10s) 431s --- PASS: TestRun/Run_and_usage_error_only_does_not_fail (0.10s) 431s --- PASS: TestRun/Run_and_return_usage_error (0.10s) 431s --- PASS: TestRun/Run_and_return_error (0.10s) 431s PASS 431s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service 0.610s 432s === RUN TestHelp 432s --- PASS: TestHelp (0.00s) 432s === RUN TestCompletion 432s --- PASS: TestCompletion (0.00s) 432s === RUN TestVersion 432s --- PASS: TestVersion (0.00s) 432s === RUN TestNoUsageError 433s --- PASS: TestNoUsageError (0.00s) 433s === RUN TestUsageError 433s === PAUSE TestUsageError 433s === RUN TestCanQuitWhenExecute 433s === PAUSE TestCanQuitWhenExecute 433s === RUN TestCanQuitTwice 433s === PAUSE TestCanQuitTwice 433s === RUN TestAppCanQuitWithoutExecute 433s === PAUSE TestAppCanQuitWithoutExecute 433s === RUN TestAppRunFailsOnComponentsCreationAndQuit 433s === PAUSE TestAppRunFailsOnComponentsCreationAndQuit 433s === RUN TestAppGetRootCmd 433s === PAUSE TestAppGetRootCmd 433s === RUN TestWithProMock 433s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 433s --- SKIP: TestWithProMock (0.00s) 433s === RUN TestWithWslPathMock 433s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 433s --- SKIP: TestWithWslPathMock (0.00s) 433s === RUN TestWithWslInfoMock 433s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 433s --- SKIP: TestWithWslInfoMock (0.00s) 433s === RUN TestWithCmdExeMock 433s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 433s --- SKIP: TestWithCmdExeMock (0.00s) 433s === CONT TestUsageError 433s --- PASS: TestUsageError (0.00s) 433s === CONT TestAppGetRootCmd 433s --- PASS: TestAppGetRootCmd (0.00s) 433s === CONT TestAppRunFailsOnComponentsCreationAndQuit 436s --- PASS: TestAppRunFailsOnComponentsCreationAndQuit (3.86s) 436s === CONT TestAppCanQuitWithoutExecute 436s service_test.go:140: This test is skipped because it is flaky. There is no way to guarantee Quit has been called before run. 436s --- SKIP: TestAppCanQuitWithoutExecute (0.00s) 436s === CONT TestCanQuitTwice 436s time="2024-04-19T08:33:38Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 436s time="2024-04-19T08:33:38Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:75 New() Building new daemon" 439s time="2024-04-19T08:33:41Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 439s time="2024-04-19T08:33:41Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 439s time="2024-04-19T08:33:41Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 441s time="2024-04-19T08:33:43Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:33225" 441s time="2024-04-19T08:33:43Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 441s time="2024-04-19T08:33:43Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.ProAttachCmd requests" 441s time="2024-04-19T08:33:43Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/streams/server.go:196 (*handlingLoop[...]).run() Started serving agentapi.LandscapeConfigCmd requests" 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/streams/server.go:141 (*Server).Serve() Server: sent preface messages to all streams" 442s time="2024-04-19T08:33:44Z" level=warning msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:186 (*Daemon).Serve.func1() Daemon: disconnected from Windows host" 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/testutils/mock_agent.go:300 (*mockWSLInstanceService).ProAttachmentCommands() MockWindowsAgent: ProAttachmentCommands ready" 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/testutils/mock_agent.go:326 (*mockWSLInstanceService).LandscapeConfigCommands() MockWindowsAgent: LandscapeConfigCommands ready" 442s time="2024-04-19T08:33:44Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.aslIha/build.DTz/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 442s time="2024-04-19T08:33:44Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.aslIha/build.DTz/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/testutils/mock_agent.go:275 (*mockWSLInstanceService).Connected() MockWindowsAgent: Connected ready" 442s time="2024-04-19T08:33:44Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" func=github.com/ubuntu/decorate.LogOnErrorContext file="/tmp/autopkgtest.aslIha/build.DTz/src/vendor/github.com/ubuntu/decorate/decorate.go:27" 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 442s --- PASS: TestCanQuitTwice (5.78s) 442s === CONT TestCanQuitWhenExecute 442s time="2024-04-19T08:33:44Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/testutils/mock_agent.go:76 NewMockWindowsAgent.func1() MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44499" 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/cmd/wsl-pro-service/service/service.go:66 New.func1() Debug mode is enabled" 442s time="2024-04-19T08:33:44Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:75 New() Building new daemon" 445s time="2024-04-19T08:33:47Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:153 (*Daemon).Serve.func1() Daemon: connecting to Windows Agent" 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:288 (*Daemon).connect() Daemon: starting connection to Windows Agent via 127.0.0.1:44499" 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:173 (*Daemon).Serve.func1() Daemon: completed connection to Windows Agent" 446s time="2024-04-19T08:33:48Z" level=warning msg="/tmp/autopkgtest.aslIha/build.DTz/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:44499: connect: connection refused\"" 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:209 (*Daemon).Serve() Reconnecting to Windows host in 1 seconds" 446s time="2024-04-19T08:33:48Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:220 (*Daemon).Quit() Stopping daemon requested." 446s time="2024-04-19T08:33:48Z" level=info msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:226 (*Daemon).Quit() Waiting for active requests to close." 446s time="2024-04-19T08:33:48Z" level=debug msg="/tmp/autopkgtest.aslIha/build.DTz/src/internal/daemon/daemon.go:234 (*Daemon).Quit() All connections have now ended." 446s --- PASS: TestCanQuitWhenExecute (4.24s) 446s PASS 446s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/cmd/wsl-pro-service/service 13.898s 446s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/generate/doc [no test files] 447s === RUN TestApplyProToken 447s === PAUSE TestApplyProToken 447s === RUN TestApplyLandscapeConfig 447s === PAUSE TestApplyLandscapeConfig 447s === RUN TestWithProMock 447s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 447s --- SKIP: TestWithProMock (0.00s) 447s === RUN TestWithLandscapeConfigMock 447s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 447s --- SKIP: TestWithLandscapeConfigMock (0.00s) 447s === RUN TestWithWslPathMock 447s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 447s --- SKIP: TestWithWslPathMock (0.00s) 447s === RUN TestWithWslInfoMock 447s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 447s --- SKIP: TestWithWslInfoMock (0.00s) 447s === RUN TestWithCmdExeMock 447s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 447s --- SKIP: TestWithCmdExeMock (0.00s) 447s === CONT TestApplyProToken 447s === RUN TestApplyProToken/Success_attaching 447s === PAUSE TestApplyProToken/Success_attaching 447s === RUN TestApplyProToken/Success_detaching 447s === PAUSE TestApplyProToken/Success_detaching 447s === RUN TestApplyProToken/Error_calling_pro_detach 447s === PAUSE TestApplyProToken/Error_calling_pro_detach 447s === RUN TestApplyProToken/Error_calling_pro_attach 447s === PAUSE TestApplyProToken/Error_calling_pro_attach 447s === CONT TestApplyLandscapeConfig 447s === RUN TestApplyLandscapeConfig/Error_calling_landscape_disable 447s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_disable 447s === RUN TestApplyLandscapeConfig/Error_calling_landscape_enable 447s === PAUSE TestApplyLandscapeConfig/Error_calling_landscape_enable 447s === RUN TestApplyLandscapeConfig/Success_enabling_Landscape 447s === PAUSE TestApplyLandscapeConfig/Success_enabling_Landscape 447s === RUN TestApplyLandscapeConfig/Success_disabling_Landscape 447s === PAUSE TestApplyLandscapeConfig/Success_disabling_Landscape 447s === CONT TestApplyProToken/Success_attaching 447s time="2024-04-19T08:33:49Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 449s === CONT TestApplyLandscapeConfig/Error_calling_landscape_disable 449s time="2024-04-19T08:33:51Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 450s === CONT TestApplyProToken/Error_calling_pro_attach 450s time="2024-04-19T08:33:52Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 453s === CONT TestApplyProToken/Error_calling_pro_detach 453s time="2024-04-19T08:33:55Z" level=info msg="ApplyProToken: Received token \"12**bc\": attaching" 454s === CONT TestApplyProToken/Success_detaching 454s time="2024-04-19T08:33:56Z" level=info msg="ApplyProToken: Received empty token: detaching" 455s --- PASS: TestApplyProToken (0.00s) 455s --- PASS: TestApplyProToken/Success_attaching (2.23s) 455s --- PASS: TestApplyProToken/Error_calling_pro_attach (2.14s) 455s --- PASS: TestApplyProToken/Error_calling_pro_detach (1.04s) 455s --- PASS: TestApplyProToken/Success_detaching (1.06s) 455s === CONT TestApplyLandscapeConfig/Success_disabling_Landscape 455s time="2024-04-19T08:33:57Z" level=info msg="ApplyLandscapeConfig: received empty config: disabling" 456s === CONT TestApplyLandscapeConfig/Success_enabling_Landscape 456s time="2024-04-19T08:33:58Z" level=info msg="ApplyLandscapeConfig: received config: registering" 457s === CONT TestApplyLandscapeConfig/Error_calling_landscape_enable 457s time="2024-04-19T08:33:59Z" level=info msg="ApplyLandscapeConfig: received config: registering" 458s --- PASS: TestApplyLandscapeConfig (0.00s) 458s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_disable (1.10s) 458s --- PASS: TestApplyLandscapeConfig/Success_disabling_Landscape (0.98s) 458s --- PASS: TestApplyLandscapeConfig/Success_enabling_Landscape (1.02s) 458s --- PASS: TestApplyLandscapeConfig/Error_calling_landscape_enable (1.05s) 458s PASS 458s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/commandservice 10.629s 458s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/consts [no test files] 459s === RUN TestNew 459s === PAUSE TestNew 459s === RUN TestServe 459s === PAUSE TestServe 459s === RUN TestServeAndQuit 459s === PAUSE TestServeAndQuit 459s === RUN TestReconnection 459s === PAUSE TestReconnection 459s === RUN TestWithProMock 459s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 459s --- SKIP: TestWithProMock (0.00s) 459s === RUN TestWithWslPathMock 459s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 459s --- SKIP: TestWithWslPathMock (0.00s) 459s === RUN TestWithWslInfoMock 459s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 459s --- SKIP: TestWithWslInfoMock (0.00s) 459s === RUN TestWithCmdExeMock 459s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 459s --- SKIP: TestWithCmdExeMock (0.00s) 459s === CONT TestNew 459s === RUN TestNew/Success 459s === PAUSE TestNew/Success 459s === RUN TestNew/Error_when_WslPath_returns_error 459s === PAUSE TestNew/Error_when_WslPath_returns_error 459s === CONT TestNew/Success 459s time="2024-04-19T08:34:01Z" level=debug msg="Building new daemon" 461s === CONT TestReconnection 461s === RUN TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 461s === PAUSE TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 461s === RUN TestReconnection/Success_connecting_after_failing_to_connect 461s === PAUSE TestReconnection/Success_connecting_after_failing_to_connect 461s === RUN TestReconnection/Success_connecting_after_previous_connection_dropped 461s === PAUSE TestReconnection/Success_connecting_after_previous_connection_dropped 461s === CONT TestServeAndQuit 461s === RUN TestServeAndQuit/Success_with_graceful_quit 461s === PAUSE TestServeAndQuit/Success_with_graceful_quit 461s === RUN TestServeAndQuit/Success_with_forceful_quit 461s === PAUSE TestServeAndQuit/Success_with_forceful_quit 461s === RUN TestServeAndQuit/Success_with_double_quit 461s === PAUSE TestServeAndQuit/Success_with_double_quit 461s === RUN TestServeAndQuit/Error_due_to_quitting_before_serving 461s === PAUSE TestServeAndQuit/Error_due_to_quitting_before_serving 461s === CONT TestServe 461s === RUN TestServe/Error_because_the_context_is_pre-cancelled 461s === PAUSE TestServe/Error_because_the_context_is_pre-cancelled 461s === RUN TestServe/Error_because_WindowsHostAddress_returns_an_error 461s === PAUSE TestServe/Error_because_WindowsHostAddress_returns_an_error 461s === RUN TestServe/Success_with_systemd_notifier_returning_true 461s === PAUSE TestServe/Success_with_systemd_notifier_returning_true 461s === RUN TestServe/No_connection_because_the_port_file_has_port_0 461s === PAUSE TestServe/No_connection_because_the_port_file_has_port_0 461s === RUN TestServe/No_connection_because_cannot_read_root_CA_certificate_file 461s === PAUSE TestServe/No_connection_because_cannot_read_root_CA_certificate_file 461s === RUN TestServe/No_connection_because_the_port_file_has_a_bad_port 461s === PAUSE TestServe/No_connection_because_the_port_file_has_a_bad_port 461s === RUN TestServe/No_connection_because_the_port_file_has_a_negative_port 461s === PAUSE TestServe/No_connection_because_the_port_file_has_a_negative_port 461s === RUN TestServe/No_connection_because_there_is_no_server 461s === PAUSE TestServe/No_connection_because_there_is_no_server 461s === RUN TestServe/No_connection_because_there_are_no_certificates 461s === PAUSE TestServe/No_connection_because_there_are_no_certificates 461s === RUN TestServe/Error_because_the_notifier_returns_an_error 461s === PAUSE TestServe/Error_because_the_notifier_returns_an_error 461s === RUN TestServe/Success 461s === PAUSE TestServe/Success 461s === RUN TestServe/No_connection_because_the_port_file_does_not_exist 461s === PAUSE TestServe/No_connection_because_the_port_file_does_not_exist 461s === RUN TestServe/No_connection_because_the_port_file_is_empty 461s === PAUSE TestServe/No_connection_because_the_port_file_is_empty 461s === CONT TestNew/Error_when_WslPath_returns_error 461s time="2024-04-19T08:34:03Z" level=debug msg="Building new daemon" 464s --- PASS: TestNew (0.00s) 464s --- PASS: TestNew/Success (2.43s) 464s --- PASS: TestNew/Error_when_WslPath_returns_error (2.29s) 464s === CONT TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped 464s time="2024-04-19T08:34:06Z" level=debug msg="Building new daemon" 466s time="2024-04-19T08:34:08Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35909" 466s time="2024-04-19T08:34:08Z" level=debug msg="Ready state sent to systemd" 466s time="2024-04-19T08:34:08Z" level=info msg="Daemon: connecting to Windows Agent" 466s time="2024-04-19T08:34:08Z" level=debug msg="Updated systemd status to \"Connecting\"" 467s time="2024-04-19T08:34:09Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35909" 467s time="2024-04-19T08:34:09Z" level=info msg="Daemon: completed connection to Windows Agent" 467s time="2024-04-19T08:34:09Z" level=debug msg="Updated systemd status to \"Connected\"" 467s time="2024-04-19T08:34:09Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 467s time="2024-04-19T08:34:09Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 468s time="2024-04-19T08:34:10Z" level=debug msg="Server: sent preface messages to all streams" 468s time="2024-04-19T08:34:10Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 468s time="2024-04-19T08:34:10Z" level=info msg="MockWindowsAgent: Connected ready" 468s time="2024-04-19T08:34:10Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 533s time="2024-04-19T08:35:15Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 533s time="2024-04-19T08:35:15Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 533s time="2024-04-19T08:35:15Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 533s time="2024-04-19T08:35:15Z" level=warning msg="Daemon: disconnected from Windows host" 533s time="2024-04-19T08:35:15Z" level=info msg="Daemon: connecting to Windows Agent" 533s time="2024-04-19T08:35:15Z" level=debug msg="Updated systemd status to \"Connecting\"" 533s time="2024-04-19T08:35:15Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not read agent port file \"/tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped2440326589/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_previous_long-lived_connection_dropped2440326589/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 533s time="2024-04-19T08:35:15Z" level=info msg="Reconnecting to Windows host in 1 seconds" 533s time="2024-04-19T08:35:15Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 533s time="2024-04-19T08:35:15Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35821" 534s time="2024-04-19T08:35:16Z" level=info msg="Daemon: connecting to Windows Agent" 534s time="2024-04-19T08:35:16Z" level=debug msg="Updated systemd status to \"Connecting\"" 535s time="2024-04-19T08:35:17Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35821" 535s time="2024-04-19T08:35:17Z" level=info msg="Daemon: completed connection to Windows Agent" 535s time="2024-04-19T08:35:17Z" level=debug msg="Updated systemd status to \"Connected\"" 535s time="2024-04-19T08:35:17Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 535s time="2024-04-19T08:35:17Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 537s time="2024-04-19T08:35:18Z" level=debug msg="Server: sent preface messages to all streams" 537s time="2024-04-19T08:35:18Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 537s time="2024-04-19T08:35:18Z" level=info msg="MockWindowsAgent: Connected ready" 537s time="2024-04-19T08:35:18Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 537s time="2024-04-19T08:35:19Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 537s time="2024-04-19T08:35:19Z" level=info msg="Stopping daemon requested." 537s time="2024-04-19T08:35:19Z" level=info msg="Stopping active requests." 537s time="2024-04-19T08:35:19Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 537s time="2024-04-19T08:35:19Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 537s time="2024-04-19T08:35:19Z" level=warning msg="Daemon: disconnected from Windows host" 537s time="2024-04-19T08:35:19Z" level=info msg="Reconnecting to Windows host in 2 seconds" 537s time="2024-04-19T08:35:19Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 537s time="2024-04-19T08:35:19Z" level=debug msg="Updated systemd status to \"Stopped\"" 537s time="2024-04-19T08:35:19Z" level=debug msg="All connections have now ended." 537s === CONT TestServeAndQuit/Success_with_graceful_quit 537s time="2024-04-19T08:35:19Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44925" 537s time="2024-04-19T08:35:19Z" level=debug msg="Building new daemon" 539s time="2024-04-19T08:35:21Z" level=debug msg="Ready state sent to systemd" 539s time="2024-04-19T08:35:21Z" level=info msg="Daemon: connecting to Windows Agent" 539s time="2024-04-19T08:35:21Z" level=debug msg="Updated systemd status to \"Connecting\"" 541s time="2024-04-19T08:35:23Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:44925" 541s time="2024-04-19T08:35:23Z" level=info msg="Daemon: completed connection to Windows Agent" 541s time="2024-04-19T08:35:23Z" level=debug msg="Updated systemd status to \"Connected\"" 541s time="2024-04-19T08:35:23Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 541s time="2024-04-19T08:35:23Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 542s time="2024-04-19T08:35:24Z" level=debug msg="Server: sent preface messages to all streams" 542s time="2024-04-19T08:35:24Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 542s time="2024-04-19T08:35:24Z" level=info msg="MockWindowsAgent: Connected ready" 542s time="2024-04-19T08:35:24Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 542s time="2024-04-19T08:35:24Z" level=info msg="Stopping daemon requested." 542s time="2024-04-19T08:35:24Z" level=info msg="Waiting for active requests to close." 542s time="2024-04-19T08:35:24Z" level=warning msg="Daemon: disconnected from Windows host" 542s time="2024-04-19T08:35:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 542s time="2024-04-19T08:35:24Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 542s time="2024-04-19T08:35:24Z" level=debug msg="Updated systemd status to \"Stopped\"" 542s time="2024-04-19T08:35:24Z" level=debug msg="All connections have now ended." 542s time="2024-04-19T08:35:24Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 542s time="2024-04-19T08:35:24Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 542s time="2024-04-19T08:35:24Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 542s === CONT TestReconnection/Success_connecting_after_previous_connection_dropped 542s time="2024-04-19T08:35:24Z" level=debug msg="Building new daemon" 545s time="2024-04-19T08:35:27Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43343" 545s time="2024-04-19T08:35:27Z" level=debug msg="Ready state sent to systemd" 545s time="2024-04-19T08:35:27Z" level=info msg="Daemon: connecting to Windows Agent" 545s time="2024-04-19T08:35:27Z" level=debug msg="Updated systemd status to \"Connecting\"" 546s time="2024-04-19T08:35:28Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43343" 546s time="2024-04-19T08:35:28Z" level=info msg="Daemon: completed connection to Windows Agent" 546s time="2024-04-19T08:35:28Z" level=debug msg="Updated systemd status to \"Connected\"" 547s time="2024-04-19T08:35:28Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 547s time="2024-04-19T08:35:28Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 548s time="2024-04-19T08:35:30Z" level=debug msg="Server: sent preface messages to all streams" 548s time="2024-04-19T08:35:30Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 548s time="2024-04-19T08:35:30Z" level=info msg="MockWindowsAgent: Connected ready" 548s time="2024-04-19T08:35:30Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 548s time="2024-04-19T08:35:30Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 548s time="2024-04-19T08:35:30Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 548s time="2024-04-19T08:35:30Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 548s time="2024-04-19T08:35:30Z" level=warning msg="Daemon: disconnected from Windows host" 548s time="2024-04-19T08:35:30Z" level=info msg="Reconnecting to Windows host in 1 seconds" 548s time="2024-04-19T08:35:30Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 548s time="2024-04-19T08:35:30Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38481" 549s time="2024-04-19T08:35:31Z" level=info msg="Daemon: connecting to Windows Agent" 549s time="2024-04-19T08:35:31Z" level=debug msg="Updated systemd status to \"Connecting\"" 550s time="2024-04-19T08:35:32Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:38481" 550s time="2024-04-19T08:35:32Z" level=info msg="Daemon: completed connection to Windows Agent" 550s time="2024-04-19T08:35:32Z" level=debug msg="Updated systemd status to \"Connected\"" 550s time="2024-04-19T08:35:32Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 550s time="2024-04-19T08:35:32Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 551s time="2024-04-19T08:35:33Z" level=debug msg="Server: sent preface messages to all streams" 551s time="2024-04-19T08:35:33Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 551s time="2024-04-19T08:35:33Z" level=info msg="MockWindowsAgent: Connected ready" 551s time="2024-04-19T08:35:33Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 552s time="2024-04-19T08:35:33Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 552s time="2024-04-19T08:35:33Z" level=info msg="Stopping daemon requested." 552s time="2024-04-19T08:35:33Z" level=info msg="Stopping active requests." 552s time="2024-04-19T08:35:33Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 552s time="2024-04-19T08:35:33Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 552s time="2024-04-19T08:35:33Z" level=warning msg="Daemon: disconnected from Windows host" 552s time="2024-04-19T08:35:33Z" level=info msg="Reconnecting to Windows host in 2 seconds" 552s time="2024-04-19T08:35:33Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 552s time="2024-04-19T08:35:33Z" level=debug msg="Updated systemd status to \"Stopped\"" 552s time="2024-04-19T08:35:33Z" level=debug msg="All connections have now ended." 552s === CONT TestReconnection/Success_connecting_after_failing_to_connect 552s time="2024-04-19T08:35:33Z" level=debug msg="Building new daemon" 554s time="2024-04-19T08:35:36Z" level=debug msg="Ready state sent to systemd" 554s time="2024-04-19T08:35:36Z" level=info msg="Daemon: connecting to Windows Agent" 554s time="2024-04-19T08:35:36Z" level=debug msg="Updated systemd status to \"Connecting\"" 554s time="2024-04-19T08:35:36Z" 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_connect3823200025/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestReconnectionSuccess_connecting_after_failing_to_connect3823200025/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 554s time="2024-04-19T08:35:36Z" level=info msg="Reconnecting to Windows host in 1 seconds" 554s time="2024-04-19T08:35:36Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 554s time="2024-04-19T08:35:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35621" 555s time="2024-04-19T08:35:37Z" level=info msg="Daemon: connecting to Windows Agent" 555s time="2024-04-19T08:35:37Z" level=debug msg="Updated systemd status to \"Connecting\"" 556s time="2024-04-19T08:35:38Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35621" 556s time="2024-04-19T08:35:38Z" level=info msg="Daemon: completed connection to Windows Agent" 556s time="2024-04-19T08:35:38Z" level=debug msg="Updated systemd status to \"Connected\"" 556s time="2024-04-19T08:35:38Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 556s time="2024-04-19T08:35:38Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 557s time="2024-04-19T08:35:39Z" level=debug msg="Server: sent preface messages to all streams" 557s time="2024-04-19T08:35:39Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 557s time="2024-04-19T08:35:39Z" level=info msg="MockWindowsAgent: Connected ready" 557s time="2024-04-19T08:35:39Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 557s time="2024-04-19T08:35:39Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 557s time="2024-04-19T08:35:39Z" level=info msg="Stopping daemon requested." 557s time="2024-04-19T08:35:39Z" level=info msg="Stopping active requests." 557s time="2024-04-19T08:35:39Z" level=warning msg="Daemon: disconnected from Windows host" 557s time="2024-04-19T08:35:39Z" level=info msg="Reconnecting to Windows host in 2 seconds" 557s time="2024-04-19T08:35:39Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 557s time="2024-04-19T08:35:39Z" level=debug msg="Updated systemd status to \"Stopped\"" 557s time="2024-04-19T08:35:39Z" level=debug msg="All connections have now ended." 557s --- PASS: TestReconnection (0.00s) 557s --- PASS: TestReconnection/Success_connecting_after_previous_long-lived_connection_dropped (73.00s) 557s --- PASS: TestReconnection/Success_connecting_after_previous_connection_dropped (9.27s) 557s --- PASS: TestReconnection/Success_connecting_after_failing_to_connect (6.01s) 557s time="2024-04-19T08:35:39Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 557s time="2024-04-19T08:35:39Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 557s === CONT TestServe/Error_because_the_context_is_pre-cancelled 558s time="2024-04-19T08:35:39Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43577" 558s time="2024-04-19T08:35:39Z" level=debug msg="Building new daemon" 560s time="2024-04-19T08:35:42Z" level=info msg="Stopping daemon requested." 560s time="2024-04-19T08:35:42Z" level=info msg="Waiting for active requests to close." 560s time="2024-04-19T08:35:42Z" level=debug msg="All connections have now ended." 560s === CONT TestServeAndQuit/Error_due_to_quitting_before_serving 560s time="2024-04-19T08:35:42Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:36351" 560s time="2024-04-19T08:35:42Z" level=debug msg="Building new daemon" 563s time="2024-04-19T08:35:45Z" level=info msg="Stopping daemon requested." 563s time="2024-04-19T08:35:45Z" level=info msg="Waiting for active requests to close." 563s time="2024-04-19T08:35:45Z" level=info msg="Stopping daemon requested." 563s time="2024-04-19T08:35:45Z" level=info msg="Waiting for active requests to close." 563s time="2024-04-19T08:35:45Z" level=debug msg="Updated systemd status to \"Stopped\"" 563s === CONT TestServeAndQuit/Success_with_double_quit 563s time="2024-04-19T08:35:45Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34199" 563s time="2024-04-19T08:35:45Z" level=debug msg="Building new daemon" 565s time="2024-04-19T08:35:47Z" level=debug msg="Ready state sent to systemd" 565s time="2024-04-19T08:35:47Z" level=info msg="Daemon: connecting to Windows Agent" 565s time="2024-04-19T08:35:47Z" level=debug msg="Updated systemd status to \"Connecting\"" 567s time="2024-04-19T08:35:49Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34199" 567s time="2024-04-19T08:35:49Z" level=info msg="Daemon: completed connection to Windows Agent" 567s time="2024-04-19T08:35:49Z" level=debug msg="Updated systemd status to \"Connected\"" 567s time="2024-04-19T08:35:49Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 567s time="2024-04-19T08:35:49Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 568s time="2024-04-19T08:35:50Z" level=debug msg="Server: sent preface messages to all streams" 568s time="2024-04-19T08:35:50Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 568s time="2024-04-19T08:35:50Z" level=info msg="MockWindowsAgent: Connected ready" 568s time="2024-04-19T08:35:50Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 568s time="2024-04-19T08:35:50Z" level=info msg="Stopping daemon requested." 568s time="2024-04-19T08:35:50Z" level=info msg="Waiting for active requests to close." 568s time="2024-04-19T08:35:50Z" level=warning msg="Daemon: disconnected from Windows host" 568s time="2024-04-19T08:35:50Z" level=info msg="Reconnecting to Windows host in 1 seconds" 568s time="2024-04-19T08:35:50Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 568s time="2024-04-19T08:35:50Z" level=debug msg="Updated systemd status to \"Stopped\"" 568s time="2024-04-19T08:35:50Z" level=debug msg="All connections have now ended." 568s time="2024-04-19T08:35:50Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 568s time="2024-04-19T08:35:50Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 568s time="2024-04-19T08:35:50Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 568s time="2024-04-19T08:35:50Z" level=info msg="Stopping daemon requested." 568s time="2024-04-19T08:35:50Z" level=info msg="Waiting for active requests to close." 568s time="2024-04-19T08:35:50Z" level=debug msg="All connections have now ended." 568s === CONT TestServeAndQuit/Success_with_forceful_quit 568s time="2024-04-19T08:35:50Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43949" 568s time="2024-04-19T08:35:50Z" level=debug msg="Building new daemon" 571s time="2024-04-19T08:35:53Z" level=debug msg="Ready state sent to systemd" 571s time="2024-04-19T08:35:53Z" level=info msg="Daemon: connecting to Windows Agent" 571s time="2024-04-19T08:35:53Z" level=debug msg="Updated systemd status to \"Connecting\"" 572s time="2024-04-19T08:35:54Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43949" 572s time="2024-04-19T08:35:54Z" level=info msg="Daemon: completed connection to Windows Agent" 572s time="2024-04-19T08:35:54Z" level=debug msg="Updated systemd status to \"Connected\"" 572s time="2024-04-19T08:35:54Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 572s time="2024-04-19T08:35:54Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 573s time="2024-04-19T08:35:55Z" level=debug msg="Server: sent preface messages to all streams" 573s time="2024-04-19T08:35:55Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 573s time="2024-04-19T08:35:55Z" level=info msg="MockWindowsAgent: Connected ready" 573s time="2024-04-19T08:35:55Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 574s time="2024-04-19T08:35:55Z" level=info msg="Stopping daemon requested." 574s time="2024-04-19T08:35:55Z" level=info msg="Stopping active requests." 574s time="2024-04-19T08:35:55Z" level=warning msg="Daemon: disconnected from Windows host" 574s time="2024-04-19T08:35:55Z" level=info msg="Reconnecting to Windows host in 1 seconds" 574s time="2024-04-19T08:35:55Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 574s time="2024-04-19T08:35:55Z" level=debug msg="Updated systemd status to \"Stopped\"" 574s time="2024-04-19T08:35:55Z" level=debug msg="All connections have now ended." 574s time="2024-04-19T08:35:55Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 574s time="2024-04-19T08:35:55Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 574s time="2024-04-19T08:35:55Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 574s --- PASS: TestServeAndQuit (0.00s) 574s --- PASS: TestServeAndQuit/Success_with_graceful_quit (5.53s) 574s --- PASS: TestServeAndQuit/Error_due_to_quitting_before_serving (2.84s) 574s --- PASS: TestServeAndQuit/Success_with_double_quit (5.11s) 574s --- PASS: TestServeAndQuit/Success_with_forceful_quit (5.62s) 574s === CONT TestServe/No_connection_because_the_port_file_is_empty 574s time="2024-04-19T08:35:56Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38183" 574s time="2024-04-19T08:35:56Z" level=debug msg="Building new daemon" 576s time="2024-04-19T08:35:58Z" level=info msg="Daemon: connecting to Windows Agent" 576s time="2024-04-19T08:35:58Z" 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" 576s time="2024-04-19T08:35:58Z" level=info msg="Reconnecting to Windows host in 1 seconds" 577s time="2024-04-19T08:35:59Z" level=info msg="Stopping daemon requested." 577s time="2024-04-19T08:35:59Z" level=info msg="Waiting for active requests to close." 577s time="2024-04-19T08:35:59Z" level=debug msg="All connections have now ended." 577s === CONT TestServe/No_connection_because_the_port_file_does_not_exist 577s time="2024-04-19T08:35:59Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:38507" 577s time="2024-04-19T08:35:59Z" level=debug msg="Building new daemon" 580s time="2024-04-19T08:36:02Z" level=info msg="Daemon: connecting to Windows Agent" 580s time="2024-04-19T08:36:02Z" 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_exist1908541028/001/mnt/d/Users/TestUser/.ubuntupro/.address\": open /tmp/TestServeNo_connection_because_the_port_file_does_not_exist1908541028/001/mnt/d/Users/TestUser/.ubuntupro/.address: no such file or directory" 580s time="2024-04-19T08:36:02Z" level=info msg="Reconnecting to Windows host in 1 seconds" 581s time="2024-04-19T08:36:03Z" level=info msg="Stopping daemon requested." 581s time="2024-04-19T08:36:03Z" level=info msg="Waiting for active requests to close." 581s time="2024-04-19T08:36:03Z" level=debug msg="All connections have now ended." 581s === CONT TestServe/Success 581s time="2024-04-19T08:36:03Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46705" 581s time="2024-04-19T08:36:03Z" level=debug msg="Building new daemon" 584s time="2024-04-19T08:36:06Z" level=info msg="Daemon: connecting to Windows Agent" 585s time="2024-04-19T08:36:07Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:46705" 585s time="2024-04-19T08:36:07Z" level=info msg="Daemon: completed connection to Windows Agent" 585s time="2024-04-19T08:36:07Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 585s time="2024-04-19T08:36:07Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 587s time="2024-04-19T08:36:09Z" level=debug msg="Server: sent preface messages to all streams" 587s time="2024-04-19T08:36:09Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 587s time="2024-04-19T08:36:09Z" level=info msg="MockWindowsAgent: Connected ready" 587s time="2024-04-19T08:36:09Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 588s time="2024-04-19T08:36:10Z" level=info msg="Stopping daemon requested." 588s time="2024-04-19T08:36:10Z" level=info msg="Waiting for active requests to close." 588s time="2024-04-19T08:36:10Z" level=warning msg="Daemon: disconnected from Windows host" 588s time="2024-04-19T08:36:10Z" level=info msg="Reconnecting to Windows host in 1 seconds" 588s time="2024-04-19T08:36:10Z" level=debug msg="All connections have now ended." 588s time="2024-04-19T08:36:10Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 588s === CONT TestServe/Error_because_the_notifier_returns_an_error 588s time="2024-04-19T08:36:10Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:33637" 588s time="2024-04-19T08:36:10Z" level=debug msg="Building new daemon" 588s time="2024-04-19T08:36:10Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 588s time="2024-04-19T08:36:10Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 590s time="2024-04-19T08:36:12Z" level=warning msg="Daemon: couldn't update systemd status to \"Stopped\": mock error" 590s time="2024-04-19T08:36:12Z" level=info msg="Stopping daemon requested." 590s time="2024-04-19T08:36:12Z" level=info msg="Waiting for active requests to close." 590s time="2024-04-19T08:36:12Z" level=debug msg="All connections have now ended." 590s === CONT TestServe/No_connection_because_there_are_no_certificates 590s time="2024-04-19T08:36:12Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:43343" 590s time="2024-04-19T08:36:12Z" level=debug msg="Building new daemon" 593s time="2024-04-19T08:36:15Z" level=info msg="Daemon: connecting to Windows Agent" 594s time="2024-04-19T08:36:16Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:43343" 594s time="2024-04-19T08:36:16Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_there_are_no_certificates3296464464/001/mnt/d/Users/TestUser/.ubuntupro/certs/client_cert.pem: no such file or directory" 594s time="2024-04-19T08:36:16Z" level=info msg="Reconnecting to Windows host in 1 seconds" 595s time="2024-04-19T08:36:17Z" level=info msg="Stopping daemon requested." 595s time="2024-04-19T08:36:17Z" level=info msg="Waiting for active requests to close." 595s time="2024-04-19T08:36:17Z" level=debug msg="All connections have now ended." 595s === CONT TestServe/No_connection_because_there_is_no_server 595s time="2024-04-19T08:36:17Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:35897" 595s time="2024-04-19T08:36:17Z" level=debug msg="Building new daemon" 597s time="2024-04-19T08:36:19Z" level=info msg="Daemon: connecting to Windows Agent" 598s time="2024-04-19T08:36:20Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:35897" 598s time="2024-04-19T08:36:20Z" level=info msg="Daemon: completed connection to Windows Agent" 598s time="2024-04-19T08:36:20Z" 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:35897: connect: connection refused\"" 598s time="2024-04-19T08:36:20Z" level=info msg="Reconnecting to Windows host in 1 seconds" 599s time="2024-04-19T08:36:21Z" level=info msg="Stopping daemon requested." 599s time="2024-04-19T08:36:21Z" level=info msg="Waiting for active requests to close." 599s time="2024-04-19T08:36:21Z" level=debug msg="All connections have now ended." 599s === CONT TestServe/No_connection_because_the_port_file_has_a_negative_port 599s time="2024-04-19T08:36:21Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:42633" 599s time="2024-04-19T08:36:21Z" level=debug msg="Building new daemon" 602s time="2024-04-19T08:36:24Z" level=info msg="Daemon: connecting to Windows Agent" 602s time="2024-04-19T08:36:24Z" level=warning msg="Daemon: could not connect to Windows Agent: could not get address: could not parse port from \"127.0.0.1:-5\": port cannot be negative" 602s time="2024-04-19T08:36:24Z" level=info msg="Reconnecting to Windows host in 1 seconds" 603s time="2024-04-19T08:36:25Z" level=info msg="Stopping daemon requested." 603s time="2024-04-19T08:36:25Z" level=info msg="Waiting for active requests to close." 603s time="2024-04-19T08:36:25Z" level=debug msg="All connections have now ended." 603s === CONT TestServe/No_connection_because_the_port_file_has_a_bad_port 603s time="2024-04-19T08:36:25Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:46295" 603s time="2024-04-19T08:36:25Z" level=debug msg="Building new daemon" 605s time="2024-04-19T08:36:27Z" level=info msg="Daemon: connecting to Windows Agent" 605s time="2024-04-19T08:36:27Z" 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" 605s time="2024-04-19T08:36:27Z" level=info msg="Reconnecting to Windows host in 1 seconds" 606s time="2024-04-19T08:36:28Z" level=info msg="Stopping daemon requested." 606s time="2024-04-19T08:36:28Z" level=info msg="Waiting for active requests to close." 606s time="2024-04-19T08:36:28Z" level=debug msg="All connections have now ended." 606s === CONT TestServe/No_connection_because_cannot_read_root_CA_certificate_file 606s time="2024-04-19T08:36:28Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34969" 606s time="2024-04-19T08:36:28Z" level=debug msg="Building new daemon" 609s time="2024-04-19T08:36:31Z" level=info msg="Daemon: connecting to Windows Agent" 610s time="2024-04-19T08:36:32Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:34969" 610s time="2024-04-19T08:36:32Z" level=warning msg="Daemon: could not connect to Windows Agent: open /tmp/TestServeNo_connection_because_cannot_read_root_CA_certificate_file380830241/001/mnt/d/Users/TestUser/.ubuntupro/certs/ca_cert.pem: no such file or directory" 610s time="2024-04-19T08:36:32Z" level=info msg="Reconnecting to Windows host in 1 seconds" 611s time="2024-04-19T08:36:33Z" level=info msg="Stopping daemon requested." 611s time="2024-04-19T08:36:33Z" level=info msg="Waiting for active requests to close." 611s time="2024-04-19T08:36:33Z" level=debug msg="All connections have now ended." 611s === CONT TestServe/No_connection_because_the_port_file_has_port_0 611s time="2024-04-19T08:36:33Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:45875" 611s time="2024-04-19T08:36:33Z" level=debug msg="Building new daemon" 613s time="2024-04-19T08:36:35Z" level=info msg="Daemon: connecting to Windows Agent" 613s time="2024-04-19T08:36:35Z" 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" 613s time="2024-04-19T08:36:35Z" level=info msg="Reconnecting to Windows host in 1 seconds" 614s time="2024-04-19T08:36:36Z" level=info msg="Stopping daemon requested." 614s time="2024-04-19T08:36:36Z" level=info msg="Waiting for active requests to close." 614s time="2024-04-19T08:36:36Z" level=debug msg="All connections have now ended." 614s === CONT TestServe/Success_with_systemd_notifier_returning_true 614s time="2024-04-19T08:36:36Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:41617" 614s time="2024-04-19T08:36:36Z" level=debug msg="Building new daemon" 617s time="2024-04-19T08:36:39Z" level=debug msg="Ready state sent to systemd" 617s time="2024-04-19T08:36:39Z" level=info msg="Daemon: connecting to Windows Agent" 617s time="2024-04-19T08:36:39Z" level=debug msg="Updated systemd status to \"Connecting\"" 619s time="2024-04-19T08:36:41Z" level=info msg="Daemon: starting connection to Windows Agent via 127.0.0.1:41617" 619s time="2024-04-19T08:36:41Z" level=info msg="Daemon: completed connection to Windows Agent" 619s time="2024-04-19T08:36:41Z" level=debug msg="Updated systemd status to \"Connected\"" 619s time="2024-04-19T08:36:41Z" level=debug msg="Started serving agentapi.ProAttachCmd requests" 619s time="2024-04-19T08:36:41Z" level=debug msg="Started serving agentapi.LandscapeConfigCmd requests" 620s time="2024-04-19T08:36:42Z" level=debug msg="Server: sent preface messages to all streams" 620s time="2024-04-19T08:36:42Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 620s time="2024-04-19T08:36:42Z" level=info msg="MockWindowsAgent: Connected ready" 620s time="2024-04-19T08:36:42Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 621s time="2024-04-19T08:36:43Z" level=info msg="Stopping daemon requested." 621s time="2024-04-19T08:36:43Z" level=info msg="Waiting for active requests to close." 621s time="2024-04-19T08:36:43Z" level=warning msg="Daemon: disconnected from Windows host" 621s time="2024-04-19T08:36:43Z" level=info msg="Reconnecting to Windows host in 1 seconds" 621s time="2024-04-19T08:36:43Z" level=debug msg="Updated systemd status to \"Not connected: waiting to retry\"" 621s time="2024-04-19T08:36:43Z" level=debug msg="Updated systemd status to \"Stopped\"" 621s time="2024-04-19T08:36:43Z" level=debug msg="All connections have now ended." 621s time="2024-04-19T08:36:43Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 621s time="2024-04-19T08:36:43Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 621s === CONT TestServe/Error_because_WindowsHostAddress_returns_an_error 621s time="2024-04-19T08:36:43Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 621s time="2024-04-19T08:36:43Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:39639" 621s time="2024-04-19T08:36:43Z" level=debug msg="Building new daemon" 624s time="2024-04-19T08:36:46Z" level=info msg="Daemon: connecting to Windows Agent" 625s time="2024-04-19T08:36:47Z" level=info msg="Stopping daemon requested." 625s time="2024-04-19T08:36:47Z" level=info msg="Waiting for active requests to close." 625s time="2024-04-19T08:36:47Z" level=debug msg="All connections have now ended." 625s --- PASS: TestServe (0.00s) 625s --- PASS: TestServe/Error_because_the_context_is_pre-cancelled (2.61s) 625s --- PASS: TestServe/No_connection_because_the_port_file_is_empty (3.46s) 625s --- PASS: TestServe/No_connection_because_the_port_file_does_not_exist (4.09s) 625s --- PASS: TestServe/Success (6.72s) 625s --- PASS: TestServe/Error_because_the_notifier_returns_an_error (2.51s) 625s --- PASS: TestServe/No_connection_because_there_are_no_certificates (4.41s) 625s --- PASS: TestServe/No_connection_because_there_is_no_server (4.37s) 625s --- PASS: TestServe/No_connection_because_the_port_file_has_a_negative_port (3.47s) 625s --- PASS: TestServe/No_connection_because_the_port_file_has_a_bad_port (3.48s) 625s --- PASS: TestServe/No_connection_because_cannot_read_root_CA_certificate_file (4.68s) 625s --- PASS: TestServe/No_connection_because_the_port_file_has_port_0 (3.53s) 625s --- PASS: TestServe/Success_with_systemd_notifier_returning_true (6.82s) 625s --- PASS: TestServe/Error_because_WindowsHostAddress_returns_an_error (4.10s) 625s PASS 625s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/daemon 166.383s 627s === RUN TestConnect 627s === PAUSE TestConnect 627s === RUN TestSendAndRecv 627s --- PASS: TestSendAndRecv (0.41s) 627s === RUN TestServe 627s === PAUSE TestServe 627s === RUN TestStop 627s === PAUSE TestStop 627s === RUN TestWithProMock 627s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 627s --- SKIP: TestWithProMock (0.00s) 627s === RUN TestWithWslPathMock 627s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 627s --- SKIP: TestWithWslPathMock (0.00s) 627s === RUN TestWithWslInfoMock 627s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 627s --- SKIP: TestWithWslInfoMock (0.00s) 627s === RUN TestWithCmdExeMock 627s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 627s --- SKIP: TestWithCmdExeMock (0.00s) 627s === CONT TestConnect 627s === RUN TestConnect/Success 627s === PAUSE TestConnect/Success 627s === RUN TestConnect/Error_dialing_an_address_that_is_not_serving 627s === PAUSE TestConnect/Error_dialing_an_address_that_is_not_serving 627s === CONT TestConnect/Success 627s === CONT TestStop 627s time="2024-04-19T08:36:49Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:34843" 629s time="2024-04-19T08:36:51Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 629s time="2024-04-19T08:36:51Z" level=info msg="MockWindowsAgent: Connected ready" 629s time="2024-04-19T08:36:51Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 639s time="2024-04-19T08:37:01Z" level=warning msg="Streamserver: could not gather info after command completion: could not obtain pro status: pro status: /usr/bin/bash: error: context canceled.\n Stdout: \n Stderr: " 639s time="2024-04-19T08:37:01Z" level=warning msg="Streamserver: could not stream back info after command completion" 639s time="2024-04-19T08:37:01Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 639s time="2024-04-19T08:37:01Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 639s time="2024-04-19T08:37:01Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 639s --- PASS: TestStop (11.52s) 639s === CONT TestServe 639s time="2024-04-19T08:37:01Z" level=info msg="MockWindowsAgent: Windows-agent mock serving on 127.0.0.1:44599" 640s time="2024-04-19T08:37:02Z" level=info msg="MockWindowsAgent: LandscapeConfigCommands ready" 640s time="2024-04-19T08:37:02Z" level=info msg="MockWindowsAgent: Connected ready" 640s time="2024-04-19T08:37:02Z" level=info msg="MockWindowsAgent: ProAttachmentCommands ready" 646s --- PASS: TestServe (6.97s) 646s time="2024-04-19T08:37:08Z" level=warning msg="context.Background MockWindowsAgent: Connected stopped: rpc error: code = Canceled desc = context canceled" 646s time="2024-04-19T08:37:08Z" level=warning msg="context.Background MockWindowsAgent: ProAttachmentCommands stopped: rpc error: code = Canceled desc = context canceled" 646s time="2024-04-19T08:37:08Z" level=warning msg="context.Background MockWindowsAgent: LandscapeConfigCommands stopped: rpc error: code = Canceled desc = context canceled" 646s === CONT TestConnect/Error_dialing_an_address_that_is_not_serving 666s --- PASS: TestConnect (0.00s) 666s --- PASS: TestConnect/Success (0.30s) 666s --- PASS: TestConnect/Error_dialing_an_address_that_is_not_serving (20.00s) 666s PASS 666s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/streams 39.207s 667s === RUN TestInfo 667s === PAUSE TestInfo 667s === RUN TestWslDistroName 667s === PAUSE TestWslDistroName 667s === RUN TestUserProfileDir 667s === PAUSE TestUserProfileDir 667s === RUN TestProStatus 667s === PAUSE TestProStatus 668s === RUN TestProAttach 668s === PAUSE TestProAttach 668s === RUN TestProDetach 668s === PAUSE TestProDetach 668s === RUN TestLandscapeEnable 668s === PAUSE TestLandscapeEnable 668s === RUN TestWindowsHostAddress 668s === PAUSE TestWindowsHostAddress 668s === RUN TestLandscapeDisable 668s === PAUSE TestLandscapeDisable 668s === RUN TestRealBackend 668s === PAUSE TestRealBackend 668s === RUN TestWithProMock 668s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithProMock (0.00s) 668s === RUN TestWithLandscapeConfigMock 668s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithLandscapeConfigMock (0.00s) 668s === RUN TestWithWslPathMock 668s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithWslPathMock (0.00s) 668s === RUN TestWithWslInfoMock 668s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithWslInfoMock (0.00s) 668s === RUN TestWithCmdExeMock 668s mock_executables.go:629: Skipped because it is not a real test, but rather a mocked executable 668s --- SKIP: TestWithCmdExeMock (0.00s) 668s === CONT TestInfo 668s === RUN TestInfo/Success 668s === PAUSE TestInfo/Success 668s === RUN TestInfo/Error_when_WslDistroName_fails 668s === PAUSE TestInfo/Error_when_WslDistroName_fails 668s === RUN TestInfo/Error_when_pro_status_command_fails 668s === PAUSE TestInfo/Error_when_pro_status_command_fails 668s === RUN TestInfo/Error_when_pro_status_output_cannot_be_parsed 668s === PAUSE TestInfo/Error_when_pro_status_output_cannot_be_parsed 668s === RUN TestInfo/Error_when_/etc/os-release_cannot_be_read 668s === PAUSE TestInfo/Error_when_/etc/os-release_cannot_be_read 668s === RUN TestInfo/Error_whem_/etc/os-release_returns_bad_contents 668s === PAUSE TestInfo/Error_whem_/etc/os-release_returns_bad_contents 668s === RUN TestInfo/Error_when_hostname_cannot_be_obtained 668s === PAUSE TestInfo/Error_when_hostname_cannot_be_obtained 668s === CONT TestRealBackend 668s --- PASS: TestRealBackend (0.00s) 668s === CONT TestLandscapeDisable 668s === RUN TestLandscapeDisable/Success 668s === PAUSE TestLandscapeDisable/Success 668s === RUN TestLandscapeDisable/Error_when_the_landscape-config_command_fails 668s === PAUSE TestLandscapeDisable/Error_when_the_landscape-config_command_fails 668s === CONT TestWindowsHostAddress 668s === RUN TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 668s === PAUSE TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 668s === RUN TestWindowsHostAddress/Success_without_NAT 668s === PAUSE TestWindowsHostAddress/Success_without_NAT 668s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 668s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 668s === RUN TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 668s === PAUSE TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 668s === RUN TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 668s === PAUSE TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 668s === CONT TestLandscapeEnable 668s === RUN TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 668s === PAUSE TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 668s === RUN TestLandscapeEnable/Error_when_the_landscape-config_command_fails 668s === PAUSE TestLandscapeEnable/Error_when_the_landscape-config_command_fails 668s === RUN TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 668s === PAUSE TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 668s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 668s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 668s === RUN TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 668s === PAUSE TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 668s === RUN TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 668s === PAUSE TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 668s === RUN TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 668s === PAUSE TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 668s === RUN TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 668s === PAUSE TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 668s === RUN TestLandscapeEnable/Success 668s === PAUSE TestLandscapeEnable/Success 668s === RUN TestLandscapeEnable/Success_overriding_computer_title 668s === PAUSE TestLandscapeEnable/Success_overriding_computer_title 668s === CONT TestProDetach 668s === RUN TestProDetach/success_on_unattached_distro 668s === PAUSE TestProDetach/success_on_unattached_distro 668s === RUN TestProDetach/success_on_attached_distro 668s === PAUSE TestProDetach/success_on_attached_distro 668s === RUN TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 668s === PAUSE TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 668s === RUN TestProDetach/error_on_'pro_detach'_error_and_some_reason 668s === PAUSE TestProDetach/error_on_'pro_detach'_error_and_some_reason 668s === RUN TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 668s === PAUSE TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 668s === CONT TestProAttach 668s === RUN TestProAttach/success 668s === PAUSE TestProAttach/success 668s === RUN TestProAttach/error_on_'pro_attach'_error 668s === PAUSE TestProAttach/error_on_'pro_attach'_error 668s === CONT TestProStatus 668s === RUN TestProStatus/error_on_'pro_attach'_error 668s === PAUSE TestProStatus/error_on_'pro_attach'_error 668s === RUN TestProStatus/success_on_unattached_distro 668s === PAUSE TestProStatus/success_on_unattached_distro 668s === RUN TestProStatus/success_on_attached_distro 668s === PAUSE TestProStatus/success_on_attached_distro 668s === RUN TestProStatus/error_on_'pro_attach'_returning_bad_output 668s === PAUSE TestProStatus/error_on_'pro_attach'_returning_bad_output 668s === CONT TestUserProfileDir 668s === RUN TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 668s === PAUSE TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 668s === RUN TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 668s === PAUSE TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 668s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 668s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 668s === RUN TestUserProfileDir/Error_when_cmd.exe_does_not_exist 668s === PAUSE TestUserProfileDir/Error_when_cmd.exe_does_not_exist 668s === RUN TestUserProfileDir/Success_with_cached_cmd.exe_path 668s === PAUSE TestUserProfileDir/Success_with_cached_cmd.exe_path 668s === RUN TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 668s === PAUSE TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 668s === RUN TestUserProfileDir/Error_on_wslpath_error 668s === PAUSE TestUserProfileDir/Error_on_wslpath_error 668s === RUN TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 668s === PAUSE TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 668s === RUN TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 668s === PAUSE TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 668s === RUN TestUserProfileDir/Error_on_cmd.exe_error 668s === PAUSE TestUserProfileDir/Error_on_cmd.exe_error 668s === CONT TestWslDistroName 668s === RUN TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 668s === PAUSE TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 668s === RUN TestWslDistroName/Success_using_wslpath 668s === PAUSE TestWslDistroName/Success_using_wslpath 668s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 668s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 668s === RUN TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 668s === PAUSE TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 668s === CONT TestInfo/Success 669s === CONT TestInfo/Error_when_hostname_cannot_be_obtained 670s === CONT TestInfo/Error_whem_/etc/os-release_returns_bad_contents 672s === CONT TestInfo/Error_when_/etc/os-release_cannot_be_read 673s === CONT TestInfo/Error_when_pro_status_output_cannot_be_parsed 674s === CONT TestInfo/Error_when_pro_status_command_fails 675s === CONT TestInfo/Error_when_WslDistroName_fails 677s --- PASS: TestInfo (0.00s) 677s --- PASS: TestInfo/Success (1.50s) 677s --- PASS: TestInfo/Error_when_hostname_cannot_be_obtained (1.27s) 677s --- PASS: TestInfo/Error_whem_/etc/os-release_returns_bad_contents (1.33s) 677s --- PASS: TestInfo/Error_when_/etc/os-release_cannot_be_read (1.13s) 677s --- PASS: TestInfo/Error_when_pro_status_output_cannot_be_parsed (1.22s) 677s --- PASS: TestInfo/Error_when_pro_status_command_fails (1.16s) 677s --- PASS: TestInfo/Error_when_WslDistroName_fails (1.56s) 677s === CONT TestLandscapeDisable/Success 678s === CONT TestWindowsHostAddress/Error_when_wslinfo_returns_an_error 679s === CONT TestLandscapeDisable/Error_when_the_landscape-config_command_fails 680s --- PASS: TestLandscapeDisable (0.00s) 680s --- PASS: TestLandscapeDisable/Success (1.12s) 680s --- PASS: TestLandscapeDisable/Error_when_the_landscape-config_command_fails (1.13s) 680s === CONT TestLandscapeEnable/Error_when_the_config_file_cannot_be_written 680s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP 681s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed 683s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback 684s === CONT TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback 685s === CONT TestWindowsHostAddress/Success_without_NAT 686s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP 688s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed 689s === CONT TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist 690s === CONT TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist 691s --- PASS: TestWindowsHostAddress (0.00s) 691s --- PASS: TestWindowsHostAddress/Error_when_wslinfo_returns_an_error (1.39s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_has_an_ill-formed_IP (1.08s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_is_ill-formed (1.17s) 691s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_loopback (1.35s) 691s --- PASS: TestWindowsHostAddress/Success_with_NAT,_nameserver_is_not_loopback (1.31s) 691s --- PASS: TestWindowsHostAddress/Success_without_NAT (1.24s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_has_an_ill-formed_IP (1.11s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_is_ill-formed (1.43s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/proc/net/route_does_not_exist (1.11s) 691s --- PASS: TestWindowsHostAddress/Error_with_NAT_when_/etc/resolv.conf_does_not_exist (1.25s) 691s === CONT TestProDetach/success_on_unattached_distro 693s === CONT TestLandscapeEnable/Success_overriding_computer_title 693s time="2024-04-19T08:37:55Z" level=info msg="Landscape config contains key \"computer_title\". Its value will be overridden." 694s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_computer_title 694s === CONT TestLandscapeEnable/Success 695s system_test.go:456: testdata/TestLandscapeEnable/golden/success 695s === CONT TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist 695s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided 695s time="2024-04-19T08:37:57Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 696s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided 696s === CONT TestLandscapeEnable/Success_overriding_the_SSL_certficate_path 699s system_test.go:456: testdata/TestLandscapeEnable/golden/success_overriding_the_ssl_certficate_path 699s === CONT TestLandscapeEnable/Error_when_the_file_cannot_be_parsed 699s === CONT TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 699s time="2024-04-19T08:38:01Z" level=info msg="Landscape config contains key \"tags\". Its value will not be overridden." 700s system_test.go:456: testdata/TestLandscapeEnable/golden/do_not_append_wsl_tag_when_config_tag_is_provided_but_empty 700s === CONT TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path 701s === CONT TestLandscapeEnable/Error_when_the_landscape-config_command_fails 702s --- PASS: TestLandscapeEnable (0.00s) 702s --- PASS: TestLandscapeEnable/Error_when_the_config_file_cannot_be_written (0.00s) 702s --- PASS: TestLandscapeEnable/Success_overriding_computer_title (1.22s) 702s --- PASS: TestLandscapeEnable/Success (1.30s) 702s --- PASS: TestLandscapeEnable/Error_when_the_Landscape_user_does_not_exist (0.00s) 702s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided (1.20s) 702s --- PASS: TestLandscapeEnable/Success_overriding_the_SSL_certficate_path (2.40s) 702s --- PASS: TestLandscapeEnable/Error_when_the_file_cannot_be_parsed (0.00s) 702s --- PASS: TestLandscapeEnable/Do_not_append_wsl_tag_when_config_tag_is_provided_but_empty (1.40s) 702s --- PASS: TestLandscapeEnable/Error_when_failing_to_override_the_SSL_certficate_path (1.12s) 702s --- PASS: TestLandscapeEnable/Error_when_the_landscape-config_command_fails (1.13s) 702s === CONT TestProAttach/success 704s === CONT TestProDetach/error_on_'pro_detach'_error_with_bad_JSON 705s === CONT TestProDetach/error_on_'pro_detach'_error_and_some_reason 706s === CONT TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason 708s === CONT TestProDetach/success_on_attached_distro 709s --- PASS: TestProDetach (0.00s) 709s --- PASS: TestProDetach/success_on_unattached_distro (1.21s) 709s --- PASS: TestProDetach/error_on_'pro_detach'_error_with_bad_JSON (1.44s) 709s --- PASS: TestProDetach/error_on_'pro_detach'_error_and_some_reason (1.24s) 709s --- PASS: TestProDetach/error_on_'pro_detach'_returning_error_and_no_reason (1.42s) 709s --- PASS: TestProDetach/success_on_attached_distro (1.43s) 709s === CONT TestProStatus/error_on_'pro_attach'_error 711s === CONT TestProAttach/error_on_'pro_attach'_error 712s --- PASS: TestProAttach (0.00s) 712s --- PASS: TestProAttach/success (1.30s) 712s --- PASS: TestProAttach/error_on_'pro_attach'_error (1.34s) 712s === CONT TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts 714s === CONT TestProStatus/error_on_'pro_attach'_returning_bad_output 716s === CONT TestProStatus/success_on_attached_distro 717s === CONT TestProStatus/success_on_unattached_distro 718s --- PASS: TestProStatus (0.00s) 718s --- PASS: TestProStatus/error_on_'pro_attach'_error (1.43s) 718s --- PASS: TestProStatus/error_on_'pro_attach'_returning_bad_output (1.12s) 718s --- PASS: TestProStatus/success_on_attached_distro (1.12s) 718s --- PASS: TestProStatus/success_on_unattached_distro (1.11s) 718s === CONT TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME 718s === CONT TestUserProfileDir/Error_on_cmd.exe_error 719s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts 719s system_test.go:205: Removing default proc/mounts 719s === CONT TestUserProfileDir/Error_when_wslpath_returns_a_bad_path 722s === CONT TestUserProfileDir/Error_on_wslpath_error 724s === CONT TestUserProfileDir/Success_with_a_single_9P_filesystem_mount 727s === CONT TestUserProfileDir/Success_with_cached_cmd.exe_path 730s === CONT TestUserProfileDir/Error_when_cmd.exe_does_not_exist 730s === CONT TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts 730s system_test.go:205: Removing default proc/mounts 730s === CONT TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts 732s --- PASS: TestUserProfileDir (0.00s) 732s --- PASS: TestUserProfileDir/Success_with_multiple_9P_filesystem_mounts (2.52s) 732s --- PASS: TestUserProfileDir/Error_on_cmd.exe_error (1.38s) 732s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_/proc/mounts (0.00s) 732s --- PASS: TestUserProfileDir/Error_when_wslpath_returns_a_bad_path (2.56s) 732s --- PASS: TestUserProfileDir/Error_on_wslpath_error (2.74s) 732s --- PASS: TestUserProfileDir/Success_with_a_single_9P_filesystem_mount (2.28s) 732s --- PASS: TestUserProfileDir/Success_with_cached_cmd.exe_path (2.77s) 732s --- PASS: TestUserProfileDir/Error_when_cmd.exe_does_not_exist (0.00s) 732s --- PASS: TestUserProfileDir/Error_finding_cmd.exe_because_there_is_no_Windows_FS_in_/proc/mounts (0.00s) 732s --- PASS: TestUserProfileDir/Success_with_multiple_types_of_filesystem_mounts (2.39s) 732s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text 733s === CONT TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails 734s === CONT TestWslDistroName/Success_using_wslpath 736s --- PASS: TestWslDistroName (0.00s) 736s --- PASS: TestWslDistroName/Success_reading_from_WSL_DISTRO_NAME (0.00s) 736s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_returns_bad_text (1.37s) 736s --- PASS: TestWslDistroName/Error_when_WSL_DISTRO_NAME_is_empty_and_wslpath_fails (1.11s) 736s --- PASS: TestWslDistroName/Success_using_wslpath (1.25s) 736s PASS 736s ok github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/system 68.213s 736s ? github.com/canonical/ubuntu-pro-for-wsl/wsl-pro-service/internal/testutils [no test files] 736s autopkgtest [08:38:38]: test command1: -----------------------] 737s command1 PASS 737s autopkgtest [08:38:39]: test command1: - - - - - - - - - - results - - - - - - - - - - 737s autopkgtest [08:38:39]: @@@@@@@@@@@@@@@@@@@@ summary 737s command1 PASS 752s Creating nova instance adt-noble-s390x-wsl-pro-service-20240419-082622-juju-7f2275-prod-proposed-migration-environment-2-df3d246b-01e1-4eba-961d-a780a1f86ec8 from image adt/ubuntu-noble-s390x-server-20240418.img (UUID 85e53509-ea4e-4742-afdb-a30c7e328507)...