0s autopkgtest [18:16:52]: starting date and time: 2025-03-15 18:16:52+0000 0s autopkgtest [18:16:52]: git checkout: 325255d2 Merge branch 'pin-any-arch' into 'ubuntu/production' 0s autopkgtest [18:16:52]: host juju-7f2275-prod-proposed-migration-environment-9; command line: /home/ubuntu/autopkgtest/runner/autopkgtest --output-dir /tmp/autopkgtest-work.2zp6nxqw/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,radosgw.ps5.canonical.com\n" >> /etc/environment' --apt-pocket=proposed=src:glibc --apt-upgrade vip-manager --timeout-short=300 --timeout-copy=20000 --timeout-build=20000 --env=ADT_TEST_TRIGGERS=glibc/2.41-1ubuntu2 -- lxd -r lxd-armhf-10.145.243.171 lxd-armhf-10.145.243.171:autopkgtest/ubuntu/plucky/armhf 21s autopkgtest [18:17:13]: testbed dpkg architecture: armhf 23s autopkgtest [18:17:15]: testbed apt version: 2.9.33 27s autopkgtest [18:17:19]: @@@@@@@@@@@@@@@@@@@@ test bed setup 29s autopkgtest [18:17:21]: testbed release detected to be: None 37s autopkgtest [18:17:29]: updating testbed package index (apt update) 39s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed InRelease [126 kB] 39s Get:2 http://ftpmaster.internal/ubuntu plucky InRelease [257 kB] 40s Get:3 http://ftpmaster.internal/ubuntu plucky-updates InRelease [126 kB] 40s Get:4 http://ftpmaster.internal/ubuntu plucky-security InRelease [126 kB] 40s Get:5 http://ftpmaster.internal/ubuntu plucky-proposed/universe Sources [379 kB] 41s Get:6 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse Sources [15.8 kB] 41s Get:7 http://ftpmaster.internal/ubuntu plucky-proposed/main Sources [99.7 kB] 41s Get:8 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf Packages [114 kB] 41s Get:9 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf c-n-f Metadata [1832 B] 41s Get:10 http://ftpmaster.internal/ubuntu plucky-proposed/restricted armhf c-n-f Metadata [116 B] 41s Get:11 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf Packages [312 kB] 41s Get:12 http://ftpmaster.internal/ubuntu plucky-proposed/universe armhf c-n-f Metadata [11.1 kB] 41s Get:13 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse armhf Packages [3472 B] 41s Get:14 http://ftpmaster.internal/ubuntu plucky-proposed/multiverse armhf c-n-f Metadata [240 B] 41s Get:15 http://ftpmaster.internal/ubuntu plucky/main Sources [1394 kB] 43s Get:16 http://ftpmaster.internal/ubuntu plucky/universe Sources [21.0 MB] 61s Get:17 http://ftpmaster.internal/ubuntu plucky/multiverse Sources [299 kB] 61s Get:18 http://ftpmaster.internal/ubuntu plucky/main armhf Packages [1378 kB] 63s Get:19 http://ftpmaster.internal/ubuntu plucky/main armhf c-n-f Metadata [29.4 kB] 63s Get:20 http://ftpmaster.internal/ubuntu plucky/restricted armhf c-n-f Metadata [108 B] 63s Get:21 http://ftpmaster.internal/ubuntu plucky/universe armhf Packages [15.1 MB] 79s Get:22 http://ftpmaster.internal/ubuntu plucky/multiverse armhf Packages [172 kB] 80s Fetched 41.0 MB in 41s (998 kB/s) 81s Reading package lists... 87s autopkgtest [18:18:19]: upgrading testbed (apt dist-upgrade and autopurge) 89s Reading package lists... 89s Building dependency tree... 89s Reading state information... 90s Calculating upgrade...Starting pkgProblemResolver with broken count: 0 90s Starting 2 pkgProblemResolver with broken count: 0 90s Done 90s Entering ResolveByKeep 91s 91s Calculating upgrade... 91s The following packages will be upgraded: 91s libc-bin libc6 locales pinentry-curses python3-jinja2 sos strace 92s 7 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 92s Need to get 8683 kB of archives. 92s After this operation, 23.6 kB of additional disk space will be used. 92s Get:1 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf libc6 armhf 2.41-1ubuntu2 [2932 kB] 95s Get:2 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf libc-bin armhf 2.41-1ubuntu2 [545 kB] 95s Get:3 http://ftpmaster.internal/ubuntu plucky-proposed/main armhf locales all 2.41-1ubuntu2 [4246 kB] 99s Get:4 http://ftpmaster.internal/ubuntu plucky/main armhf strace armhf 6.13+ds-1ubuntu1 [445 kB] 99s Get:5 http://ftpmaster.internal/ubuntu plucky/main armhf pinentry-curses armhf 1.3.1-2ubuntu3 [40.6 kB] 99s Get:6 http://ftpmaster.internal/ubuntu plucky/main armhf python3-jinja2 all 3.1.5-2ubuntu1 [109 kB] 99s Get:7 http://ftpmaster.internal/ubuntu plucky/main armhf sos all 4.9.0-5 [365 kB] 100s Preconfiguring packages ... 100s Fetched 8683 kB in 8s (1078 kB/s) 100s (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 ... 64655 files and directories currently installed.) 100s Preparing to unpack .../libc6_2.41-1ubuntu2_armhf.deb ... 100s Unpacking libc6:armhf (2.41-1ubuntu2) over (2.41-1ubuntu1) ... 101s Setting up libc6:armhf (2.41-1ubuntu2) ... 101s (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 ... 64655 files and directories currently installed.) 101s Preparing to unpack .../libc-bin_2.41-1ubuntu2_armhf.deb ... 101s Unpacking libc-bin (2.41-1ubuntu2) over (2.41-1ubuntu1) ... 101s Setting up libc-bin (2.41-1ubuntu2) ... 101s (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 ... 64655 files and directories currently installed.) 101s Preparing to unpack .../locales_2.41-1ubuntu2_all.deb ... 101s Unpacking locales (2.41-1ubuntu2) over (2.41-1ubuntu1) ... 102s Preparing to unpack .../strace_6.13+ds-1ubuntu1_armhf.deb ... 102s Unpacking strace (6.13+ds-1ubuntu1) over (6.11-0ubuntu1) ... 102s Preparing to unpack .../pinentry-curses_1.3.1-2ubuntu3_armhf.deb ... 102s Unpacking pinentry-curses (1.3.1-2ubuntu3) over (1.3.1-2ubuntu2) ... 102s Preparing to unpack .../python3-jinja2_3.1.5-2ubuntu1_all.deb ... 102s Unpacking python3-jinja2 (3.1.5-2ubuntu1) over (3.1.5-2) ... 102s Preparing to unpack .../archives/sos_4.9.0-5_all.deb ... 102s Unpacking sos (4.9.0-5) over (4.9.0-4) ... 102s Setting up sos (4.9.0-5) ... 103s Setting up pinentry-curses (1.3.1-2ubuntu3) ... 103s Setting up locales (2.41-1ubuntu2) ... 103s Generating locales (this might take a while)... 105s en_US.UTF-8... done 105s Generation complete. 105s Setting up python3-jinja2 (3.1.5-2ubuntu1) ... 106s Setting up strace (6.13+ds-1ubuntu1) ... 106s Processing triggers for man-db (2.13.0-1) ... 107s Processing triggers for systemd (257.3-1ubuntu3) ... 110s Reading package lists... 110s Building dependency tree... 110s Reading state information... 110s Starting pkgProblemResolver with broken count: 0 110s Starting 2 pkgProblemResolver with broken count: 0 110s Done 111s Solving dependencies... 111s 0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded. 113s autopkgtest [18:18:45]: rebooting testbed after setup commands that affected boot 155s autopkgtest [18:19:27]: testbed running kernel: Linux 6.8.0-52-generic #53~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Wed Jan 15 18:10:51 UTC 2 191s autopkgtest [18:20:03]: @@@@@@@@@@@@@@@@@@@@ apt-source vip-manager 202s Get:1 http://ftpmaster.internal/ubuntu plucky/universe vip-manager 1.0.2-9 (dsc) [2473 B] 202s Get:2 http://ftpmaster.internal/ubuntu plucky/universe vip-manager 1.0.2-9 (tar) [69.9 kB] 202s Get:3 http://ftpmaster.internal/ubuntu plucky/universe vip-manager 1.0.2-9 (diff) [9432 B] 202s gpgv: Signature made Fri Aug 23 16:57:11 2024 UTC 202s gpgv: using RSA key 5C48FE6157F49179597087C64C5A6BAB12D2A7AE 202s gpgv: Can't check signature: No public key 202s dpkg-source: warning: cannot verify inline signature for ./vip-manager_1.0.2-9.dsc: no acceptable signature found 202s autopkgtest [18:20:14]: testing package vip-manager version 1.0.2-9 204s autopkgtest [18:20:16]: build not needed 206s autopkgtest [18:20:18]: test test: preparing testbed 208s Reading package lists... 208s Building dependency tree... 208s Reading state information... 208s Starting pkgProblemResolver with broken count: 0 209s Starting 2 pkgProblemResolver with broken count: 0 209s Done 209s The following NEW packages will be installed: 209s etcd-server liblua5.4-0 ncat vip-manager 210s 0 upgraded, 4 newly installed, 0 to remove and 0 not upgraded. 210s Need to get 14.0 MB of archives. 210s After this operation, 48.7 MB of additional disk space will be used. 210s Get:1 http://ftpmaster.internal/ubuntu plucky/universe armhf etcd-server armhf 3.5.16-4 [11.3 MB] 218s Get:2 http://ftpmaster.internal/ubuntu plucky/main armhf liblua5.4-0 armhf 5.4.7-1 [134 kB] 218s Get:3 http://ftpmaster.internal/ubuntu plucky/universe armhf ncat armhf 7.95+dfsg-2 [217 kB] 218s Get:4 http://ftpmaster.internal/ubuntu plucky/universe armhf vip-manager armhf 1.0.2-9 [2421 kB] 220s Fetched 14.0 MB in 11s (1323 kB/s) 220s Selecting previously unselected package etcd-server. 220s (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 ... 64655 files and directories currently installed.) 220s Preparing to unpack .../etcd-server_3.5.16-4_armhf.deb ... 220s Unpacking etcd-server (3.5.16-4) ... 221s Selecting previously unselected package liblua5.4-0:armhf. 221s Preparing to unpack .../liblua5.4-0_5.4.7-1_armhf.deb ... 221s Unpacking liblua5.4-0:armhf (5.4.7-1) ... 221s Selecting previously unselected package ncat. 221s Preparing to unpack .../ncat_7.95+dfsg-2_armhf.deb ... 221s Unpacking ncat (7.95+dfsg-2) ... 221s Selecting previously unselected package vip-manager. 221s Preparing to unpack .../vip-manager_1.0.2-9_armhf.deb ... 221s Unpacking vip-manager (1.0.2-9) ... 221s Setting up liblua5.4-0:armhf (5.4.7-1) ... 221s Setting up etcd-server (3.5.16-4) ... 221s info: Selecting UID from range 100 to 999 ... 221s 221s info: Selecting GID from range 100 to 999 ... 221s info: Adding system user `etcd' (UID 107) ... 221s info: Adding new group `etcd' (GID 108) ... 221s info: Adding new user `etcd' (UID 107) with group `etcd' ... 221s info: Creating home directory `/var/lib/etcd/' ... 221s Created symlink '/etc/systemd/system/etcd2.service' → '/usr/lib/systemd/system/etcd.service'. 221s Created symlink '/etc/systemd/system/multi-user.target.wants/etcd.service' → '/usr/lib/systemd/system/etcd.service'. 222s Setting up vip-manager (1.0.2-9) ... 222s Created symlink '/etc/systemd/system/multi-user.target.wants/vip-manager.service' → '/usr/lib/systemd/system/vip-manager.service'. 223s Setting up ncat (7.95+dfsg-2) ... 223s Processing triggers for man-db (2.13.0-1) ... 223s Processing triggers for libc-bin (2.41-1ubuntu2) ... 231s autopkgtest [18:20:43]: test test: [----------------------- 234s ○ etcd.service - etcd - highly-available key value store 234s Loaded: loaded (/usr/lib/systemd/system/etcd.service; enabled; preset: enabled) 234s Active: inactive (dead) since Sat 2025-03-15 18:20:46 UTC; 15ms ago 234s Duration: 11.811s 234s Invocation: 8ece4f8f8e1044709f3a1582af798b8f 234s Docs: https://etcd.io/docs 234s man:etcd 234s Process: 871 ExecStart=/usr/bin/etcd $DAEMON_ARGS (code=killed, signal=TERM) 234s Main PID: 871 (code=killed, signal=TERM) 234s 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"info","ts":"2025-03-15T18:20:46.368733Z","caller":"embed/etcd.go:378","msg":"closing etcd server","name":"autopkgtest-lxd-etmxwz","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"warn","ts":"2025-03-15T18:20:46.368861Z","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"} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"warn","ts":"2025-03-15T18:20:46.369141Z","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"} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"info","ts":"2025-03-15T18:20:46.369170Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz systemd[1]: Stopping etcd.service - etcd - highly-available key value store... 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"info","ts":"2025-03-15T18:20:46.374250Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"info","ts":"2025-03-15T18:20:46.374440Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz etcd[871]: {"level":"info","ts":"2025-03-15T18:20:46.374477Z","caller":"embed/etcd.go:380","msg":"closed etcd server","name":"autopkgtest-lxd-etmxwz","data-dir":"/var/lib/etcd/default","advertise-peer-urls":["http://localhost:2380"],"advertise-client-urls":["http://localhost:2379"]} 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz systemd[1]: etcd.service: Deactivated successfully. 234s Mar 15 18:20:46 autopkgtest-lxd-etmxwz systemd[1]: Stopped etcd.service - etcd - highly-available key value store. 234s dpkg-architecture: warning: cannot determine CC system type, falling back to default (native compilation) 234s {"level":"info","ts":"2025-03-15T18:20:46.456362Z","caller":"etcdmain/etcd.go:482","msg":"running etcd on unsupported architecture since ETCD_UNSUPPORTED_ARCH is set","arch":"arm"} 234s {"level":"warn","ts":"2025-03-15T18:20:46.457780Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 234s {"level":"info","ts":"2025-03-15T18:20:46.457859Z","caller":"etcdmain/etcd.go:73","msg":"Running: ","args":["etcd","--enable-v2"]} 234s {"level":"warn","ts":"2025-03-15T18:20:46.457900Z","caller":"etcdmain/etcd.go:105","msg":"'data-dir' was empty; using default","data-dir":"default.etcd"} 234s {"level":"warn","ts":"2025-03-15T18:20:46.457956Z","caller":"embed/config.go:689","msg":"Running http and grpc server on single port. This is not recommended for production."} 234s {"level":"info","ts":"2025-03-15T18:20:46.458015Z","caller":"embed/etcd.go:128","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:2380"]} 234s {"level":"info","ts":"2025-03-15T18:20:46.458603Z","caller":"embed/etcd.go:136","msg":"configuring client listeners","listen-client-urls":["http://localhost:2379"]} 234s {"level":"info","ts":"2025-03-15T18:20:46.458838Z","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.24.1","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"} 234s {"level":"info","ts":"2025-03-15T18:20:46.461776Z","caller":"etcdserver/backend.go:81","msg":"opened backend db","path":"default.etcd/member/snap/db","took":"2.52198ms"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467530Z","caller":"etcdserver/raft.go:505","msg":"starting local member","local-member-id":"8e9e05c52164694d","cluster-id":"cdf818194e3a8c32"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467657Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=()"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467706Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 0"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467720Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"newRaft 8e9e05c52164694d [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467736Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became follower at term 1"} 234s {"level":"info","ts":"2025-03-15T18:20:46.467780Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 234s {"level":"warn","ts":"2025-03-15T18:20:46.472262Z","caller":"auth/store.go:1241","msg":"simple token is not cryptographically signed"} 234s {"level":"info","ts":"2025-03-15T18:20:46.476276Z","caller":"mvcc/kvstore.go:423","msg":"kvstore restored","current-rev":1} 234s {"level":"info","ts":"2025-03-15T18:20:46.479698Z","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"} 234s {"level":"info","ts":"2025-03-15T18:20:46.482929Z","caller":"etcdserver/server.go:873","msg":"starting etcd server","local-member-id":"8e9e05c52164694d","local-server-version":"3.5.16","cluster-version":"to_be_decided"} 234s {"level":"info","ts":"2025-03-15T18:20:46.483155Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 234s {"level":"info","ts":"2025-03-15T18:20:46.486303Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap.db","max":5,"interval":"30s"} 234s {"level":"info","ts":"2025-03-15T18:20:46.486434Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/snap","suffix":"snap","max":5,"interval":"30s"} 234s {"level":"info","ts":"2025-03-15T18:20:46.486487Z","caller":"fileutil/purge.go:50","msg":"started to purge file","dir":"default.etcd/member/wal","suffix":"wal","max":5,"interval":"30s"} 234s {"level":"info","ts":"2025-03-15T18:20:46.486605Z","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"} 234s {"level":"warn","ts":"2025-03-15T18:20:46.488841Z","caller":"embed/etcd.go:742","msg":"Flag `enable-v2` is deprecated and will get removed in etcd 3.6."} 234s {"level":"info","ts":"2025-03-15T18:20:46.489048Z","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":[]} 234s {"level":"info","ts":"2025-03-15T18:20:46.489553Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d switched to configuration voters=(10276657743932975437)"} 234s {"level":"info","ts":"2025-03-15T18:20:46.489693Z","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"]} 234s {"level":"info","ts":"2025-03-15T18:20:46.489702Z","caller":"embed/etcd.go:600","msg":"serving peer traffic","address":"127.0.0.1:2380"} 234s {"level":"info","ts":"2025-03-15T18:20:46.489752Z","caller":"embed/etcd.go:572","msg":"cmux::serve","address":"127.0.0.1:2380"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068065Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d is starting a new election at term 1"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068132Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became pre-candidate at term 1"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068175Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgPreVoteResp from 8e9e05c52164694d at term 1"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068194Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became candidate at term 2"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068204Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d received MsgVoteResp from 8e9e05c52164694d at term 2"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068219Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"8e9e05c52164694d became leader at term 2"} 235s {"level":"info","ts":"2025-03-15T18:20:47.068230Z","logger":"raft","caller":"etcdserver/zap_raft.go:77","msg":"raft.node: 8e9e05c52164694d elected leader 8e9e05c52164694d at term 2"} 235s {"level":"info","ts":"2025-03-15T18:20:47.070228Z","caller":"etcdserver/server.go:2651","msg":"setting up initial cluster version using v2 API","cluster-version":"3.5"} 235s {"level":"info","ts":"2025-03-15T18:20:47.072118Z","caller":"embed/serve.go:104","msg":"ready to serve client requests"} 235s {"level":"info","ts":"2025-03-15T18:20:47.072111Z","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"} 235s {"level":"info","ts":"2025-03-15T18:20:47.072414Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"} 235s {"level":"info","ts":"2025-03-15T18:20:47.072493Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"} 235s {"level":"info","ts":"2025-03-15T18:20:47.072806Z","caller":"v3rpc/health.go:61","msg":"grpc service status changed","service":"","status":"SERVING"} 235s {"level":"info","ts":"2025-03-15T18:20:47.073233Z","caller":"embed/serve.go:188","msg":"serving client traffic insecurely; this is strongly discouraged!","traffic":"grpc+http","address":"127.0.0.1:2379"} 235s {"level":"info","ts":"2025-03-15T18:20:47.073588Z","caller":"membership/cluster.go:584","msg":"set initial cluster version","cluster-id":"cdf818194e3a8c32","local-member-id":"8e9e05c52164694d","cluster-version":"3.5"} 235s {"level":"info","ts":"2025-03-15T18:20:47.073706Z","caller":"api/capability.go:75","msg":"enabled capabilities for version","cluster-version":"3.5"} 235s {"level":"info","ts":"2025-03-15T18:20:47.073746Z","caller":"etcdserver/server.go:2675","msg":"cluster version is updated","cluster-version":"3.5"} 236s Ncat: Version 7.95 ( https://nmap.org/ncat ) 236s Ncat: Listening on 0.0.0.0:12345 236s {"errorCode":100,"message":"Key not found","cause":"/service","index":3} 236s 2025/03/15 18:20:48 No dcs-endpoints specified, trying to use localhost with standard ports! 236s 2025/03/15 18:20:48 This is the config that will be used: 236s 2025/03/15 18:20:48 IP address 10.0.2.123/32 state is false, desired false 236s dcs-endpoints : [http://127.0.0.1:2379] 236s dcs-type : etcd 236s hostingtype : basic 236s interface : eth0 236s interval : 1000 236s ip : 10.0.2.123 236s manager-type : basic 236s netmask : 32 236s retry-after : 250 236s retry-num : 3 236s trigger-key : service/pgcluster/leader 236s trigger-value : autopkgtest-lxd-etmxwz 236s verbose : false 236s version : false 236s 2025/03/15 18:20:48 etcd error: 100: Key not found (/service) [3] 237s 2025/03/15 18:20:49 etcd error: 100: Key not found (/service) [3] 238s { 238s "action": "set", 238s "node": { 238s "key": "/service/pgcluster/leader", 238s "value": "autopkgtest-lxd-etmxwz", 238s "modifiedIndex": 4, 238s "createdIndex": 4 238s } 238s } 238s 2025/03/15 18:20:50 IP address 10.0.2.123/32 state is false, desired true 238s 2025/03/15 18:20:50 Configuring address 10.0.2.123/32 on eth0 238s 2025/03/15 18:20:50 Sent gratuitous ARP reply 238s 2025/03/15 18:20:50 Sent gratuitous ARP request 238s 2025/03/15 18:20:50 IP address 10.0.2.123/32 state is true, desired true 240s inet 10.0.2.123/32 scope global eth0 240s Ncat: Version 7.95 ( https://nmap.org/ncat ) 240s Ncat: Connected to 10.0.2.123:12345. 240s Ncat: 0 bytes sent, 0 bytes received in 0.03 seconds. 240s Ncat: Connection from 10.0.2.123:53550. 240s { 240s "action": "set", 240s "node": { 240s "key": "/service/pgcluster/leader", 240s "value": "0xGARBAGE", 240s "modifiedIndex": 5, 240s "createdIndex": 5 240s }, 240s "prevNode": { 240s "key": "/service/pgcluster/leader", 240s "value": "autopkgtest-lxd-etmxwz", 240s "modifiedIndex": 4, 240s "createdIndex": 4 240s } 240s } 241s 2025/03/15 18:20:53 IP address 10.0.2.123/32 state is true, desired false 241s 2025/03/15 18:20:53 Removing address 10.0.2.123/32 on eth0 241s 2025/03/15 18:20:53 IP address 10.0.2.123/32 state is false, desired false 242s Ncat: Version 7.95 ( https://nmap.org/ncat ) 242s ### You've reached the end of the script, all "tests" have successfully been passed! ### 242s Ncat: Connection refused. 242s {"level":"info","ts":"2025-03-15T18:20:54.590106Z","caller":"osutil/interrupt_unix.go:64","msg":"received signal; shutting down","signal":"terminated"} 242s {"level":"info","ts":"2025-03-15T18:20:54.590184Z","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"]} 242s {"level":"warn","ts":"2025-03-15T18:20:54.590298Z","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"} 242s {"level":"warn","ts":"2025-03-15T18:20:54.590694Z","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"} 242s {"level":"info","ts":"2025-03-15T18:20:54.590803Z","caller":"etcdserver/server.go:1543","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"8e9e05c52164694d","current-leader-member-id":"8e9e05c52164694d"} 242s {"level":"info","ts":"2025-03-15T18:20:54.595914Z","caller":"embed/etcd.go:582","msg":"stopping serving peer traffic","address":"127.0.0.1:2380"} 242s {"level":"info","ts":"2025-03-15T18:20:54.596095Z","caller":"embed/etcd.go:587","msg":"stopped serving peer traffic","address":"127.0.0.1:2380"} 242s {"level":"info","ts":"2025-03-15T18:20:54.596133Z","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"]} 243s autopkgtest [18:20:55]: test test: -----------------------] 246s test PASS 246s autopkgtest [18:20:58]: test test: - - - - - - - - - - results - - - - - - - - - - 251s autopkgtest [18:21:03]: @@@@@@@@@@@@@@@@@@@@ summary 251s test PASS