0s autopkgtest [01:08:05]: starting date and time: 2024-11-05 01:08:05+0000 0s autopkgtest [01:08:05]: git checkout: 6f3be7a8 Fix armhf LXD image generation for plucky 0s autopkgtest [01:08:05]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.rxpgqm4k/out --timeout-copy=6000 --setup-commands 'ln -s /dev/null /etc/systemd/system/bluetooth.service; printf "http_proxy=http://squid.internal:3128\nhttps_proxy=http://squid.internal:3128\nno_proxy=127.0.0.1,127.0.1.1,login.ubuntu.com,localhost,localdomain,novalocal,internal,archive.ubuntu.com,ports.ubuntu.com,security.ubuntu.com,ddebs.ubuntu.com,changelogs.ubuntu.com,keyserver.ubuntu.com,launchpadlibrarian.net,launchpadcontent.net,launchpad.net,10.24.0.0/24,keystone.ps5.canonical.com,objectstorage.prodstack5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:etcd,src:golang-opentelemetry-contrib,src:golang-opentelemetry-otel,src:golang-opentelemetry-proto --apt-upgrade vip-manager2 --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 '--env=ADT_TEST_TRIGGERS=etcd/3.5.16-3 golang-opentelemetry-contrib/0.56.0-4 golang-opentelemetry-otel/1.31.0-3 golang-opentelemetry-proto/1.3.1-2' -- lxd -r lxd-armhf-10.145.243.182 lxd-armhf-10.145.243.182:autopkgtest/ubuntu/plucky/armhf 52s autopkgtest [01:08:57]: testbed dpkg architecture: armhf 54s autopkgtest [01:08:59]: testbed apt version: 2.9.8 54s autopkgtest [01:08:59]: @@@@@@@@@@@@@@@@@@@@ test bed setup 62s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [73.9 kB] 62s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [1772 kB] 62s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/restricted Sources [7016 B] 62s Get:4 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [22.2 kB] 62s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [177 kB] 62s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf Packages [217 kB] 62s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf Packages [1332 kB] 62s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse armhf Packages [20.3 kB] 63s Fetched 3622 kB in 1s (3386 kB/s) 63s Reading package lists... 80s tee: /proc/self/fd/2: Permission denied 101s Hit:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease 101s Hit:2 http://ftpmaster.internal/ubuntu plucky InRelease 101s Hit:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease 101s Hit:4 http://ftpmaster.internal/ubuntu plucky-security InRelease 102s Reading package lists... 102s Reading package lists... 103s Building dependency tree... 103s Reading state information... 103s Calculating upgrade... 104s The following packages were automatically installed and are no longer required: 104s libperl5.38t64 perl-modules-5.38 104s Use 'apt autoremove' to remove them. 104s The following NEW packages will be installed: 104s libperl5.40 perl-modules-5.40 104s The following packages will be upgraded: 104s base-files distro-info-data fwupd gcc-14-base info install-info iproute2 104s libatomic1 libblockdev-crypto3 libblockdev-fs3 libblockdev-loop3 104s libblockdev-mdraid3 libblockdev-nvme3 libblockdev-part3 libblockdev-swap3 104s libblockdev-utils3 libblockdev3 libdb5.3t64 libdw1t64 libelf1t64 libevdev2 104s libftdi1-2 libfwupd2 libgcc-s1 libinih1 libkeyutils1 libldap-common libldap2 104s liblocale-gettext-perl libpipeline1 libsgutils2-1.46-2 libstdc++6 104s libtext-charwidth-perl libtext-iconv-perl libtraceevent1 104s libtraceevent1-plugin motd-news-config nano perl perl-base python3-configobj 104s python3-json-pointer python3-lazr.uri python3-oauthlib python3-zipp 104s sg3-utils sg3-utils-udev vim-common vim-tiny xxd 104s 50 upgraded, 2 newly installed, 0 to remove and 0 not upgraded. 104s Need to get 20.0 MB of archives. 104s After this operation, 42.8 MB of additional disk space will be used. 104s Get:1 http://ftpmaster.internal/ubuntu plucky/main armhf motd-news-config all 13.5ubuntu2 [5274 B] 104s Get:2 http://ftpmaster.internal/ubuntu plucky/main armhf base-files armhf 13.5ubuntu2 [68.6 kB] 104s Get:3 http://ftpmaster.internal/ubuntu plucky/main armhf perl-modules-5.40 all 5.40.0-6 [3214 kB] 104s Get:4 http://ftpmaster.internal/ubuntu plucky/main armhf libperl5.40 armhf 5.40.0-6 [4140 kB] 104s Get:5 http://ftpmaster.internal/ubuntu plucky/main armhf perl armhf 5.40.0-6 [262 kB] 104s Get:6 http://ftpmaster.internal/ubuntu plucky/main armhf perl-base armhf 5.40.0-6 [1674 kB] 105s Get:7 http://ftpmaster.internal/ubuntu plucky/main armhf liblocale-gettext-perl armhf 1.07-7build1 [15.0 kB] 105s Get:8 http://ftpmaster.internal/ubuntu plucky/main armhf libtext-iconv-perl armhf 1.7-8build4 [12.8 kB] 105s Get:9 http://ftpmaster.internal/ubuntu plucky/main armhf libtext-charwidth-perl armhf 0.04-11build4 [9128 B] 105s Get:10 http://ftpmaster.internal/ubuntu plucky/main armhf libdb5.3t64 armhf 5.3.28+dfsg2-9 [655 kB] 105s Get:11 http://ftpmaster.internal/ubuntu plucky/main armhf libatomic1 armhf 14.2.0-7ubuntu1 [7842 B] 105s Get:12 http://ftpmaster.internal/ubuntu plucky/main armhf gcc-14-base armhf 14.2.0-7ubuntu1 [51.2 kB] 105s Get:13 http://ftpmaster.internal/ubuntu plucky/main armhf libstdc++6 armhf 14.2.0-7ubuntu1 [711 kB] 105s Get:14 http://ftpmaster.internal/ubuntu plucky/main armhf libgcc-s1 armhf 14.2.0-7ubuntu1 [40.8 kB] 105s Get:15 http://ftpmaster.internal/ubuntu plucky/main armhf install-info armhf 7.1.1-1 [61.4 kB] 105s Get:16 http://ftpmaster.internal/ubuntu plucky/main armhf distro-info-data all 0.63 [6588 B] 105s Get:17 http://ftpmaster.internal/ubuntu plucky/main armhf libdw1t64 armhf 0.192-4 [243 kB] 105s Get:18 http://ftpmaster.internal/ubuntu plucky/main armhf libelf1t64 armhf 0.192-4 [50.2 kB] 105s Get:19 http://ftpmaster.internal/ubuntu plucky/main armhf iproute2 armhf 6.10.0-2ubuntu1 [1082 kB] 105s Get:20 http://ftpmaster.internal/ubuntu plucky/main armhf libkeyutils1 armhf 1.6.3-4ubuntu2 [8712 B] 105s Get:21 http://ftpmaster.internal/ubuntu plucky/main armhf vim-tiny armhf 2:9.1.0777-1ubuntu1 [693 kB] 105s Get:22 http://ftpmaster.internal/ubuntu plucky/main armhf vim-common all 2:9.1.0777-1ubuntu1 [394 kB] 105s Get:23 http://ftpmaster.internal/ubuntu plucky/main armhf xxd armhf 2:9.1.0777-1ubuntu1 [66.8 kB] 105s Get:24 http://ftpmaster.internal/ubuntu plucky/main armhf info armhf 7.1.1-1 [126 kB] 105s Get:25 http://ftpmaster.internal/ubuntu plucky/main armhf libevdev2 armhf 1.13.3+dfsg-1 [29.7 kB] 105s Get:26 http://ftpmaster.internal/ubuntu plucky/main armhf libpipeline1 armhf 1.5.8-1 [26.9 kB] 105s Get:27 http://ftpmaster.internal/ubuntu plucky/main armhf libtraceevent1-plugin armhf 1:1.8.3-1ubuntu1 [18.1 kB] 105s Get:28 http://ftpmaster.internal/ubuntu plucky/main armhf libtraceevent1 armhf 1:1.8.3-1ubuntu1 [52.1 kB] 105s Get:29 http://ftpmaster.internal/ubuntu plucky/main armhf nano armhf 8.2-1 [276 kB] 105s Get:30 http://ftpmaster.internal/ubuntu plucky/main armhf libfwupd2 armhf 1.9.26-2 [125 kB] 105s Get:31 http://ftpmaster.internal/ubuntu plucky/main armhf fwupd armhf 1.9.26-2 [4404 kB] 105s Get:32 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-utils3 armhf 3.2.0-2 [17.4 kB] 105s Get:33 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-crypto3 armhf 3.2.0-2 [22.3 kB] 105s Get:34 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-fs3 armhf 3.2.0-2 [34.3 kB] 105s Get:35 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-loop3 armhf 3.2.0-2 [6552 B] 105s Get:36 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-mdraid3 armhf 3.2.0-2 [13.4 kB] 105s Get:37 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-nvme3 armhf 3.2.0-2 [17.6 kB] 105s Get:38 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-part3 armhf 3.2.0-2 [16.5 kB] 105s Get:39 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev-swap3 armhf 3.2.0-2 [8942 B] 105s Get:40 http://ftpmaster.internal/ubuntu plucky/main armhf libblockdev3 armhf 3.2.0-2 [44.2 kB] 105s Get:41 http://ftpmaster.internal/ubuntu plucky/main armhf libftdi1-2 armhf 1.5-7 [25.7 kB] 105s Get:42 http://ftpmaster.internal/ubuntu plucky/main armhf libinih1 armhf 58-1ubuntu1 [6750 B] 105s Get:43 http://ftpmaster.internal/ubuntu plucky/main armhf libldap-common all 2.6.8+dfsg-1~exp4ubuntu3 [32.3 kB] 105s Get:44 http://ftpmaster.internal/ubuntu plucky/main armhf libldap2 armhf 2.6.8+dfsg-1~exp4ubuntu3 [173 kB] 105s Get:45 http://ftpmaster.internal/ubuntu plucky/main armhf libsgutils2-1.46-2 armhf 1.46-3ubuntu5 [82.5 kB] 105s Get:46 http://ftpmaster.internal/ubuntu plucky/main armhf python3-configobj all 5.0.9-1 [33.9 kB] 105s Get:47 http://ftpmaster.internal/ubuntu plucky/main armhf python3-json-pointer all 2.4-2 [8396 B] 105s Get:48 http://ftpmaster.internal/ubuntu plucky/main armhf python3-lazr.uri all 1.0.6-4 [13.6 kB] 105s Get:49 http://ftpmaster.internal/ubuntu plucky/main armhf python3-oauthlib all 3.2.2-2 [89.8 kB] 105s Get:50 http://ftpmaster.internal/ubuntu plucky/main armhf python3-zipp all 3.20.2-1 [10.1 kB] 105s Get:51 http://ftpmaster.internal/ubuntu plucky/main armhf sg3-utils armhf 1.46-3ubuntu5 [816 kB] 105s Get:52 http://ftpmaster.internal/ubuntu plucky/main armhf sg3-utils-udev all 1.46-3ubuntu5 [5916 B] 106s Preconfiguring packages ... 106s Fetched 20.0 MB in 2s (12.8 MB/s) 106s (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 ... 59386 files and directories currently installed.) 106s Preparing to unpack .../motd-news-config_13.5ubuntu2_all.deb ... 106s Unpacking motd-news-config (13.5ubuntu2) over (13.3ubuntu6) ... 106s Preparing to unpack .../base-files_13.5ubuntu2_armhf.deb ... 106s Unpacking base-files (13.5ubuntu2) over (13.3ubuntu6) ... 106s Setting up base-files (13.5ubuntu2) ... 106s Installing new version of config file /etc/issue ... 106s Installing new version of config file /etc/issue.net ... 106s Installing new version of config file /etc/lsb-release ... 106s motd-news.service is a disabled or a static unit not running, not starting it. 107s (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 ... 59386 files and directories currently installed.) 107s Preparing to unpack .../perl_5.40.0-6_armhf.deb ... 107s Unpacking perl (5.40.0-6) over (5.38.2-5) ... 107s Selecting previously unselected package perl-modules-5.40. 107s Preparing to unpack .../perl-modules-5.40_5.40.0-6_all.deb ... 107s Unpacking perl-modules-5.40 (5.40.0-6) ... 107s Selecting previously unselected package libperl5.40:armhf. 107s Preparing to unpack .../libperl5.40_5.40.0-6_armhf.deb ... 107s Unpacking libperl5.40:armhf (5.40.0-6) ... 107s Preparing to unpack .../perl-base_5.40.0-6_armhf.deb ... 107s Unpacking perl-base (5.40.0-6) over (5.38.2-5) ... 107s Setting up perl-base (5.40.0-6) ... 107s (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 ... 61462 files and directories currently installed.) 107s Preparing to unpack .../liblocale-gettext-perl_1.07-7build1_armhf.deb ... 107s Unpacking liblocale-gettext-perl (1.07-7build1) over (1.07-7) ... 107s Preparing to unpack .../libtext-iconv-perl_1.7-8build4_armhf.deb ... 107s Unpacking libtext-iconv-perl:armhf (1.7-8build4) over (1.7-8build3) ... 107s Preparing to unpack .../libtext-charwidth-perl_0.04-11build4_armhf.deb ... 107s Unpacking libtext-charwidth-perl:armhf (0.04-11build4) over (0.04-11build3) ... 107s Preparing to unpack .../libdb5.3t64_5.3.28+dfsg2-9_armhf.deb ... 107s Unpacking libdb5.3t64:armhf (5.3.28+dfsg2-9) over (5.3.28+dfsg2-7) ... 107s Setting up libdb5.3t64:armhf (5.3.28+dfsg2-9) ... 107s (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 ... 61462 files and directories currently installed.) 107s Preparing to unpack .../libatomic1_14.2.0-7ubuntu1_armhf.deb ... 107s Unpacking libatomic1:armhf (14.2.0-7ubuntu1) over (14.2.0-4ubuntu2) ... 108s Preparing to unpack .../gcc-14-base_14.2.0-7ubuntu1_armhf.deb ... 108s Unpacking gcc-14-base:armhf (14.2.0-7ubuntu1) over (14.2.0-4ubuntu2) ... 108s Setting up gcc-14-base:armhf (14.2.0-7ubuntu1) ... 108s (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 ... 61462 files and directories currently installed.) 108s Preparing to unpack .../libstdc++6_14.2.0-7ubuntu1_armhf.deb ... 108s Unpacking libstdc++6:armhf (14.2.0-7ubuntu1) over (14.2.0-4ubuntu2) ... 108s Setting up libstdc++6:armhf (14.2.0-7ubuntu1) ... 108s (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 ... 61462 files and directories currently installed.) 108s Preparing to unpack .../libgcc-s1_14.2.0-7ubuntu1_armhf.deb ... 108s Unpacking libgcc-s1:armhf (14.2.0-7ubuntu1) over (14.2.0-4ubuntu2) ... 108s Setting up libgcc-s1:armhf (14.2.0-7ubuntu1) ... 108s (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 ... 61462 files and directories currently installed.) 108s Preparing to unpack .../install-info_7.1.1-1_armhf.deb ... 108s Unpacking install-info (7.1.1-1) over (7.1-3build2) ... 108s Setting up install-info (7.1.1-1) ... 108s (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 ... 61462 files and directories currently installed.) 108s Preparing to unpack .../00-distro-info-data_0.63_all.deb ... 108s Unpacking distro-info-data (0.63) over (0.62) ... 108s Preparing to unpack .../01-libdw1t64_0.192-4_armhf.deb ... 108s Unpacking libdw1t64:armhf (0.192-4) over (0.191-2) ... 108s Preparing to unpack .../02-libelf1t64_0.192-4_armhf.deb ... 108s Unpacking libelf1t64:armhf (0.192-4) over (0.191-2) ... 108s Preparing to unpack .../03-iproute2_6.10.0-2ubuntu1_armhf.deb ... 108s Unpacking iproute2 (6.10.0-2ubuntu1) over (6.10.0-2) ... 108s Preparing to unpack .../04-libkeyutils1_1.6.3-4ubuntu2_armhf.deb ... 108s Unpacking libkeyutils1:armhf (1.6.3-4ubuntu2) over (1.6.3-3build1) ... 108s Preparing to unpack .../05-vim-tiny_2%3a9.1.0777-1ubuntu1_armhf.deb ... 108s Unpacking vim-tiny (2:9.1.0777-1ubuntu1) over (2:9.1.0496-1ubuntu6) ... 109s Preparing to unpack .../06-vim-common_2%3a9.1.0777-1ubuntu1_all.deb ... 109s Unpacking vim-common (2:9.1.0777-1ubuntu1) over (2:9.1.0496-1ubuntu6) ... 109s Preparing to unpack .../07-xxd_2%3a9.1.0777-1ubuntu1_armhf.deb ... 109s Unpacking xxd (2:9.1.0777-1ubuntu1) over (2:9.1.0496-1ubuntu6) ... 109s Preparing to unpack .../08-info_7.1.1-1_armhf.deb ... 109s Unpacking info (7.1.1-1) over (7.1-3build2) ... 109s Preparing to unpack .../09-libevdev2_1.13.3+dfsg-1_armhf.deb ... 109s Unpacking libevdev2:armhf (1.13.3+dfsg-1) over (1.13.2+dfsg-1) ... 109s Preparing to unpack .../10-libpipeline1_1.5.8-1_armhf.deb ... 109s Unpacking libpipeline1:armhf (1.5.8-1) over (1.5.7-2) ... 109s Preparing to unpack .../11-libtraceevent1-plugin_1%3a1.8.3-1ubuntu1_armhf.deb ... 109s Unpacking libtraceevent1-plugin:armhf (1:1.8.3-1ubuntu1) over (1:1.8.2-1ubuntu3) ... 109s Preparing to unpack .../12-libtraceevent1_1%3a1.8.3-1ubuntu1_armhf.deb ... 109s Unpacking libtraceevent1:armhf (1:1.8.3-1ubuntu1) over (1:1.8.2-1ubuntu3) ... 109s Preparing to unpack .../13-nano_8.2-1_armhf.deb ... 109s Unpacking nano (8.2-1) over (8.1-1) ... 109s Preparing to unpack .../14-libfwupd2_1.9.26-2_armhf.deb ... 109s Unpacking libfwupd2:armhf (1.9.26-2) over (1.9.24-1) ... 109s Preparing to unpack .../15-fwupd_1.9.26-2_armhf.deb ... 109s Unpacking fwupd (1.9.26-2) over (1.9.24-1) ... 109s Preparing to unpack .../16-libblockdev-utils3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-utils3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../17-libblockdev-crypto3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-crypto3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../18-libblockdev-fs3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-fs3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../19-libblockdev-loop3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-loop3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../20-libblockdev-mdraid3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-mdraid3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../21-libblockdev-nvme3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-nvme3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../22-libblockdev-part3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-part3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../23-libblockdev-swap3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev-swap3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../24-libblockdev3_3.2.0-2_armhf.deb ... 109s Unpacking libblockdev3:armhf (3.2.0-2) over (3.1.1-2) ... 109s Preparing to unpack .../25-libftdi1-2_1.5-7_armhf.deb ... 109s Unpacking libftdi1-2:armhf (1.5-7) over (1.5-6build5) ... 109s Preparing to unpack .../26-libinih1_58-1ubuntu1_armhf.deb ... 109s Unpacking libinih1:armhf (58-1ubuntu1) over (55-1ubuntu2) ... 109s Preparing to unpack .../27-libldap-common_2.6.8+dfsg-1~exp4ubuntu3_all.deb ... 109s Unpacking libldap-common (2.6.8+dfsg-1~exp4ubuntu3) over (2.6.8+dfsg-1~exp4ubuntu1) ... 109s Preparing to unpack .../28-libldap2_2.6.8+dfsg-1~exp4ubuntu3_armhf.deb ... 109s Unpacking libldap2:armhf (2.6.8+dfsg-1~exp4ubuntu3) over (2.6.8+dfsg-1~exp4ubuntu1) ... 109s Preparing to unpack .../29-libsgutils2-1.46-2_1.46-3ubuntu5_armhf.deb ... 109s Unpacking libsgutils2-1.46-2:armhf (1.46-3ubuntu5) over (1.46-3ubuntu4) ... 109s Preparing to unpack .../30-python3-configobj_5.0.9-1_all.deb ... 109s Unpacking python3-configobj (5.0.9-1) over (5.0.8-3) ... 110s Preparing to unpack .../31-python3-json-pointer_2.4-2_all.deb ... 110s Unpacking python3-json-pointer (2.4-2) over (2.0-0ubuntu1) ... 110s Preparing to unpack .../32-python3-lazr.uri_1.0.6-4_all.deb ... 110s Unpacking python3-lazr.uri (1.0.6-4) over (1.0.6-3) ... 110s Preparing to unpack .../33-python3-oauthlib_3.2.2-2_all.deb ... 110s Unpacking python3-oauthlib (3.2.2-2) over (3.2.2-1) ... 110s Preparing to unpack .../34-python3-zipp_3.20.2-1_all.deb ... 110s Unpacking python3-zipp (3.20.2-1) over (3.20.0-1) ... 110s Preparing to unpack .../35-sg3-utils_1.46-3ubuntu5_armhf.deb ... 110s Unpacking sg3-utils (1.46-3ubuntu5) over (1.46-3ubuntu4) ... 110s Preparing to unpack .../36-sg3-utils-udev_1.46-3ubuntu5_all.deb ... 110s Unpacking sg3-utils-udev (1.46-3ubuntu5) over (1.46-3ubuntu4) ... 110s Setting up libpipeline1:armhf (1.5.8-1) ... 110s Setting up motd-news-config (13.5ubuntu2) ... 110s Setting up libtext-iconv-perl:armhf (1.7-8build4) ... 110s Setting up libtext-charwidth-perl:armhf (0.04-11build4) ... 110s Setting up libkeyutils1:armhf (1.6.3-4ubuntu2) ... 110s Setting up distro-info-data (0.63) ... 110s Setting up libinih1:armhf (58-1ubuntu1) ... 110s Setting up libfwupd2:armhf (1.9.26-2) ... 110s Setting up libsgutils2-1.46-2:armhf (1.46-3ubuntu5) ... 110s Setting up python3-lazr.uri (1.0.6-4) ... 110s Setting up python3-zipp (3.20.2-1) ... 110s Setting up libldap-common (2.6.8+dfsg-1~exp4ubuntu3) ... 110s Setting up xxd (2:9.1.0777-1ubuntu1) ... 110s Setting up libelf1t64:armhf (0.192-4) ... 110s Setting up libdw1t64:armhf (0.192-4) ... 110s Setting up libftdi1-2:armhf (1.5-7) ... 110s Setting up python3-oauthlib (3.2.2-2) ... 110s Setting up python3-configobj (5.0.9-1) ... 111s Setting up vim-common (2:9.1.0777-1ubuntu1) ... 111s Installing new version of config file /etc/vim/vimrc ... 111s Setting up libblockdev-utils3:armhf (3.2.0-2) ... 111s Setting up libatomic1:armhf (14.2.0-7ubuntu1) ... 111s Setting up libblockdev-nvme3:armhf (3.2.0-2) ... 111s Setting up nano (8.2-1) ... 111s Setting up libblockdev-fs3:armhf (3.2.0-2) ... 111s Setting up perl-modules-5.40 (5.40.0-6) ... 111s Setting up python3-json-pointer (2.4-2) ... 111s Setting up libtraceevent1:armhf (1:1.8.3-1ubuntu1) ... 111s Setting up libevdev2:armhf (1.13.3+dfsg-1) ... 111s Setting up libldap2:armhf (2.6.8+dfsg-1~exp4ubuntu3) ... 111s Setting up fwupd (1.9.26-2) ... 111s fwupd-offline-update.service is a disabled or a static unit not running, not starting it. 111s fwupd-refresh.service is a disabled or a static unit not running, not starting it. 111s fwupd.service is a disabled or a static unit not running, not starting it. 111s Setting up info (7.1.1-1) ... 111s Setting up liblocale-gettext-perl (1.07-7build1) ... 111s Setting up sg3-utils (1.46-3ubuntu5) ... 111s Setting up libblockdev-mdraid3:armhf (3.2.0-2) ... 111s Setting up libblockdev-crypto3:armhf (3.2.0-2) ... 111s Setting up libblockdev-swap3:armhf (3.2.0-2) ... 111s Setting up iproute2 (6.10.0-2ubuntu1) ... 111s Setting up libblockdev-loop3:armhf (3.2.0-2) ... 111s Setting up vim-tiny (2:9.1.0777-1ubuntu1) ... 111s Setting up libblockdev3:armhf (3.2.0-2) ... 111s Installing new version of config file /etc/libblockdev/3/conf.d/00-default.cfg ... 111s Setting up libblockdev-part3:armhf (3.2.0-2) ... 111s Setting up sg3-utils-udev (1.46-3ubuntu5) ... 111s update-initramfs: deferring update (trigger activated) 111s Setting up libperl5.40:armhf (5.40.0-6) ... 111s Setting up perl (5.40.0-6) ... 111s Setting up libtraceevent1-plugin:armhf (1:1.8.3-1ubuntu1) ... 111s Processing triggers for initramfs-tools (0.142ubuntu34) ... 112s Processing triggers for libc-bin (2.40-1ubuntu3) ... 112s Processing triggers for man-db (2.12.1-3) ... 113s Processing triggers for plymouth-theme-ubuntu-text (24.004.60-1ubuntu10) ... 113s update-initramfs: deferring update (trigger activated) 113s Processing triggers for dbus (1.14.10-4ubuntu5) ... 113s Processing triggers for install-info (7.1.1-1) ... 113s Processing triggers for initramfs-tools (0.142ubuntu34) ... 113s Reading package lists... 114s Building dependency tree... 114s Reading state information... 114s The following packages will be REMOVED: 114s libperl5.38t64* perl-modules-5.38* 115s 0 upgraded, 0 newly installed, 2 to remove and 0 not upgraded. 115s After this operation, 41.6 MB disk space will be freed. 115s (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 ... 61462 files and directories currently installed.) 115s Removing libperl5.38t64:armhf (5.38.2-5) ... 115s Removing perl-modules-5.38 (5.38.2-5) ... 115s Processing triggers for man-db (2.12.1-3) ... 115s Processing triggers for libc-bin (2.40-1ubuntu3) ... 117s autopkgtest [01:10:02]: rebooting testbed after setup commands that affected boot 186s autopkgtest [01:11:11]: testbed running kernel: Linux 6.8.0-47-generic #47~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Wed Oct 2 16:39:14 UTC 2 213s autopkgtest [01:11:38]: @@@@@@@@@@@@@@@@@@@@ apt-source vip-manager2 223s Get:1 http://ftpmaster.internal/ubuntu plucky/universe vip-manager2 2.5.0-1 (dsc) [2487 B] 223s Get:2 http://ftpmaster.internal/ubuntu plucky/universe vip-manager2 2.5.0-1 (tar) [45.4 kB] 223s Get:3 http://ftpmaster.internal/ubuntu plucky/universe vip-manager2 2.5.0-1 (diff) [8284 B] 223s gpgv: Signature made Fri May 17 08:39:51 2024 UTC 223s gpgv: using RSA key 5C48FE6157F49179597087C64C5A6BAB12D2A7AE 223s gpgv: Can't check signature: No public key 223s dpkg-source: warning: cannot verify inline signature for ./vip-manager2_2.5.0-1.dsc: no acceptable signature found 223s autopkgtest [01:11:48]: testing package vip-manager2 version 2.5.0-1 225s autopkgtest [01:11:50]: build not needed 227s autopkgtest [01:11:52]: test test: preparing testbed 237s Reading package lists... 237s Building dependency tree... 237s Reading state information... 237s Starting pkgProblemResolver with broken count: 0 238s Starting 2 pkgProblemResolver with broken count: 0 238s Done 238s The following additional packages will be installed: 238s etcd-client etcd-server liblua5.4-0 ncat vip-manager2 238s The following NEW packages will be installed: 238s autopkgtest-satdep etcd-client etcd-server liblua5.4-0 ncat vip-manager2 238s 0 upgraded, 6 newly installed, 0 to remove and 0 not upgraded. 238s Need to get 19.6 MB/19.6 MB of archives. 238s After this operation, 69.5 MB of additional disk space will be used. 238s Get:1 /tmp/autopkgtest.HIiDQG/1-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [732 B] 238s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf etcd-server armhf 3.5.16-3 [10.7 MB] 239s Get:3 http://ftpmaster.internal/ubuntu plucky/main armhf liblua5.4-0 armhf 5.4.6-3build2 [133 kB] 239s Get:4 http://ftpmaster.internal/ubuntu plucky/universe armhf ncat armhf 7.94+git20230807.3be01efb1+dfsg-4 [217 kB] 239s Get:5 http://ftpmaster.internal/ubuntu plucky/universe armhf vip-manager2 armhf 2.5.0-1 [3562 kB] 239s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf etcd-client armhf 3.5.16-3 [5050 kB] 240s Fetched 19.6 MB in 1s (13.7 MB/s) 240s Selecting previously unselected package etcd-server. 240s (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 ... 59532 files and directories currently installed.) 240s Preparing to unpack .../0-etcd-server_3.5.16-3_armhf.deb ... 240s Unpacking etcd-server (3.5.16-3) ... 240s Selecting previously unselected package liblua5.4-0:armhf. 240s Preparing to unpack .../1-liblua5.4-0_5.4.6-3build2_armhf.deb ... 240s Unpacking liblua5.4-0:armhf (5.4.6-3build2) ... 240s Selecting previously unselected package ncat. 240s Preparing to unpack .../2-ncat_7.94+git20230807.3be01efb1+dfsg-4_armhf.deb ... 240s Unpacking ncat (7.94+git20230807.3be01efb1+dfsg-4) ... 240s Selecting previously unselected package vip-manager2. 240s Preparing to unpack .../3-vip-manager2_2.5.0-1_armhf.deb ... 240s Unpacking vip-manager2 (2.5.0-1) ... 240s Selecting previously unselected package etcd-client. 241s Preparing to unpack .../4-etcd-client_3.5.16-3_armhf.deb ... 241s Unpacking etcd-client (3.5.16-3) ... 241s Selecting previously unselected package autopkgtest-satdep. 241s Preparing to unpack .../5-1-autopkgtest-satdep.deb ... 241s Unpacking autopkgtest-satdep (0) ... 241s Setting up vip-manager2 (2.5.0-1) ... 241s Created symlink '/etc/systemd/system/multi-user.target.wants/vip-manager.service' → '/usr/lib/systemd/system/vip-manager.service'. 241s Setting up etcd-client (3.5.16-3) ... 241s Setting up liblua5.4-0:armhf (5.4.6-3build2) ... 241s Setting up etcd-server (3.5.16-3) ... 241s info: Selecting UID from range 100 to 999 ... 241s 241s info: Selecting GID from range 100 to 999 ... 241s info: Adding system user `etcd' (UID 107) ... 241s info: Adding new group `etcd' (GID 108) ... 241s info: Adding new user `etcd' (UID 107) with group `etcd' ... 241s info: Creating home directory `/var/lib/etcd/' ... 242s Created symlink '/etc/systemd/system/etcd2.service' → '/usr/lib/systemd/system/etcd.service'. 242s Created symlink '/etc/systemd/system/multi-user.target.wants/etcd.service' → '/usr/lib/systemd/system/etcd.service'. 242s Setting up ncat (7.94+git20230807.3be01efb1+dfsg-4) ... 242s Setting up autopkgtest-satdep (0) ... 242s Processing triggers for man-db (2.12.1-3) ... 242s Processing triggers for libc-bin (2.40-1ubuntu3) ... 253s (Reading database ... 59577 files and directories currently installed.) 253s Removing autopkgtest-satdep (0) ... 259s autopkgtest [01:12:24]: test test: [----------------------- 261s ○ etcd.service - etcd - highly-available key value store 261s Loaded: loaded (/usr/lib/systemd/system/etcd.service; enabled; preset: enabled) 261s Active: inactive (dead) since Tue 2024-11-05 01:12:26 UTC; 14ms ago 261s Duration: 19.243s 261s Invocation: 28adea96815e44e08caba45bac6a31bf 261s Docs: https://etcd.io/docs 261s man:etcd 261s Process: 1000 ExecStart=/usr/bin/etcd $DAEMON_ARGS (code=killed, signal=TERM) 261s Main PID: 1000 (code=killed, signal=TERM) 261s 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.851820Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.851924Z","caller":"embed/serve.go:161","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.852088Z","caller":"embed/serve.go:163","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.852157Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopping etcd.service - etcd - highly-available key value store... 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856203Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856362Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856376Z","caller":"embed/etcd.go:380","msg":"closed etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: etcd.service: Deactivated successfully. 261s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopped etcd.service - etcd - highly-available key value store. 261s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 261s {"level":"info","ts":"2024-11-05T01:12:26.930269Z","caller":"etcdmain/etcd.go:482","msg":"running etcd on unsupported architecture since ETCD_UNSUPPORTED_ARCH is set","arch":"arm"} 261s {"level":"warn","ts":"2024-11-05T01:12:26.931390Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 261s {"level":"info","ts":"2024-11-05T01:12:26.931456Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd"]} 261s {"level":"warn","ts":"2024-11-05T01:12:26.931484Z","caller":"etcdmain/etcd.go:105","msg":"'data-dir' was empty; using default","data-dir":"default.etcd"} 261s {"level":"warn","ts":"2024-11-05T01:12:26.931554Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 261s {"level":"info","ts":"2024-11-05T01:12:26.931604Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} 261s {"level":"info","ts":"2024-11-05T01:12:26.932080Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://localhost:2379"]} 261s {"level":"info","ts":"2024-11-05T01:12:26.932272Z","caller":"embed/etcd.go:311","msg":"starting an etcd server","etcd-version":"3.5.16","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.23.2","go-os":"linux","go-arch":"arm","max-cpu-set":8,"max-cpu-available":8,"member-initialized":false,"name":"default","data-dir":"default.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"default.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"],"listen-client-urls":["http://localhost:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"default=http://localhost:2380","initial-cluster-state":"new","initial-cluster-token":"etcd-cluster","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} 261s {"level":"info","ts":"2024-11-05T01:12:26.935282Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"default.etcd/member/snap/db","took":"2.306861ms"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939260Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939383Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939426Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939440Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939458Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} 261s {"level":"info","ts":"2024-11-05T01:12:26.939496Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 261s {"level":"warn","ts":"2024-11-05T01:12:26.946341Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} 261s {"level":"info","ts":"2024-11-05T01:12:26.950557Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} 261s {"level":"info","ts":"2024-11-05T01:12:26.953509Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} 261s {"level":"info","ts":"2024-11-05T01:12:26.956535Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} 261s {"level":"info","ts":"2024-11-05T01:12:26.956727Z","caller":"etcdserver/server.go:757","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"8e9e05c52164694d","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"} 261s {"level":"info","ts":"2024-11-05T01:12:26.956762Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 261s {"level":"info","ts":"2024-11-05T01:12:26.956821Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} 261s {"level":"info","ts":"2024-11-05T01:12:26.957506Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} 261s {"level":"info","ts":"2024-11-05T01:12:26.957658Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} 261s {"level":"info","ts":"2024-11-05T01:12:26.958683Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 262s {"level":"info","ts":"2024-11-05T01:12:26.958876Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"]} 262s {"level":"info","ts":"2024-11-05T01:12:26.960783Z","caller":"embed/etcd.go:280","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"],"listen-client-urls":["http://localhost:2379"],"listen-metrics-urls":[]} 262s {"level":"info","ts":"2024-11-05T01:12:26.960786Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} 262s {"level":"info","ts":"2024-11-05T01:12:26.960849Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340135Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340226Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340268Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340290Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340299Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340312Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} 262s {"level":"info","ts":"2024-11-05T01:12:27.340322Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} 262s {"level":"info","ts":"2024-11-05T01:12:27.342459Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} 262s {"level":"info","ts":"2024-11-05T01:12:27.344191Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:default ClientURLs:[http://localhost:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} 262s {"level":"info","ts":"2024-11-05T01:12:27.344235Z","caller":"embed/serve.go:104","msg":"ready to serve client requests"} 262s {"level":"info","ts":"2024-11-05T01:12:27.344435Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} 262s {"level":"info","ts":"2024-11-05T01:12:27.344499Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} 262s {"level":"info","ts":"2024-11-05T01:12:27.344874Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 262s {"level":"info","ts":"2024-11-05T01:12:27.345337Z","caller":"embed/serve.go:188","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:2379"} 262s {"level":"info","ts":"2024-11-05T01:12:27.345998Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} 262s {"level":"info","ts":"2024-11-05T01:12:27.346098Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} 262s {"level":"info","ts":"2024-11-05T01:12:27.346140Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} 263s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 263s Ncat: Listening on 0.0.0.0:12345 263s 0 263s 2024-11-05 01:12:28.966781 I | No dcs-endpoints specified, trying to use localhost with standard ports! 263s 2024-11-05 01:12:28.967081 I | This is the config that will be used: 263s 2024-11-05 01:12:28.967770 I | IP address 10.0.2.123/32 state is false, desired false 263s dcs-endpoints : [http://127.0.0.1:2379] 263s dcs-type : etcd 263s hostingtype : basic 263s interface : eth0 263s interval : 3000 263s ip : 10.0.2.123 263s manager-type : basic 263s netmask : 32 263s retry-after : 250 263s retry-num : 3 263s trigger-key : service/pgcluster/leader 263s trigger-value : autopkgtest-lxd-rkihls 263s verbose : false 263s version : false 263s 2024-11-05 01:12:28.969900 I | set WATCH on service/pgcluster/leader 266s 2024-11-05 01:12:30.985784 I | Current Leader from DCS: autopkgtest-lxd-rkihls 266s 2024-11-05 01:12:30.986024 I | IP address 10.0.2.123/32 state is false, desired true 266s 2024-11-05 01:12:30.986107 I | Configuring address 10.0.2.123/32 on eth0 266s 2024-11-05 01:12:30.988095 I | Sent gratuitous ARP reply 266s 2024-11-05 01:12:30.988156 I | Sent gratuitous ARP request 266s 2024-11-05 01:12:30.988503 I | IP address 10.0.2.123/32 state is true, desired true 266s OK 268s inet 10.0.2.123/32 scope global eth0 268s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 268s Ncat: Connected to 10.0.2.123:12345. 268s Ncat: 0 bytes sent, 0 bytes received in 0.03 seconds. 268s Ncat: Connection from 10.0.2.123:49966. 268s OK 268s 2024-11-05 01:12:33.047837 I | Current Leader from DCS: 0xGARBAGE 268s 2024-11-05 01:12:33.048397 I | IP address 10.0.2.123/32 state is true, desired false 268s 2024-11-05 01:12:33.048430 I | Removing address 10.0.2.123/32 on eth0 268s 2024-11-05 01:12:33.051009 I | IP address 10.0.2.123/32 state is false, desired false 270s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 270s Ncat: Connection refused. 270s ### You've reached the end of the script, all "tests" have successfully been passed! ### 270s {"level":"info","ts":"2024-11-05T01:12:35.096767Z","caller":"osutil/interrupt_unix.go:64","msg":"received signal; shutting down","signal":"terminated"} 270s {"level":"info","ts":"2024-11-05T01:12:35.096863Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"default","data-dir":"default.etcd","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 270s {"level":"warn","ts":"2024-11-05T01:12:35.097002Z","caller":"embed/serve.go:161","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 270s {"level":"warn","ts":"2024-11-05T01:12:35.097442Z","caller":"embed/serve.go:163","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 270s {"level":"info","ts":"2024-11-05T01:12:35.097561Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 270s {"level":"info","ts":"2024-11-05T01:12:35.102554Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 270s {"level":"info","ts":"2024-11-05T01:12:35.102797Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 270s {"level":"info","ts":"2024-11-05T01:12:35.102824Z","caller":"embed/etcd.go:380","msg":"closed etcd server","name":"default","data-dir":"default.etcd","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 270s autopkgtest [01:12:35]: test test: -----------------------] 274s autopkgtest [01:12:39]: test test: - - - - - - - - - - results - - - - - - - - - - 274s test PASS 277s autopkgtest [01:12:42]: test cacert-test: preparing testbed 287s Reading package lists... 287s Building dependency tree... 287s Reading state information... 287s Starting pkgProblemResolver with broken count: 0 287s Starting 2 pkgProblemResolver with broken count: 0 287s Done 288s The following NEW packages will be installed: 288s autopkgtest-satdep 288s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 288s Need to get 0 B/740 B of archives. 288s After this operation, 0 B of additional disk space will be used. 288s Get:1 /tmp/autopkgtest.HIiDQG/2-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [740 B] 288s Selecting previously unselected package autopkgtest-satdep. 289s (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 ... 59577 files and directories currently installed.) 289s Preparing to unpack .../2-autopkgtest-satdep.deb ... 289s Unpacking autopkgtest-satdep (0) ... 289s Setting up autopkgtest-satdep (0) ... 297s (Reading database ... 59577 files and directories currently installed.) 297s Removing autopkgtest-satdep (0) ... 303s autopkgtest [01:13:08]: test cacert-test: [----------------------- 306s ○ etcd.service - etcd - highly-available key value store 306s Loaded: loaded (/usr/lib/systemd/system/etcd.service; enabled; preset: enabled) 306s Active: inactive (dead) since Tue 2024-11-05 01:12:26 UTC; 44s ago 306s Duration: 19.243s 306s Invocation: 28adea96815e44e08caba45bac6a31bf 306s Docs: https://etcd.io/docs 306s man:etcd 306s Process: 1000 ExecStart=/usr/bin/etcd $DAEMON_ARGS (code=killed, signal=TERM) 306s Main PID: 1000 (code=killed, signal=TERM) 306s 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.851820Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.851924Z","caller":"embed/serve.go:161","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.852088Z","caller":"embed/serve.go:163","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.852157Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopping etcd.service - etcd - highly-available key value store... 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856203Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856362Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856376Z","caller":"embed/etcd.go:380","msg":"closed etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: etcd.service: Deactivated successfully. 306s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopped etcd.service - etcd - highly-available key value store. 306s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 306s {"level":"info","ts":"2024-11-05T01:13:11.228057Z","caller":"etcdmain/etcd.go:482","msg":"running etcd on unsupported architecture since ETCD_UNSUPPORTED_ARCH is set","arch":"arm"} 306s {"level":"warn","ts":"2024-11-05T01:13:11.230219Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 306s {"level":"info","ts":"2024-11-05T01:13:11.230275Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--enable-v2","--cert-file=test/certs/etcd_server.crt","--key-file=test/certs/etcd_server.key","--listen-client-urls","https://127.0.0.1:2379","--advertise-client-urls","https://127.0.0.1:2379"]} 306s {"level":"warn","ts":"2024-11-05T01:13:11.230303Z","caller":"etcdmain/etcd.go:105","msg":"'data-dir' was empty; using default","data-dir":"default.etcd"} 306s {"level":"info","ts":"2024-11-05T01:13:11.230381Z","caller":"etcdmain/etcd.go:116","msg":"server has been already initialized","data-dir":"default.etcd","dir-type":"member"} 306s {"level":"warn","ts":"2024-11-05T01:13:11.230404Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 306s {"level":"info","ts":"2024-11-05T01:13:11.230414Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} 306s {"level":"info","ts":"2024-11-05T01:13:11.230914Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379"]} 306s {"level":"info","ts":"2024-11-05T01:13:11.231092Z","caller":"embed/etcd.go:311","msg":"starting an etcd server","etcd-version":"3.5.16","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.23.2","go-os":"linux","go-arch":"arm","max-cpu-set":8,"max-cpu-available":8,"member-initialized":true,"name":"default","data-dir":"default.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"default.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["https://127.0.0.1:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"","initial-cluster-state":"new","initial-cluster-token":"","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} 306s {"level":"info","ts":"2024-11-05T01:13:11.231650Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"default.etcd/member/snap/db","took":"283.402µs"} 306s {"level":"info","ts":"2024-11-05T01:13:11.231964Z","caller":"etcdserver/server.go:532","msg":"No snapshot found. Recovering WAL from scratch!"} 306s {"level":"info","ts":"2024-11-05T01:13:11.233149Z","caller":"etcdserver/raft.go:540","msg":"restarting local member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","commit-index":7} 306s {"level":"info","ts":"2024-11-05T01:13:11.233252Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} 306s {"level":"info","ts":"2024-11-05T01:13:11.233291Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 2"} 306s {"level":"info","ts":"2024-11-05T01:13:11.233308Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 2, commit: 7, applied: 0, lastindex: 7, lastterm: 2]"} 306s {"level":"warn","ts":"2024-11-05T01:13:11.237965Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} 306s {"level":"info","ts":"2024-11-05T01:13:11.243034Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":3} 306s {"level":"info","ts":"2024-11-05T01:13:11.248157Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} 306s {"level":"info","ts":"2024-11-05T01:13:11.252927Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} 306s {"level":"info","ts":"2024-11-05T01:13:11.253207Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 306s {"level":"info","ts":"2024-11-05T01:13:11.253187Z","caller":"etcdserver/server.go:773","msg":"starting initial election tick advance","election-ticks":10} 306s {"level":"info","ts":"2024-11-05T01:13:11.253758Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 306s {"level":"info","ts":"2024-11-05T01:13:11.253548Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} 306s {"level":"info","ts":"2024-11-05T01:13:11.253857Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} 306s {"level":"info","ts":"2024-11-05T01:13:11.253888Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"]} 306s {"level":"info","ts":"2024-11-05T01:13:11.253927Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} 306s {"level":"info","ts":"2024-11-05T01:13:11.254000Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} 306s {"level":"info","ts":"2024-11-05T01:13:11.254043Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} 306s {"level":"info","ts":"2024-11-05T01:13:11.256246Z","caller":"embed/etcd.go:729","msg":"starting with client TLS","tls-info":"cert = test/certs/etcd_server.crt, key = test/certs/etcd_server.key, client-cert=, client-key=, trusted-ca = , client-cert-auth = false, crl-file = ","cipher-suites":[]} 306s {"level":"warn","ts":"2024-11-05T01:13:11.256309Z","caller":"embed/etcd.go:742","msg":"Flag `enable-v2` is deprecated and will get removed in etcd 3.6."} 306s {"level":"info","ts":"2024-11-05T01:13:11.256439Z","caller":"embed/etcd.go:280","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["https://127.0.0.1:2379"],"listen-metrics-urls":[]} 306s {"level":"info","ts":"2024-11-05T01:13:11.256599Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} 306s {"level":"info","ts":"2024-11-05T01:13:11.256738Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633719Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 2"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633784Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 2"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633831Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 2"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633853Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 3"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633862Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 3"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633875Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 3"} 307s {"level":"info","ts":"2024-11-05T01:13:12.633886Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 3"} 307s {"level":"info","ts":"2024-11-05T01:13:12.640953Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:default ClientURLs:[https://127.0.0.1:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} 307s {"level":"info","ts":"2024-11-05T01:13:12.640939Z","caller":"embed/serve.go:104","msg":"ready to serve client requests"} 307s {"level":"info","ts":"2024-11-05T01:13:12.641268Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} 307s {"level":"info","ts":"2024-11-05T01:13:12.641325Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} 307s {"level":"info","ts":"2024-11-05T01:13:12.644706Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 307s {"level":"info","ts":"2024-11-05T01:13:12.647091Z","caller":"embed/serve.go:251","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:2379"} 308s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 308s Ncat: Listening on 0.0.0.0:12345 308s 1 310s OK 312s inet 10.0.2.123/32 scope global eth0 312s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 312s Ncat: Connected to 10.0.2.123:12345. 312s Ncat: 0 bytes sent, 0 bytes received in 0.03 seconds. 312s Ncat: Connection from 10.0.2.123:34344. 312s ### You've reached the end of the script, all "tests" have successfully been passed! ### 312s {"level":"info","ts":"2024-11-05T01:13:17.476604Z","caller":"osutil/interrupt_unix.go:64","msg":"received signal; shutting down","signal":"terminated"} 312s {"level":"info","ts":"2024-11-05T01:13:17.476702Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"default","data-dir":"default.etcd","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]} 312s {"level":"warn","ts":"2024-11-05T01:13:17.476855Z","caller":"embed/serve.go:213","msg":"stopping secure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 312s {"level":"warn","ts":"2024-11-05T01:13:17.477050Z","caller":"embed/serve.go:215","msg":"stopped secure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 312s /tmp/autopkgtest.HIiDQG/wrapper.sh: Killing leaked background processes: 1617 312s PID TTY STAT TIME COMMAND 312s 1617 ? Sl 0:00 etcd --enable-v2 --cert-file=test/certs/etcd_server.crt --key-file=test/certs/etcd_server.key --listen-client-urls https://127.0.0.1:2379 --advertise-client-urls https://127.0.0.1:2379 312s autopkgtest [01:13:17]: test cacert-test: -----------------------] 316s autopkgtest [01:13:21]: test cacert-test: - - - - - - - - - - results - - - - - - - - - - 316s cacert-test PASS 320s autopkgtest [01:13:25]: test clientcert-test: preparing testbed 329s Reading package lists... 330s Building dependency tree... 330s Reading state information... 330s Starting pkgProblemResolver with broken count: 0 330s Starting 2 pkgProblemResolver with broken count: 0 330s Done 331s The following NEW packages will be installed: 331s autopkgtest-satdep 331s 0 upgraded, 1 newly installed, 0 to remove and 0 not upgraded. 331s Need to get 0 B/736 B of archives. 331s After this operation, 0 B of additional disk space will be used. 331s Get:1 /tmp/autopkgtest.HIiDQG/3-autopkgtest-satdep.deb autopkgtest-satdep armhf 0 [736 B] 331s Selecting previously unselected package autopkgtest-satdep. 331s (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 ... 59577 files and directories currently installed.) 331s Preparing to unpack .../3-autopkgtest-satdep.deb ... 331s Unpacking autopkgtest-satdep (0) ... 331s Setting up autopkgtest-satdep (0) ... 340s (Reading database ... 59577 files and directories currently installed.) 340s Removing autopkgtest-satdep (0) ... 346s autopkgtest [01:13:51]: test clientcert-test: [----------------------- 348s ○ etcd.service - etcd - highly-available key value store 348s Loaded: loaded (/usr/lib/systemd/system/etcd.service; enabled; preset: enabled) 348s Active: inactive (dead) since Tue 2024-11-05 01:12:26 UTC; 1min 26s ago 348s Duration: 19.243s 348s Invocation: 28adea96815e44e08caba45bac6a31bf 348s Docs: https://etcd.io/docs 348s man:etcd 348s Process: 1000 ExecStart=/usr/bin/etcd $DAEMON_ARGS (code=killed, signal=TERM) 348s Main PID: 1000 (code=killed, signal=TERM) 348s 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.851820Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.851924Z","caller":"embed/serve.go:161","msg":"stopping insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"warn","ts":"2024-11-05T01:12:26.852088Z","caller":"embed/serve.go:163","msg":"stopped insecure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.852157Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopping etcd.service - etcd - highly-available key value store... 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856203Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856362Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls etcd[1000]: {"level":"info","ts":"2024-11-05T01:12:26.856376Z","caller":"embed/etcd.go:380","msg":"closed etcd server","name":"autopkgtest-lxd-rkihls","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: etcd.service: Deactivated successfully. 348s Nov 05 01:12:26 autopkgtest-lxd-rkihls systemd[1]: Stopped etcd.service - etcd - highly-available key value store. 348s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 348s inet 10.0.2.123/32 scope global eth0 348s {"level":"info","ts":"2024-11-05T01:13:53.711342Z","caller":"etcdmain/etcd.go:482","msg":"running etcd on unsupported architecture since ETCD_UNSUPPORTED_ARCH is set","arch":"arm"} 348s {"level":"warn","ts":"2024-11-05T01:13:53.712690Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 348s {"level":"info","ts":"2024-11-05T01:13:53.712762Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--enable-v2","--cert-file=test/certs/etcd_server.crt","--key-file=test/certs/etcd_server.key","--listen-client-urls","https://127.0.0.1:2379","--advertise-client-urls","https://127.0.0.1:2379"]} 348s {"level":"warn","ts":"2024-11-05T01:13:53.712789Z","caller":"etcdmain/etcd.go:105","msg":"'data-dir' was empty; using default","data-dir":"default.etcd"} 348s {"level":"info","ts":"2024-11-05T01:13:53.712873Z","caller":"etcdmain/etcd.go:116","msg":"server has been already initialized","data-dir":"default.etcd","dir-type":"member"} 348s {"level":"warn","ts":"2024-11-05T01:13:53.712901Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 348s {"level":"info","ts":"2024-11-05T01:13:53.712912Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} 348s {"level":"info","ts":"2024-11-05T01:13:53.713347Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["https://127.0.0.1:2379"]} 348s {"level":"info","ts":"2024-11-05T01:13:53.713529Z","caller":"embed/etcd.go:311","msg":"starting an etcd server","etcd-version":"3.5.16","git-sha":"Not provided (use ./build instead of go build)","go-version":"go1.23.2","go-os":"linux","go-arch":"arm","max-cpu-set":8,"max-cpu-available":8,"member-initialized":true,"name":"default","data-dir":"default.etcd","wal-dir":"","wal-dir-dedicated":"","member-dir":"default.etcd/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","initial-election-tick-advance":true,"snapshot-count":100000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["https://127.0.0.1:2379"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"","initial-cluster-state":"new","initial-cluster-token":"","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":false,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","downgrade-check-interval":"5s"} 348s {"level":"info","ts":"2024-11-05T01:13:53.714061Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"default.etcd/member/snap/db","took":"210.482µs"} 348s {"level":"info","ts":"2024-11-05T01:13:53.714338Z","caller":"etcdserver/server.go:532","msg":"No snapshot found. Recovering WAL from scratch!"} 348s {"level":"info","ts":"2024-11-05T01:13:53.715541Z","caller":"etcdserver/raft.go:540","msg":"restarting local member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","commit-index":11} 348s {"level":"info","ts":"2024-11-05T01:13:53.715633Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} 348s {"level":"info","ts":"2024-11-05T01:13:53.715679Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 3"} 348s {"level":"info","ts":"2024-11-05T01:13:53.715697Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 3, commit: 11, applied: 0, lastindex: 11, lastterm: 3]"} 348s {"level":"warn","ts":"2024-11-05T01:13:53.718755Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} 348s {"level":"info","ts":"2024-11-05T01:13:53.720389Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":5} 348s {"level":"info","ts":"2024-11-05T01:13:53.724303Z","caller":"etcdserver/quota.go:94","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"} 348s {"level":"info","ts":"2024-11-05T01:13:53.728514Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} 348s {"level":"info","ts":"2024-11-05T01:13:53.728687Z","caller":"etcdserver/server.go:773","msg":"starting initial election tick advance","election-ticks":10} 348s {"level":"info","ts":"2024-11-05T01:13:53.728814Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 348s {"level":"info","ts":"2024-11-05T01:13:53.728799Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} 348s {"level":"info","ts":"2024-11-05T01:13:53.729037Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 348s {"level":"info","ts":"2024-11-05T01:13:53.729068Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} 348s {"level":"info","ts":"2024-11-05T01:13:53.729099Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} 348s {"level":"info","ts":"2024-11-05T01:13:53.729130Z","caller":"membership/cluster.go:421","msg":"added member","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","added-peer-id":"8e9e05c52164694d","added-peer-peer-urls":["http://localhost:2380"]} 348s {"level":"info","ts":"2024-11-05T01:13:53.729221Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} 348s {"level":"info","ts":"2024-11-05T01:13:53.729273Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} 348s {"level":"info","ts":"2024-11-05T01:13:53.732388Z","caller":"embed/etcd.go:729","msg":"starting with client TLS","tls-info":"cert = test/certs/etcd_server.crt, key = test/certs/etcd_server.key, client-cert=, client-key=, trusted-ca = , client-cert-auth = false, crl-file = ","cipher-suites":[]} 348s {"level":"warn","ts":"2024-11-05T01:13:53.732482Z","caller":"embed/etcd.go:742","msg":"Flag `enable-v2` is deprecated and will get removed in etcd 3.6."} 348s {"level":"info","ts":"2024-11-05T01:13:53.732661Z","caller":"embed/etcd.go:280","msg":"now serving peer/client/metrics","local-member-id":"8e9e05c52164694d","initial-advertise-peer-urls":["http://localhost:2380"],"listen-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"],"listen-client-urls":["https://127.0.0.1:2379"],"listen-metrics-urls":[]} 348s {"level":"info","ts":"2024-11-05T01:13:53.732796Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} 348s {"level":"info","ts":"2024-11-05T01:13:53.732955Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116030Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 3"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116199Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 3"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116259Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 3"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116303Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 4"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116326Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 4"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116338Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 4"} 350s {"level":"info","ts":"2024-11-05T01:13:55.116348Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 4"} 350s {"level":"info","ts":"2024-11-05T01:13:55.121891Z","caller":"etcdserver/server.go:2140","msg":"published local member to cluster through raft","local-member-id":"8e9e05c52164694d","local-member-attributes":"{Name:default ClientURLs:[https://127.0.0.1:2379]}","request-path":"/0/members/8e9e05c52164694d/attributes","cluster-id":"cdf818194e3a8c32","publish-timeout":"7s"} 350s {"level":"info","ts":"2024-11-05T01:13:55.121913Z","caller":"embed/serve.go:104","msg":"ready to serve client requests"} 350s {"level":"info","ts":"2024-11-05T01:13:55.122056Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} 350s {"level":"info","ts":"2024-11-05T01:13:55.122089Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} 350s {"level":"info","ts":"2024-11-05T01:13:55.123915Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 350s {"level":"info","ts":"2024-11-05T01:13:55.125678Z","caller":"embed/serve.go:251","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:2379"} 350s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 350s Ncat: Listening on 0.0.0.0:12345 350s 1 352s OK 354s inet 10.0.2.123/32 scope global eth0 354s Ncat: Version 7.94SVN ( https://nmap.org/ncat ) 354s Ncat: Connected to 10.0.2.123:12345. 354s Ncat: 0 bytes sent, 0 bytes received in 0.02 seconds. 354s Ncat: Connection from 10.0.2.123:58946. 354s ### You've reached the end of the script, all "tests" have successfully been passed! ### 354s {"level":"info","ts":"2024-11-05T01:13:59.940880Z","caller":"osutil/interrupt_unix.go:64","msg":"received signal; shutting down","signal":"terminated"} 354s {"level":"info","ts":"2024-11-05T01:13:59.940968Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"default","data-dir":"default.etcd","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["https://127.0.0.1:2379"]} 354s {"level":"warn","ts":"2024-11-05T01:13:59.941057Z","caller":"embed/serve.go:213","msg":"stopping secure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 354s {"level":"warn","ts":"2024-11-05T01:13:59.941189Z","caller":"embed/serve.go:215","msg":"stopped secure grpc server due to error","error":"accept tcp 127.0.0.1:2379: use of closed network connection"} 354s /tmp/autopkgtest.HIiDQG/wrapper.sh: Killing leaked background processes: 2007 354s {"level":"info","ts":"2024-11-05T01:13:59.950561Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 354s PID TTY STAT TIME COMMAND 354s 2007 ? Sl 0:00 etcd --enable-v2 --cert-file=test/certs/etcd_server.crt --key-file=test/certs/etcd_server.key --listen-client-urls https://127.0.0.1:2379 --advertise-client-urls https://127.0.0.1:2379 355s autopkgtest [01:14:00]: test clientcert-test: -----------------------] 359s clientcert-test PASS 359s autopkgtest [01:14:04]: test clientcert-test: - - - - - - - - - - results - - - - - - - - - - 363s autopkgtest [01:14:08]: @@@@@@@@@@@@@@@@@@@@ summary 363s test PASS 363s cacert-test PASS 363s clientcert-test PASS