01KS31F1NW3BQ9WV32YAVTGMHF: falcon

BasicConfig {
    output_rules: [],
    rust_toolchain: None,
    target: Some(
        "lab-2.0-gimlet",
    ),
    access_repos: [],
    publish: [],
    skip_clone: true,
}

Buildomat Job: 01KS31FK9PFGS5WQDPZF9VBNJ6

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-05-20T16:07:32.180Zjob dependencies complete; ready to run (waiting for 13 m 46 s)
22026-05-20T16:10:46.516Zjob assigned to worker 01KS328VCZT693R67P9DME37YJ [factory edgar, gimlet/BRM42220060/586] (queued for 3 m 14 s)
32026-05-20T16:10:47.566Zdownloading input: /input/build/work/debug/ddmadm
42026-05-20T16:11:18.987Zdownloaded input: /input/build/work/debug/ddmadm
52026-05-20T16:11:19.019Zdownloading input: /input/build/work/debug/ddmd
62026-05-20T16:11:57.523Zdownloaded input: /input/build/work/debug/ddmd
72026-05-20T16:11:57.669Zdownloading input: /input/build-interop/work/testbed.tar.gz
82026-05-20T16:12:08.968Zdownloaded input: /input/build-interop/work/testbed.tar.gz
92026-05-20T16:12:08.968Zdownloading input: /input/build/work/debug/mgadm
102026-05-20T16:13:00.884Zdownloaded input: /input/build/work/debug/mgadm
112026-05-20T16:13:00.884Zdownloading input: /input/build-interop/work/dhcp-server
122026-05-20T16:13:05.688Zdownloaded input: /input/build-interop/work/dhcp-server
132026-05-20T16:13:05.689Zdownloading input: /input/build/work/debug/mgd
142026-05-20T16:14:15.696Zdownloaded input: /input/build/work/debug/mgd
152026-05-20T16:14:15.732Zdownloading input: /input/build/work/release/ddmadm
162026-05-20T16:14:19.655Zdownloaded input: /input/build/work/release/ddmadm
172026-05-20T16:14:19.655Zdownloading input: /input/build/work/release/ddmd
182026-05-20T16:14:23.168Zdownloaded input: /input/build/work/release/ddmd
192026-05-20T16:14:23.168Zdownloading input: /input/build/work/release/falcon-lab
202026-05-20T16:14:27.682Zdownloaded input: /input/build/work/release/falcon-lab
212026-05-20T16:14:27.683Zdownloading input: /input/build/work/release/mgadm
222026-05-20T16:14:31.171Zdownloaded input: /input/build/work/release/mgadm
232026-05-20T16:14:31.208Zdownloading input: /input/build/work/release/mgd
242026-05-20T16:14:35.436Zdownloaded input: /input/build/work/release/mgd
 
252026-05-20T16:14:35.436Zstarting task 0: "setup"
262026-05-20T16:14:35.470Z++ uname -s
272026-05-20T16:14:35.470Z+ kern=SunOS
282026-05-20T16:14:35.470Z+ build_user=build
292026-05-20T16:14:35.470Z+ build_uid=12345
302026-05-20T16:14:35.470Z+ work_dir=/work
312026-05-20T16:14:35.470Z+ input_dir=/input
322026-05-20T16:14:35.470Z+ [[ 0 == 12345 ]]
332026-05-20T16:14:35.470Z+ case "$kern" in
342026-05-20T16:14:35.470Z+ groupadd -g 12345 build
352026-05-20T16:14:35.470Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-05-20T16:14:37.478Z+ zfs create -o mountpoint=/work rpool/work
372026-05-20T16:14:37.674Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-05-20T16:14:37.706Z+ home_fs=
392026-05-20T16:14:37.706Z+ [[ '' == autofs ]]
402026-05-20T16:14:37.706Z+ mkdir -p /home/build
412026-05-20T16:14:37.706Z+ chown build:build /home/build /work
422026-05-20T16:14:39.689Z+ chmod 0700 /home/build /work
432026-05-20T16:14:39.722Zprocess exited: duration 4254 ms, exit code 0
 
442026-05-20T16:14:39.786Zstarting task 1: "authentication"
452026-05-20T16:14:39.897Zprocess exited: duration 106 ms, exit code 0
 
462026-05-20T16:14:39.961Zstarting task 2: "build"
472026-05-20T16:14:39.997Z+ set -e
482026-05-20T16:14:39.997Z+ banner zpool
492026-05-20T16:14:39.997Z
502026-05-20T16:14:39.997Z ###### ##### #### #### #
512026-05-20T16:14:39.997Z # # # # # # # #
522026-05-20T16:14:39.997Z # # # # # # # #
532026-05-20T16:14:39.997Z # ##### # # # # #
542026-05-20T16:14:39.997Z # # # # # # #
552026-05-20T16:14:39.997Z ###### # #### #### ######
562026-05-20T16:14:39.998Z
572026-05-20T16:14:39.998Z++ pfexec diskinfo -pH
582026-05-20T16:14:39.998Z++ sort -k8 -n -r
592026-05-20T16:14:39.998Z++ head -1
602026-05-20T16:14:39.998Z++ awk '{print $2}'
612026-05-20T16:14:40.039Z+ DISK=c9t0014EE81000BC57Cd0
622026-05-20T16:14:40.039Z+ export DISK
632026-05-20T16:14:40.039Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC57Cd0
642026-05-20T16:14:40.106Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-05-20T16:14:40.144Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-05-20T16:14:40.380Z+ [[ true =~ true ]]
672026-05-20T16:14:40.380Z+ pfexec zpool trim cpool
682026-05-20T16:14:40.417Z++ zpool status -t cpool
692026-05-20T16:14:40.417Z+ [[ ! pool: cpool
702026-05-20T16:14:40.417Z state: ONLINE
712026-05-20T16:14:40.417Z scan: none requested
722026-05-20T16:14:40.417Zconfig:
732026-05-20T16:14:40.417Z
742026-05-20T16:14:40.417Z NAME STATE READ WRITE CKSUM
752026-05-20T16:14:40.417Z cpool ONLINE 0 0 0
762026-05-20T16:14:40.417Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (1% trimmed, started at May 20, 2026 at 04:14:40 PM UTC)
772026-05-20T16:14:40.417Z
782026-05-20T16:14:40.417Zerrors: No known data errors =~ 100% ]]
792026-05-20T16:14:40.417Z+ sleep 10
802026-05-20T16:14:50.417Z++ zpool status -t cpool
812026-05-20T16:14:50.452Z+ [[ ! pool: cpool
822026-05-20T16:14:50.452Z state: ONLINE
832026-05-20T16:14:50.452Z scan: none requested
842026-05-20T16:14:50.452Zconfig:
852026-05-20T16:14:50.452Z
862026-05-20T16:14:50.452Z NAME STATE READ WRITE CKSUM
872026-05-20T16:14:50.452Z cpool ONLINE 0 0 0
882026-05-20T16:14:50.452Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (69% trimmed, started at May 20, 2026 at 04:14:40 PM UTC)
892026-05-20T16:14:50.452Z
902026-05-20T16:14:50.452Zerrors: No known data errors =~ 100% ]]
912026-05-20T16:14:50.453Z+ sleep 10
922026-05-20T16:15:00.433Z++ zpool status -t cpool
932026-05-20T16:15:00.467Z+ [[ ! pool: cpool
942026-05-20T16:15:00.467Z state: ONLINE
952026-05-20T16:15:00.467Z scan: none requested
962026-05-20T16:15:00.467Zconfig:
972026-05-20T16:15:00.468Z
982026-05-20T16:15:00.468Z NAME STATE READ WRITE CKSUM
992026-05-20T16:15:00.468Z cpool ONLINE 0 0 0
1002026-05-20T16:15:00.468Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (100% trimmed, completed at May 20, 2026 at 04:14:54 PM UTC)
1012026-05-20T16:15:00.468Z
1022026-05-20T16:15:00.468Zerrors: No known data errors =~ 100% ]]
1032026-05-20T16:15:00.468Z+ pfexec chown 12345 /ci
1042026-05-20T16:15:00.468Z+ cd /ci
1052026-05-20T16:15:00.468Z+ export FALCON_DATASET=cpool/falcon
1062026-05-20T16:15:00.468Z+ FALCON_DATASET=cpool/falcon
1072026-05-20T16:15:00.468Z+ banner setup
1082026-05-20T16:15:00.468Z
1092026-05-20T16:15:00.468Z #### ###### ##### # # #####
1102026-05-20T16:15:00.468Z # # # # # # #
1112026-05-20T16:15:00.468Z #### ##### # # # # #
1122026-05-20T16:15:00.468Z # # # # # #####
1132026-05-20T16:15:00.468Z # # # # # # #
1142026-05-20T16:15:00.468Z #### ###### # #### #
1152026-05-20T16:15:00.468Z
1162026-05-20T16:15:00.468Z+ cp /input/build-interop/work/dhcp-server .
1172026-05-20T16:15:00.688Z+ cp /input/build/work/release/falcon-lab .
1182026-05-20T16:15:00.749Z+ cp /input/build/work/release/mgd .
1192026-05-20T16:15:00.816Z+ cp /input/build/work/release/ddmd .
1202026-05-20T16:15:00.876Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-05-20T16:15:00.908Z+ mkdir -p cargo-bay
1222026-05-20T16:15:00.908Z+ mv mgd cargo-bay/
1232026-05-20T16:15:00.908Z+ mv ddmd cargo-bay/
1242026-05-20T16:15:00.908Z+ export EXT_INTERFACE=igb0
1252026-05-20T16:15:00.908Z+ EXT_INTERFACE=igb0
1262026-05-20T16:15:00.908Z++ bmat address ls -f extra -Ho first
1272026-05-20T16:15:00.943Z+ first=10.151.7.164
1282026-05-20T16:15:00.943Z++ bmat address ls -f extra -Ho last
1292026-05-20T16:15:00.977Z+ last=10.151.7.227
1302026-05-20T16:15:00.977Z++ bmat address ls -f extra -Ho gateway
1312026-05-20T16:15:00.977Z+ gw=10.151.7.1
1322026-05-20T16:15:00.977Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-05-20T16:15:00.977Z++ sed 's#/.*##g'
1342026-05-20T16:15:01.025Z+ server=10.151.7.100
1352026-05-20T16:15:01.025Z+ RUST_LOG=debug
1362026-05-20T16:15:01.025Z+ pfexec ./falcon-lab run trio-unnumbered
1372026-05-20T16:15:01.025Z+ pfexec ./dhcp-server 10.151.7.164 10.151.7.227 10.151.7.1 10.151.7.100
1382026-05-20T16:15:01.025ZMay 20 16:15:01.005 DEBG using default route interface igb0
1392026-05-20T16:15:01.025ZMay 20 16:15:01.005 DEBG using default route interface igb0
1402026-05-20T16:15:01.025ZMay 20 16:15:01.005 DEBG using default route interface igb0
1412026-05-20T16:15:01.025ZMay 20 16:15:01.005 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1422026-05-20T16:15:01.025ZMay 20 16:15:01.005 INFO starting preflight for deployment mgtriou
1432026-05-20T16:15:01.025ZMay 20 16:15:01.005 INFO propolis-server binary not found
1442026-05-20T16:15:01.025ZMay 20 16:15:01.005 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1452026-05-20T16:15:07.179ZMay 20 16:15:07.179 INFO ovmf fd not found
1462026-05-20T16:15:07.179ZMay 20 16:15:07.179 INFO downloading ovmf
1472026-05-20T16:15:07.666ZMay 20 16:15:07.659 INFO base image for helios-2.9 does not exist, attempting to install
1482026-05-20T16:15:07.666ZMay 20 16:15:07.659 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1492026-05-20T16:15:22.663ZMay 20 16:15:22.658 WARN failed to get url https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz: retrying in 1 second
1502026-05-20T16:15:59.953ZMay 20 16:15:59.941 INFO extracting image to /tmp/helios-2.9_0.raw
1512026-05-20T16:16:33.387ZMay 20 16:16:33.370 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1522026-05-20T16:16:33.438ZMay 20 16:16:33.421 INFO copying image data to zvol
1532026-05-20T16:16:43.814ZMay 20 16:16:43.797 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1542026-05-20T16:16:47.235ZMay 20 16:16:47.216 INFO base image for debian-13.2 does not exist, attempting to install
1552026-05-20T16:16:47.235ZMay 20 16:16:47.216 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1562026-05-20T16:17:12.689ZMay 20 16:17:12.671 INFO extracting image to /tmp/debian-13.2_0.raw
1572026-05-20T16:17:33.462ZMay 20 16:17:33.432 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1582026-05-20T16:17:33.495ZMay 20 16:17:33.459 INFO copying image data to zvol
1592026-05-20T16:17:39.779ZMay 20 16:17:39.761 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1602026-05-20T16:17:43.132ZMay 20 16:17:43.112 INFO base image for eos-4.35 does not exist, attempting to install
1612026-05-20T16:17:43.132ZMay 20 16:17:43.112 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1622026-05-20T16:18:48.406ZMay 20 16:18:48.170 INFO extracting image to /tmp/eos-4.35_0.raw
1632026-05-20T16:20:11.240ZMay 20 16:20:11.219 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1642026-05-20T16:20:11.276ZMay 20 16:20:11.245 INFO copying image data to zvol
1652026-05-20T16:20:58.767ZMay 20 16:20:58.744 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1662026-05-20T16:21:02.191ZMay 20 16:21:02.174 INFO creating links
1672026-05-20T16:21:02.191ZMay 20 16:21:02.174 DEBG destroying link mgtriou_ox_sn_vnic0
1682026-05-20T16:21:02.226ZMay 20 16:21:02.174 DEBG destroying link mgtriou_ox_sn_sim0
1692026-05-20T16:21:02.226ZMay 20 16:21:02.174 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1702026-05-20T16:21:02.226ZMay 20 16:21:02.176 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1712026-05-20T16:21:02.226ZMay 20 16:21:02.183 DEBG link pair created
1722026-05-20T16:21:02.226ZMay 20 16:21:02.183 DEBG destroying link mgtriou_cr1_vn_vnic0
1732026-05-20T16:21:02.226ZMay 20 16:21:02.183 DEBG destroying link mgtriou_cr1_vn_sim0
1742026-05-20T16:21:02.226ZMay 20 16:21:02.183 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1752026-05-20T16:21:02.226ZMay 20 16:21:02.185 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1762026-05-20T16:21:02.226ZMay 20 16:21:02.191 DEBG link pair created
1772026-05-20T16:21:02.226ZMay 20 16:21:02.191 DEBG destroying link mgtriou_ox_sn_vnic1
1782026-05-20T16:21:02.226ZMay 20 16:21:02.191 DEBG destroying link mgtriou_ox_sn_sim1
1792026-05-20T16:21:02.226ZMay 20 16:21:02.191 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1802026-05-20T16:21:02.226ZMay 20 16:21:02.192 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1812026-05-20T16:21:02.226ZMay 20 16:21:02.199 DEBG link pair created
1822026-05-20T16:21:02.226ZMay 20 16:21:02.199 DEBG destroying link mgtriou_cr2_vn_vnic0
1832026-05-20T16:21:02.226ZMay 20 16:21:02.199 DEBG destroying link mgtriou_cr2_vn_sim0
1842026-05-20T16:21:02.226ZMay 20 16:21:02.199 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1852026-05-20T16:21:02.226ZMay 20 16:21:02.200 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1862026-05-20T16:21:02.261ZMay 20 16:21:02.207 DEBG link pair created
1872026-05-20T16:21:02.261ZMay 20 16:21:02.207 INFO creating external links
1882026-05-20T16:21:02.261ZMay 20 16:21:02.207 DEBG destroying external link mgtriou_ox_vn_vnic2
1892026-05-20T16:21:02.262ZMay 20 16:21:02.207 INFO creating external link mgtriou_ox_vn_vnic2
1902026-05-20T16:21:02.262ZMay 20 16:21:02.209 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1912026-05-20T16:21:02.262ZMay 20 16:21:02.209 DEBG destroying external link mgtriou_cr1_vn_vnic1
1922026-05-20T16:21:02.262ZMay 20 16:21:02.209 INFO creating external link mgtriou_cr1_vn_vnic1
1932026-05-20T16:21:02.262ZMay 20 16:21:02.210 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1942026-05-20T16:21:02.262ZMay 20 16:21:02.210 DEBG destroying external link mgtriou_cr2_vn_vnic1
1952026-05-20T16:21:02.262ZMay 20 16:21:02.210 INFO creating external link mgtriou_cr2_vn_vnic1
1962026-05-20T16:21:02.262ZMay 20 16:21:02.211 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1972026-05-20T16:21:02.262ZMay 20 16:21:02.211 INFO creating nodes
1982026-05-20T16:21:02.262ZMay 20 16:21:02.211 INFO ox: launching node
1992026-05-20T16:21:02.262ZMay 20 16:21:02.214 INFO cr1: launching node
2002026-05-20T16:21:02.262ZMay 20 16:21:02.216 INFO cr2: launching node
2012026-05-20T16:21:02.262ZMay 20 16:21:02.229 INFO launched instance ox with pid 843 on port 47413
2022026-05-20T16:21:02.262ZMay 20 16:21:02.229 INFO ox: instance ensure
2032026-05-20T16:21:02.262ZMay 20 16:21:02.230 INFO launched instance cr1 with pid 844 on port 56942
2042026-05-20T16:21:02.262ZMay 20 16:21:02.230 INFO cr1: instance ensure
2052026-05-20T16:21:02.262ZMay 20 16:21:02.230 INFO launched instance cr2 with pid 845 on port 43605
2062026-05-20T16:21:02.262ZMay 20 16:21:02.230 INFO cr2: instance ensure
2072026-05-20T16:21:04.639ZMay 20 16:21:04.620 INFO ox: instance ensure completed after 0 retries
2082026-05-20T16:21:04.639ZMay 20 16:21:04.620 INFO ox: instance run
2092026-05-20T16:21:04.671ZMay 20 16:21:04.621 DEBG [sc] ox: starting
2102026-05-20T16:21:04.671ZMay 20 16:21:04.621 DEBG [sc] ox: connecting to [::1]:47413
2112026-05-20T16:21:04.671ZMay 20 16:21:04.622 DEBG [sc] ox waiting for prompt
2122026-05-20T16:21:04.705ZMay 20 16:21:04.685 INFO cr2: instance ensure completed after 0 retries
2132026-05-20T16:21:04.705ZMay 20 16:21:04.685 INFO cr2: instance run
2142026-05-20T16:21:04.705ZMay 20 16:21:04.685 DEBG [sc] cr2: starting
2152026-05-20T16:21:04.705ZMay 20 16:21:04.685 DEBG [sc] cr2: connecting to [::1]:43605
2162026-05-20T16:21:04.705ZMay 20 16:21:04.686 DEBG [sc] cr2 waiting for prompt
2172026-05-20T16:21:04.737ZMay 20 16:21:04.691 INFO cr1: instance ensure completed after 0 retries
2182026-05-20T16:21:04.737ZMay 20 16:21:04.691 INFO cr1: instance run
2192026-05-20T16:21:04.737ZMay 20 16:21:04.692 DEBG [sc] cr1: starting
2202026-05-20T16:21:04.737ZMay 20 16:21:04.692 DEBG [sc] cr1: connecting to [::1]:56942
2212026-05-20T16:21:04.737ZMay 20 16:21:04.692 DEBG [sc] cr1 waiting for prompt
2222026-05-20T16:21:21.710ZMay 20 16:21:21.694 DEBG [sc] cr1: logging in
2232026-05-20T16:21:22.087ZMay 20 16:21:22.069 INFO cr1: mounting /opt/cargo-bay
2242026-05-20T16:21:22.087ZMay 20 16:21:22.069 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2252026-05-20T16:21:22.122ZMay 20 16:21:22.091 DEBG [sc] cr1: executing command `cd`
2262026-05-20T16:21:22.122ZMay 20 16:21:22.102 INFO cr1: finished mounting /opt/cargo-bay
2272026-05-20T16:21:22.123ZMay 20 16:21:22.102 DEBG [sc] cr1: executing command `hostname cr1`
2282026-05-20T16:21:22.158ZMay 20 16:21:22.113 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2292026-05-20T16:21:22.158ZMay 20 16:21:22.123 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2302026-05-20T16:21:22.158ZMay 20 16:21:22.134 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2312026-05-20T16:21:22.194ZMay 20 16:21:22.146 INFO cr1: logging out
2322026-05-20T16:21:24.226ZMay 20 16:21:24.211 INFO cr1: logged out
2332026-05-20T16:21:25.179ZMay 20 16:21:25.160 DEBG [sc] ox: logging in
2342026-05-20T16:21:25.386ZMay 20 16:21:25.369 INFO ox: mounting /opt/cargo-bay
2352026-05-20T16:21:25.386ZMay 20 16:21:25.369 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2362026-05-20T16:21:26.250ZMay 20 16:21:26.232 DEBG [sc] cr2: logging in
2372026-05-20T16:21:26.561ZMay 20 16:21:26.543 DEBG [sc] ox: executing command `cd`
2382026-05-20T16:21:26.598ZMay 20 16:21:26.553 INFO ox: finished mounting /opt/cargo-bay
2392026-05-20T16:21:26.598ZMay 20 16:21:26.553 DEBG [sc] ox: executing command `hostname ox`
2402026-05-20T16:21:26.598ZMay 20 16:21:26.565 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2412026-05-20T16:21:26.598ZMay 20 16:21:26.576 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2422026-05-20T16:21:26.635ZMay 20 16:21:26.587 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2432026-05-20T16:21:26.635ZMay 20 16:21:26.598 INFO ox: logging out
2442026-05-20T16:21:26.692ZMay 20 16:21:26.675 INFO ox: logged out
2452026-05-20T16:21:26.732ZMay 20 16:21:26.692 INFO cr2: mounting /opt/cargo-bay
2462026-05-20T16:21:26.732ZMay 20 16:21:26.692 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2472026-05-20T16:21:26.765ZMay 20 16:21:26.714 DEBG [sc] cr2: executing command `cd`
2482026-05-20T16:21:26.765ZMay 20 16:21:26.725 INFO cr2: finished mounting /opt/cargo-bay
2492026-05-20T16:21:26.765ZMay 20 16:21:26.725 DEBG [sc] cr2: executing command `hostname cr2`
2502026-05-20T16:21:26.765ZMay 20 16:21:26.736 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2512026-05-20T16:21:26.765ZMay 20 16:21:26.747 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2522026-05-20T16:21:26.800ZMay 20 16:21:26.758 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2532026-05-20T16:21:26.800ZMay 20 16:21:26.769 INFO cr2: logging out
2542026-05-20T16:21:29.649ZMay 20 16:21:29.630 INFO cr2: logged out
2552026-05-20T16:21:29.685ZMay 20 16:21:29.630 DEBG [sc] ox: starting
2562026-05-20T16:21:29.685ZMay 20 16:21:29.630 DEBG [sc] ox: connecting to [::1]:47413
2572026-05-20T16:21:29.685ZMay 20 16:21:29.631 DEBG [sc] ox waiting for prompt
2582026-05-20T16:21:29.685ZMay 20 16:21:29.641 DEBG [sc] ox: logging in
2592026-05-20T16:21:29.737ZMay 20 16:21:29.718 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2602026-05-20T16:21:34.896ZMay 20 16:21:34.879 DEBG [sc] ox: starting
2612026-05-20T16:21:34.896ZMay 20 16:21:34.879 DEBG [sc] ox: connecting to [::1]:47413
2622026-05-20T16:21:34.932ZMay 20 16:21:34.880 DEBG [sc] ox waiting for prompt
2632026-05-20T16:21:34.932ZMay 20 16:21:34.890 DEBG [sc] ox: logging in
2642026-05-20T16:21:34.999ZMay 20 16:21:34.978 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2652026-05-20T16:21:35.073ZMay 20 16:21:35.056 DEBG [sc] ox: starting
2662026-05-20T16:21:35.073ZMay 20 16:21:35.056 DEBG [sc] ox: connecting to [::1]:47413
2672026-05-20T16:21:35.105ZMay 20 16:21:35.056 DEBG [sc] ox waiting for prompt
2682026-05-20T16:21:35.105ZMay 20 16:21:35.067 DEBG [sc] ox: logging in
2692026-05-20T16:21:35.174ZMay 20 16:21:35.154 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2702026-05-20T16:21:35.239ZMay 20 16:21:35.221 INFO waiting for ceos to initialize
2712026-05-20T16:21:35.239ZMay 20 16:21:35.221 INFO cr1: installing frr
2722026-05-20T16:21:35.239ZMay 20 16:21:35.221 INFO ox: setting up npuvm
2732026-05-20T16:21:35.273ZMay 20 16:21:35.221 DEBG [sc] cr2: starting
2742026-05-20T16:21:35.274ZMay 20 16:21:35.221 DEBG [sc] cr2: connecting to [::1]:43605
2752026-05-20T16:21:35.274ZMay 20 16:21:35.221 DEBG [sc] cr1: starting
2762026-05-20T16:21:35.274ZMay 20 16:21:35.221 DEBG [sc] cr1: connecting to [::1]:56942
2772026-05-20T16:21:35.274ZMay 20 16:21:35.221 DEBG [sc] ox: starting
2782026-05-20T16:21:35.274ZMay 20 16:21:35.221 DEBG [sc] ox: connecting to [::1]:47413
2792026-05-20T16:21:35.274ZMay 20 16:21:35.222 DEBG [sc] cr2 waiting for prompt
2802026-05-20T16:21:35.274ZMay 20 16:21:35.222 DEBG [sc] ox waiting for prompt
2812026-05-20T16:21:35.274ZMay 20 16:21:35.222 DEBG [sc] cr1 waiting for prompt
2822026-05-20T16:21:35.274ZMay 20 16:21:35.232 DEBG [sc] ox: logging in
2832026-05-20T16:21:35.274ZMay 20 16:21:35.232 DEBG [sc] cr1: logging in
2842026-05-20T16:21:35.274ZMay 20 16:21:35.233 DEBG [sc] cr2: logging in
2852026-05-20T16:21:35.324ZMay 20 16:21:35.309 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2862026-05-20T16:21:35.405ZMay 20 16:21:35.387 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2872026-05-20T16:21:35.610ZMay 20 16:21:35.585 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2882026-05-20T16:21:37.671ZMay 20 16:21:37.652 INFO cr2: executing eos script show version
2892026-05-20T16:21:37.671ZMay 20 16:21:37.652 DEBG [sc] cr2: starting
2902026-05-20T16:21:37.671ZMay 20 16:21:37.652 DEBG [sc] cr2: connecting to [::1]:43605
2912026-05-20T16:21:37.708ZMay 20 16:21:37.653 DEBG [sc] cr2 waiting for prompt
2922026-05-20T16:21:37.708ZMay 20 16:21:37.663 DEBG [sc] cr2: logging in
2932026-05-20T16:21:37.827ZMay 20 16:21:37.807 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2942026-05-20T16:21:46.442ZMay 20 16:21:46.424 DEBG [sc] cr2: starting
2952026-05-20T16:21:46.442ZMay 20 16:21:46.424 DEBG [sc] cr2: connecting to [::1]:43605
2962026-05-20T16:21:46.479ZMay 20 16:21:46.425 DEBG [sc] cr2 waiting for prompt
2972026-05-20T16:21:46.479ZMay 20 16:21:46.435 DEBG [sc] cr2: logging in
2982026-05-20T16:21:46.618ZMay 20 16:21:46.600 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2992026-05-20T16:21:48.720ZMay 20 16:21:48.701 INFO cr2: executing eos script show version
3002026-05-20T16:21:48.721ZMay 20 16:21:48.701 DEBG [sc] cr2: starting
3012026-05-20T16:21:48.721ZMay 20 16:21:48.701 DEBG [sc] cr2: connecting to [::1]:43605
3022026-05-20T16:21:48.752ZMay 20 16:21:48.701 DEBG [sc] cr2 waiting for prompt
3032026-05-20T16:21:48.752ZMay 20 16:21:48.712 DEBG [sc] cr2: logging in
3042026-05-20T16:21:48.872ZMay 20 16:21:48.855 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3052026-05-20T16:21:51.304ZMay 20 16:21:51.228 DEBG [sc] ox: starting
3062026-05-20T16:21:51.304ZMay 20 16:21:51.228 DEBG [sc] ox: connecting to [::1]:47413
3072026-05-20T16:21:51.391ZMay 20 16:21:51.229 DEBG [sc] ox waiting for prompt
3082026-05-20T16:21:51.391ZMay 20 16:21:51.237 DEBG [sc] cr2: starting
3092026-05-20T16:21:51.391ZMay 20 16:21:51.237 DEBG [sc] cr2: connecting to [::1]:43605
3102026-05-20T16:21:51.391ZMay 20 16:21:51.238 DEBG [sc] cr2 waiting for prompt
3112026-05-20T16:21:51.391ZMay 20 16:21:51.238 DEBG [sc] ox: logging in
3122026-05-20T16:21:51.391ZMay 20 16:21:51.248 DEBG [sc] cr2: logging in
3132026-05-20T16:21:51.484ZMay 20 16:21:51.326 DEBG [sc] ox: executing command `chmod +x npuvm`
3142026-05-20T16:21:51.484ZMay 20 16:21:51.380 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3152026-05-20T16:21:51.484ZMay 20 16:21:51.393 DEBG [sc] ox: starting
3162026-05-20T16:21:51.484ZMay 20 16:21:51.393 DEBG [sc] ox: connecting to [::1]:47413
3172026-05-20T16:21:51.484ZMay 20 16:21:51.393 DEBG [sc] ox waiting for prompt
3182026-05-20T16:21:51.484ZMay 20 16:21:51.404 DEBG [sc] ox: logging in
3192026-05-20T16:21:51.570ZMay 20 16:21:51.493 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3202026-05-20T16:21:53.597ZMay 20 16:21:53.522 INFO cr2: executing eos script show version
3212026-05-20T16:21:53.597ZMay 20 16:21:53.522 DEBG [sc] cr2: starting
3222026-05-20T16:21:53.597ZMay 20 16:21:53.522 DEBG [sc] cr2: connecting to [::1]:43605
3232026-05-20T16:21:53.687ZMay 20 16:21:53.523 DEBG [sc] cr2 waiting for prompt
3242026-05-20T16:21:53.688ZMay 20 16:21:53.534 DEBG [sc] cr2: logging in
3252026-05-20T16:21:53.779ZMay 20 16:21:53.688 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3262026-05-20T16:21:56.132ZMay 20 16:21:56.108 INFO cr2: executing eos script
3272026-05-20T16:21:56.132Z enable
3282026-05-20T16:21:56.132Z configure
3292026-05-20T16:21:56.132Z ipv6 unicast-routing
3302026-05-20T16:21:56.132Z ip routing ipv6 interfaces
3312026-05-20T16:21:56.132Z ip routing
3322026-05-20T16:21:56.132Z ip route 1.2.3.0/24 null0
3332026-05-20T16:21:56.132Z ipv6 route fd99::/64 null0
3342026-05-20T16:21:56.132Z interface et1
3352026-05-20T16:21:56.132Z no switchport
3362026-05-20T16:21:56.132Z ipv6 enable
3372026-05-20T16:21:56.132Z
3382026-05-20T16:21:56.132Z router bgp 45
3392026-05-20T16:21:56.132Z router-id 1.2.3.1
3402026-05-20T16:21:56.133Z no bgp default ipv4-unicast
3412026-05-20T16:21:56.133Z timers bgp 2 6
3422026-05-20T16:21:56.133Z neighbor ebgp peer group
3432026-05-20T16:21:56.133Z neighbor ebgp remote-as 33
3442026-05-20T16:21:56.133Z neighbor interface Et1 peer-group ebgp
3452026-05-20T16:21:56.133Z address-family ipv4
3462026-05-20T16:21:56.133Z neighbor ebgp activate
3472026-05-20T16:21:56.133Z neighbor ebgp next-hop address-family ipv6 originate
3482026-05-20T16:21:56.133Z network 1.2.3.0/24
3492026-05-20T16:21:56.133Z exit
3502026-05-20T16:21:56.133Z address-family ipv6
3512026-05-20T16:21:56.133Z neighbor ebgp activate
3522026-05-20T16:21:56.133Z neighbor ebgp next-hop address-family ipv6 originate
3532026-05-20T16:21:56.133Z network fd99::/64
3542026-05-20T16:21:56.133Z exit
3552026-05-20T16:21:56.133Z exit
3562026-05-20T16:21:56.133Z
3572026-05-20T16:21:56.133ZMay 20 16:21:56.108 DEBG [sc] cr2: starting
3582026-05-20T16:21:56.133ZMay 20 16:21:56.108 DEBG [sc] cr2: connecting to [::1]:43605
3592026-05-20T16:21:56.169ZMay 20 16:21:56.109 DEBG [sc] cr2 waiting for prompt
3602026-05-20T16:21:56.169ZMay 20 16:21:56.120 DEBG [sc] cr2: logging in
3612026-05-20T16:21:56.281ZMay 20 16:21:56.252 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3622026-05-20T16:21:56.281Z enable
3632026-05-20T16:21:56.281Z configure
3642026-05-20T16:21:56.281Z ipv6 unicast-routing
3652026-05-20T16:21:56.281Z ip routing ipv6 interfaces
3662026-05-20T16:21:56.281Z ip routing
3672026-05-20T16:21:56.282Z ip route 1.2.3.0/24 null0
3682026-05-20T16:21:56.282Z ipv6 route fd99::/64 null0
3692026-05-20T16:21:56.282Z interface et1
3702026-05-20T16:21:56.282Z no switchport
3712026-05-20T16:21:56.282Z ipv6 enable
3722026-05-20T16:21:56.282Z
3732026-05-20T16:21:56.282Z router bgp 45
3742026-05-20T16:21:56.282Z router-id 1.2.3.1
3752026-05-20T16:21:56.282Z no bgp default ipv4-unicast
3762026-05-20T16:21:56.282Z timers bgp 2 6
3772026-05-20T16:21:56.282Z neighbor ebgp peer group
3782026-05-20T16:21:56.282Z neighbor ebgp remote-as 33
3792026-05-20T16:21:56.282Z neighbor interface Et1 peer-group ebgp
3802026-05-20T16:21:56.282Z address-family ipv4
3812026-05-20T16:21:56.282Z neighbor ebgp activate
3822026-05-20T16:21:56.282Z neighbor ebgp next-hop address-family ipv6 originate
3832026-05-20T16:21:56.282Z network 1.2.3.0/24
3842026-05-20T16:21:56.282Z exit
3852026-05-20T16:21:56.283Z address-family ipv6
3862026-05-20T16:21:56.283Z neighbor ebgp activate
3872026-05-20T16:21:56.283Z neighbor ebgp next-hop address-family ipv6 originate
3882026-05-20T16:21:56.283Z network fd99::/64
3892026-05-20T16:21:56.283Z exit
3902026-05-20T16:21:56.283Z exit
3912026-05-20T16:21:56.283Z '`
3922026-05-20T16:22:13.368ZMay 20 16:22:13.349 INFO cr1: enabling frr daemon bgpd
3932026-05-20T16:22:13.368ZMay 20 16:22:13.349 DEBG [sc] cr1: starting
3942026-05-20T16:22:13.368ZMay 20 16:22:13.349 DEBG [sc] cr1: connecting to [::1]:56942
3952026-05-20T16:22:13.404ZMay 20 16:22:13.350 DEBG [sc] cr1 waiting for prompt
3962026-05-20T16:22:13.404ZMay 20 16:22:13.360 DEBG [sc] cr1: logging in
3972026-05-20T16:22:13.534ZMay 20 16:22:13.515 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
3982026-05-20T16:22:15.610ZMay 20 16:22:15.593 DEBG [sc] cr1: starting
3992026-05-20T16:22:15.610ZMay 20 16:22:15.593 DEBG [sc] cr1: connecting to [::1]:56942
4002026-05-20T16:22:15.649ZMay 20 16:22:15.593 DEBG [sc] cr1 waiting for prompt
4012026-05-20T16:22:15.649ZMay 20 16:22:15.604 DEBG [sc] cr1: logging in
4022026-05-20T16:22:15.757ZMay 20 16:22:15.737 DEBG [sc] cr1: executing command `systemctl restart frr`
4032026-05-20T16:22:23.367ZMay 20 16:22:23.348 INFO cr1: executing frr script
4042026-05-20T16:22:23.367Z configure
4052026-05-20T16:22:23.367Z ip forwarding
4062026-05-20T16:22:23.367Z ipv6 forwarding
4072026-05-20T16:22:23.367Z ip route 1.2.3.0/24 null0
4082026-05-20T16:22:23.367Z ipv6 route fd99::/64 null0
4092026-05-20T16:22:23.367Z router bgp 44
4102026-05-20T16:22:23.367Z no bgp ebgp-requires-policy
4112026-05-20T16:22:23.367Z timers bgp 2 6
4122026-05-20T16:22:23.367Z neighbor enp0s8 interface remote-as external
4132026-05-20T16:22:23.367Z neighbor enp0s8 timers connect 1
4142026-05-20T16:22:23.367Z address-family ipv4 unicast
4152026-05-20T16:22:23.367Z network 1.2.3.0/24
4162026-05-20T16:22:23.368Z neighbor enp0s8 activate
4172026-05-20T16:22:23.368Z exit-address-family
4182026-05-20T16:22:23.368Z address-family ipv6 unicast
4192026-05-20T16:22:23.368Z network fd99::/64
4202026-05-20T16:22:23.368Z neighbor enp0s8 activate
4212026-05-20T16:22:23.368Z exit-address-family
4222026-05-20T16:22:23.368Z exit
4232026-05-20T16:22:23.368Z
4242026-05-20T16:22:23.368ZMay 20 16:22:23.348 DEBG [sc] cr1: starting
4252026-05-20T16:22:23.404ZMay 20 16:22:23.348 DEBG [sc] cr1: connecting to [::1]:56942
4262026-05-20T16:22:23.404ZMay 20 16:22:23.348 DEBG [sc] cr1 waiting for prompt
4272026-05-20T16:22:23.404ZMay 20 16:22:23.360 DEBG [sc] cr1: logging in
4282026-05-20T16:22:23.510ZMay 20 16:22:23.492 DEBG [sc] cr1: executing command `vtysh -c '' -c ' configure' -c ' ip forwarding' -c ' ipv6 forwarding' -c ' ip route 1.2.3.0/24 null0' -c ' ipv6 route fd99::/64 null0' -c ' router bgp 44' -c ' no bgp ebgp-requires-policy' -c ' timers bgp 2 6' -c ' neighbor enp0s8 interface remote-as external' -c ' neighbor enp0s8 timers connect 1 ' -c ' address-family ipv4 unicast' -c ' network 1.2.3.0/24' -c ' neighbor enp0s8 activate' -c ' exit-address-family' -c ' address-family ipv6 unicast' -c ' network fd99::/64' -c ' neighbor enp0s8 activate' -c ' exit-address-family' -c ' exit' -c ' '`
4292026-05-20T16:23:54.442ZMay 20 16:23:54.370 DEBG [sc] ox: starting
4302026-05-20T16:23:54.442ZMay 20 16:23:54.370 DEBG [sc] ox: connecting to [::1]:47413
4312026-05-20T16:23:54.442ZMay 20 16:23:54.370 DEBG [sc] ox waiting for prompt
4322026-05-20T16:23:54.533ZMay 20 16:23:54.381 DEBG [sc] ox: logging in
4332026-05-20T16:23:54.621ZMay 20 16:23:54.458 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4342026-05-20T16:23:54.792ZMay 20 16:23:54.716 DEBG [sc] ox: starting
4352026-05-20T16:23:54.792ZMay 20 16:23:54.716 DEBG [sc] ox: connecting to [::1]:47413
4362026-05-20T16:23:54.883ZMay 20 16:23:54.717 DEBG [sc] ox waiting for prompt
4372026-05-20T16:23:54.883ZMay 20 16:23:54.728 DEBG [sc] ox: logging in
4382026-05-20T16:23:54.883ZMay 20 16:23:54.806 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4392026-05-20T16:23:55.855ZMay 20 16:23:55.829 DEBG [sc] ox: starting
4402026-05-20T16:23:55.855ZMay 20 16:23:55.829 DEBG [sc] ox: connecting to [::1]:47413
4412026-05-20T16:23:55.890ZMay 20 16:23:55.830 DEBG [sc] ox waiting for prompt
4422026-05-20T16:23:55.890ZMay 20 16:23:55.830 DEBG [sc] ox: logging in
4432026-05-20T16:23:55.924ZMay 20 16:23:55.907 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4442026-05-20T16:23:55.993ZMay 20 16:23:55.975 DEBG [sc] ox: starting
4452026-05-20T16:23:55.993ZMay 20 16:23:55.975 DEBG [sc] ox: connecting to [::1]:47413
4462026-05-20T16:23:56.027ZMay 20 16:23:55.975 DEBG [sc] ox waiting for prompt
4472026-05-20T16:23:56.027ZMay 20 16:23:55.985 DEBG [sc] ox: logging in
4482026-05-20T16:23:56.083ZMay 20 16:23:56.062 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4492026-05-20T16:23:56.142ZMay 20 16:23:56.118 DEBG [sc] ox: starting
4502026-05-20T16:23:56.142ZMay 20 16:23:56.118 DEBG [sc] ox: connecting to [::1]:47413
4512026-05-20T16:23:56.175ZMay 20 16:23:56.119 DEBG [sc] ox waiting for prompt
4522026-05-20T16:23:56.175ZMay 20 16:23:56.129 DEBG [sc] ox: logging in
4532026-05-20T16:23:56.225ZMay 20 16:23:56.206 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4542026-05-20T16:23:56.286ZMay 20 16:23:56.262 DEBG [sc] ox: starting
4552026-05-20T16:23:56.286ZMay 20 16:23:56.262 DEBG [sc] ox: connecting to [::1]:47413
4562026-05-20T16:23:56.323ZMay 20 16:23:56.262 DEBG [sc] ox waiting for prompt
4572026-05-20T16:23:56.323ZMay 20 16:23:56.273 DEBG [sc] ox: logging in
4582026-05-20T16:23:56.370ZMay 20 16:23:56.350 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4592026-05-20T16:23:56.429ZMay 20 16:23:56.405 DEBG [sc] ox: starting
4602026-05-20T16:23:56.429ZMay 20 16:23:56.405 DEBG [sc] ox: connecting to [::1]:47413
4612026-05-20T16:23:56.463ZMay 20 16:23:56.406 DEBG [sc] ox waiting for prompt
4622026-05-20T16:23:56.463ZMay 20 16:23:56.416 DEBG [sc] ox: logging in
4632026-05-20T16:23:56.513ZMay 20 16:23:56.493 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4642026-05-20T16:23:56.569ZMay 20 16:23:56.548 DEBG [sc] ox: starting
4652026-05-20T16:23:56.570ZMay 20 16:23:56.548 DEBG [sc] ox: connecting to [::1]:47413
4662026-05-20T16:23:56.602ZMay 20 16:23:56.549 DEBG [sc] ox waiting for prompt
4672026-05-20T16:23:56.602ZMay 20 16:23:56.559 DEBG [sc] ox: logging in
4682026-05-20T16:23:56.655ZMay 20 16:23:56.637 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4692026-05-20T16:23:56.713ZMay 20 16:23:56.693 DEBG [sc] ox: starting
4702026-05-20T16:23:56.713ZMay 20 16:23:56.693 DEBG [sc] ox: connecting to [::1]:47413
4712026-05-20T16:23:56.746ZMay 20 16:23:56.694 DEBG [sc] ox waiting for prompt
4722026-05-20T16:23:56.746ZMay 20 16:23:56.704 DEBG [sc] ox: logging in
4732026-05-20T16:23:56.798ZMay 20 16:23:56.781 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4742026-05-20T16:23:56.865ZMay 20 16:23:56.847 DEBG [sc] ox: starting
4752026-05-20T16:23:56.865ZMay 20 16:23:56.847 DEBG [sc] ox: connecting to [::1]:47413
4762026-05-20T16:23:56.897ZMay 20 16:23:56.848 DEBG [sc] ox waiting for prompt
4772026-05-20T16:23:56.897ZMay 20 16:23:56.858 DEBG [sc] ox: logging in
4782026-05-20T16:23:56.955ZMay 20 16:23:56.936 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4792026-05-20T16:23:57.027ZMay 20 16:23:57.008 INFO adding BGP router to mgd
4802026-05-20T16:24:00.117ZMay 20 16:24:00.096 INFO cr1: executing frr script show ip bgp json
4812026-05-20T16:24:00.117ZMay 20 16:24:00.096 DEBG [sc] cr1: starting
4822026-05-20T16:24:00.117ZMay 20 16:24:00.096 DEBG [sc] cr1: connecting to [::1]:56942
4832026-05-20T16:24:00.151ZMay 20 16:24:00.096 DEBG [sc] cr1 waiting for prompt
4842026-05-20T16:24:00.151ZMay 20 16:24:00.107 DEBG [sc] cr1: logging in
4852026-05-20T16:24:00.459ZMay 20 16:24:00.438 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4862026-05-20T16:24:02.589ZMay 20 16:24:02.568 INFO cr1: executing frr script show bgp json
4872026-05-20T16:24:02.589ZMay 20 16:24:02.568 DEBG [sc] cr1: starting
4882026-05-20T16:24:02.589ZMay 20 16:24:02.568 DEBG [sc] cr1: connecting to [::1]:56942
4892026-05-20T16:24:02.621ZMay 20 16:24:02.569 DEBG [sc] cr1 waiting for prompt
4902026-05-20T16:24:02.621ZMay 20 16:24:02.579 DEBG [sc] cr1: logging in
4912026-05-20T16:24:02.724ZMay 20 16:24:02.700 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
4922026-05-20T16:24:04.836ZMay 20 16:24:04.820 INFO cr2: executing eos script show ip bgp | json
4932026-05-20T16:24:04.836ZMay 20 16:24:04.821 DEBG [sc] cr2: starting
4942026-05-20T16:24:04.836ZMay 20 16:24:04.821 DEBG [sc] cr2: connecting to [::1]:43605
4952026-05-20T16:24:04.867ZMay 20 16:24:04.821 DEBG [sc] cr2 waiting for prompt
4962026-05-20T16:24:04.867ZMay 20 16:24:04.832 DEBG [sc] cr2: logging in
4972026-05-20T16:24:05.202ZMay 20 16:24:05.180 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
4982026-05-20T16:24:07.591ZMay 20 16:24:07.566 INFO cr2: executing eos script show ipv6 bgp | json
4992026-05-20T16:24:07.591ZMay 20 16:24:07.566 DEBG [sc] cr2: starting
5002026-05-20T16:24:07.591ZMay 20 16:24:07.566 DEBG [sc] cr2: connecting to [::1]:43605
5012026-05-20T16:24:07.591ZMay 20 16:24:07.566 DEBG [sc] cr2 waiting for prompt
5022026-05-20T16:24:07.625ZMay 20 16:24:07.577 DEBG [sc] cr2: logging in
5032026-05-20T16:24:07.758ZMay 20 16:24:07.742 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5042026-05-20T16:24:10.134ZMay 20 16:24:10.118 INFO trio bgp unnumbered test passed 🎉
5052026-05-20T16:24:10.134ZMay 20 16:24:10.118 INFO destroying runner for deployment mgtriou
5062026-05-20T16:24:10.134ZMay 20 16:24:10.118 INFO destroying deployment mgtriou
5072026-05-20T16:24:10.134ZMay 20 16:24:10.118 INFO destroying nodes
5082026-05-20T16:24:10.252ZMay 20 16:24:10.233 INFO destroying links
5092026-05-20T16:24:10.252ZMay 20 16:24:10.233 INFO destroying link mgtriou_ox_sn_vnic0
5102026-05-20T16:24:10.287ZMay 20 16:24:10.235 INFO destroying link mgtriou_ox_sn_sim0
5112026-05-20T16:24:10.287ZMay 20 16:24:10.237 INFO destroying link mgtriou_cr1_vn_vnic0
5122026-05-20T16:24:11.255ZMay 20 16:24:11.239 INFO destroying link mgtriou_cr1_vn_sim0
5132026-05-20T16:24:11.288ZMay 20 16:24:11.240 INFO destroying link mgtriou_ox_sn_vnic1
5142026-05-20T16:24:11.288ZMay 20 16:24:11.242 INFO destroying link mgtriou_ox_sn_sim1
5152026-05-20T16:24:11.288ZMay 20 16:24:11.243 INFO destroying link mgtriou_cr2_vn_vnic0
5162026-05-20T16:24:11.288ZMay 20 16:24:11.244 INFO destroying link mgtriou_cr2_vn_sim0
5172026-05-20T16:24:11.288ZMay 20 16:24:11.245 INFO destroying external links
5182026-05-20T16:24:11.288ZMay 20 16:24:11.245 INFO destroying external link mgtriou_ox_vn_vnic2
5192026-05-20T16:24:11.288ZMay 20 16:24:11.246 INFO destroying external link mgtriou_cr1_vn_vnic1
5202026-05-20T16:24:11.288ZMay 20 16:24:11.248 INFO destroying external link mgtriou_cr2_vn_vnic1
5212026-05-20T16:24:11.288ZMay 20 16:24:11.249 INFO destroying images
5222026-05-20T16:24:11.743ZMay 20 16:24:11.725 INFO destroying workspace at .falcon
5232026-05-20T16:24:11.780Z+ RUST_LOG=debug
5242026-05-20T16:24:11.780Z+ pfexec ./falcon-lab run trio-bfd-static-routing
5252026-05-20T16:24:11.811ZMay 20 16:24:11.769 DEBG using default route interface igb0
5262026-05-20T16:24:11.812ZMay 20 16:24:11.769 DEBG using default route interface igb0
5272026-05-20T16:24:11.812ZMay 20 16:24:11.769 DEBG using default route interface igb0
5282026-05-20T16:24:11.812ZMay 20 16:24:11.769 INFO launching runner: deployment(mgtriobfd) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
5292026-05-20T16:24:11.812ZMay 20 16:24:11.769 INFO starting preflight for deployment mgtriobfd
5302026-05-20T16:24:12.698ZMay 20 16:24:12.680 INFO creating links
5312026-05-20T16:24:12.698ZMay 20 16:24:12.680 DEBG destroying link mgtriobfd_ox_sn_vnic0
5322026-05-20T16:24:12.698ZMay 20 16:24:12.680 DEBG destroying link mgtriobfd_ox_sn_sim0
5332026-05-20T16:24:12.698ZMay 20 16:24:12.680 INFO creating simnet link 'mgtriobfd_ox_sn_sim0'
5342026-05-20T16:24:12.735ZMay 20 16:24:12.682 INFO creating vnic link 'mgtriobfd_ox_sn_vnic0'
5352026-05-20T16:24:12.735ZMay 20 16:24:12.689 DEBG link pair created
5362026-05-20T16:24:12.735ZMay 20 16:24:12.689 DEBG destroying link mgtriobfd_cr1_vn_vnic0
5372026-05-20T16:24:12.735ZMay 20 16:24:12.689 DEBG destroying link mgtriobfd_cr1_vn_sim0
5382026-05-20T16:24:12.735ZMay 20 16:24:12.689 INFO creating simnet link 'mgtriobfd_cr1_vn_sim0'
5392026-05-20T16:24:12.735ZMay 20 16:24:12.691 INFO creating vnic link 'mgtriobfd_cr1_vn_vnic0'
5402026-05-20T16:24:12.735ZMay 20 16:24:12.697 DEBG link pair created
5412026-05-20T16:24:12.735ZMay 20 16:24:12.698 DEBG destroying link mgtriobfd_ox_sn_vnic1
5422026-05-20T16:24:12.735ZMay 20 16:24:12.698 DEBG destroying link mgtriobfd_ox_sn_sim1
5432026-05-20T16:24:12.735ZMay 20 16:24:12.698 INFO creating simnet link 'mgtriobfd_ox_sn_sim1'
5442026-05-20T16:24:12.735ZMay 20 16:24:12.698 INFO creating vnic link 'mgtriobfd_ox_sn_vnic1'
5452026-05-20T16:24:12.735ZMay 20 16:24:12.706 DEBG link pair created
5462026-05-20T16:24:12.735ZMay 20 16:24:12.706 DEBG destroying link mgtriobfd_cr2_vn_vnic0
5472026-05-20T16:24:12.735ZMay 20 16:24:12.706 DEBG destroying link mgtriobfd_cr2_vn_sim0
5482026-05-20T16:24:12.735ZMay 20 16:24:12.706 INFO creating simnet link 'mgtriobfd_cr2_vn_sim0'
5492026-05-20T16:24:12.735ZMay 20 16:24:12.708 INFO creating vnic link 'mgtriobfd_cr2_vn_vnic0'
5502026-05-20T16:24:12.771ZMay 20 16:24:12.714 DEBG link pair created
5512026-05-20T16:24:12.771ZMay 20 16:24:12.715 INFO creating external links
5522026-05-20T16:24:12.771ZMay 20 16:24:12.715 DEBG destroying external link mgtriobfd_ox_vn_vnic2
5532026-05-20T16:24:12.771ZMay 20 16:24:12.715 INFO creating external link mgtriobfd_ox_vn_vnic2
5542026-05-20T16:24:12.771ZMay 20 16:24:12.716 DEBG external link mgtriobfd_ox_vn_vnic2@igb0 created
5552026-05-20T16:24:12.771ZMay 20 16:24:12.716 DEBG destroying external link mgtriobfd_cr1_vn_vnic1
5562026-05-20T16:24:12.771ZMay 20 16:24:12.716 INFO creating external link mgtriobfd_cr1_vn_vnic1
5572026-05-20T16:24:12.771ZMay 20 16:24:12.717 DEBG external link mgtriobfd_cr1_vn_vnic1@igb0 created
5582026-05-20T16:24:12.772ZMay 20 16:24:12.717 DEBG destroying external link mgtriobfd_cr2_vn_vnic1
5592026-05-20T16:24:12.772ZMay 20 16:24:12.717 INFO creating external link mgtriobfd_cr2_vn_vnic1
5602026-05-20T16:24:12.772ZMay 20 16:24:12.718 DEBG external link mgtriobfd_cr2_vn_vnic1@igb0 created
5612026-05-20T16:24:12.772ZMay 20 16:24:12.718 INFO creating nodes
5622026-05-20T16:24:12.772ZMay 20 16:24:12.718 INFO ox: launching node
5632026-05-20T16:24:12.772ZMay 20 16:24:12.721 INFO cr1: launching node
5642026-05-20T16:24:12.772ZMay 20 16:24:12.723 INFO cr2: launching node
5652026-05-20T16:24:12.772ZMay 20 16:24:12.736 INFO launched instance ox with pid 882 on port 35507
5662026-05-20T16:24:12.772ZMay 20 16:24:12.736 INFO ox: instance ensure
5672026-05-20T16:24:12.772ZMay 20 16:24:12.736 INFO launched instance cr1 with pid 883 on port 63431
5682026-05-20T16:24:12.772ZMay 20 16:24:12.736 INFO cr1: instance ensure
5692026-05-20T16:24:12.772ZMay 20 16:24:12.737 INFO launched instance cr2 with pid 884 on port 35648
5702026-05-20T16:24:12.772ZMay 20 16:24:12.737 INFO cr2: instance ensure
5712026-05-20T16:24:14.821ZMay 20 16:24:14.801 INFO cr2: instance ensure completed after 0 retries
5722026-05-20T16:24:14.821ZMay 20 16:24:14.801 INFO cr2: instance run
5732026-05-20T16:24:14.855ZMay 20 16:24:14.801 DEBG [sc] cr2: starting
5742026-05-20T16:24:14.856ZMay 20 16:24:14.802 DEBG [sc] cr2: connecting to [::1]:35648
5752026-05-20T16:24:14.856ZMay 20 16:24:14.802 DEBG [sc] cr2 waiting for prompt
5762026-05-20T16:24:14.889ZMay 20 16:24:14.868 INFO ox: instance ensure completed after 0 retries
5772026-05-20T16:24:14.890ZMay 20 16:24:14.868 INFO ox: instance run
5782026-05-20T16:24:14.890ZMay 20 16:24:14.869 DEBG [sc] ox: starting
5792026-05-20T16:24:14.890ZMay 20 16:24:14.869 DEBG [sc] ox: connecting to [::1]:35507
5802026-05-20T16:24:14.890ZMay 20 16:24:14.869 DEBG [sc] ox waiting for prompt
5812026-05-20T16:24:14.975ZMay 20 16:24:14.957 INFO cr1: instance ensure completed after 0 retries
5822026-05-20T16:24:14.975ZMay 20 16:24:14.957 INFO cr1: instance run
5832026-05-20T16:24:15.011ZMay 20 16:24:14.957 DEBG [sc] cr1: starting
5842026-05-20T16:24:15.011ZMay 20 16:24:14.957 DEBG [sc] cr1: connecting to [::1]:63431
5852026-05-20T16:24:15.011ZMay 20 16:24:14.958 DEBG [sc] cr1 waiting for prompt
5862026-05-20T16:24:32.079ZMay 20 16:24:32.060 DEBG [sc] cr1: logging in
5872026-05-20T16:24:32.473ZMay 20 16:24:32.456 INFO cr1: mounting /opt/cargo-bay
5882026-05-20T16:24:32.473ZMay 20 16:24:32.456 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5892026-05-20T16:24:32.507ZMay 20 16:24:32.479 DEBG [sc] cr1: executing command `cd`
5902026-05-20T16:24:32.540ZMay 20 16:24:32.490 INFO cr1: finished mounting /opt/cargo-bay
5912026-05-20T16:24:32.540ZMay 20 16:24:32.490 DEBG [sc] cr1: executing command `hostname cr1`
5922026-05-20T16:24:32.540ZMay 20 16:24:32.501 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
5932026-05-20T16:24:32.540ZMay 20 16:24:32.512 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
5942026-05-20T16:24:32.608ZMay 20 16:24:32.523 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
5952026-05-20T16:24:32.608ZMay 20 16:24:32.534 INFO cr1: logging out
5962026-05-20T16:24:33.140ZMay 20 16:24:33.121 DEBG [sc] ox: logging in
5972026-05-20T16:24:33.346ZMay 20 16:24:33.325 INFO ox: mounting /opt/cargo-bay
5982026-05-20T16:24:33.346ZMay 20 16:24:33.325 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5992026-05-20T16:24:34.361ZMay 20 16:24:34.343 DEBG [sc] ox: executing command `cd`
6002026-05-20T16:24:34.394ZMay 20 16:24:34.354 INFO ox: finished mounting /opt/cargo-bay
6012026-05-20T16:24:34.394ZMay 20 16:24:34.354 DEBG [sc] ox: executing command `hostname ox`
6022026-05-20T16:24:34.394ZMay 20 16:24:34.365 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
6032026-05-20T16:24:34.394ZMay 20 16:24:34.375 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
6042026-05-20T16:24:34.428ZMay 20 16:24:34.387 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
6052026-05-20T16:24:34.428ZMay 20 16:24:34.398 INFO ox: logging out
6062026-05-20T16:24:34.480ZMay 20 16:24:34.464 INFO ox: logged out
6072026-05-20T16:24:34.627ZMay 20 16:24:34.605 INFO cr1: logged out
6082026-05-20T16:24:36.426ZMay 20 16:24:36.407 DEBG [sc] cr2: logging in
6092026-05-20T16:24:36.807ZMay 20 16:24:36.790 INFO cr2: mounting /opt/cargo-bay
6102026-05-20T16:24:36.807ZMay 20 16:24:36.790 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6112026-05-20T16:24:36.840ZMay 20 16:24:36.801 DEBG [sc] cr2: executing command `cd`
6122026-05-20T16:24:36.840ZMay 20 16:24:36.812 INFO cr2: finished mounting /opt/cargo-bay
6132026-05-20T16:24:36.840ZMay 20 16:24:36.812 DEBG [sc] cr2: executing command `hostname cr2`
6142026-05-20T16:24:36.870ZMay 20 16:24:36.823 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
6152026-05-20T16:24:36.870ZMay 20 16:24:36.835 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
6162026-05-20T16:24:36.870ZMay 20 16:24:36.845 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
6172026-05-20T16:24:36.901ZMay 20 16:24:36.856 INFO cr2: logging out
6182026-05-20T16:24:39.890ZMay 20 16:24:39.869 INFO cr2: logged out
6192026-05-20T16:24:39.924ZMay 20 16:24:39.870 DEBG [sc] ox: starting
6202026-05-20T16:24:39.924ZMay 20 16:24:39.870 DEBG [sc] ox: connecting to [::1]:35507
6212026-05-20T16:24:39.924ZMay 20 16:24:39.870 DEBG [sc] ox waiting for prompt
6222026-05-20T16:24:39.924ZMay 20 16:24:39.881 DEBG [sc] ox: logging in
6232026-05-20T16:24:39.989ZMay 20 16:24:39.969 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
6242026-05-20T16:24:45.680ZMay 20 16:24:45.665 DEBG [sc] ox: starting
6252026-05-20T16:24:45.681ZMay 20 16:24:45.665 DEBG [sc] ox: connecting to [::1]:35507
6262026-05-20T16:24:45.713ZMay 20 16:24:45.665 DEBG [sc] ox waiting for prompt
6272026-05-20T16:24:45.713ZMay 20 16:24:45.676 DEBG [sc] ox: logging in
6282026-05-20T16:24:45.784ZMay 20 16:24:45.764 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
6292026-05-20T16:24:45.874ZMay 20 16:24:45.852 DEBG [sc] ox: starting
6302026-05-20T16:24:45.874ZMay 20 16:24:45.852 DEBG [sc] ox: connecting to [::1]:35507
6312026-05-20T16:24:45.906ZMay 20 16:24:45.852 DEBG [sc] ox waiting for prompt
6322026-05-20T16:24:45.906ZMay 20 16:24:45.863 DEBG [sc] ox: logging in
6332026-05-20T16:24:45.967ZMay 20 16:24:45.952 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
6342026-05-20T16:24:46.035ZMay 20 16:24:46.017 INFO waiting for ceos to initialize
6352026-05-20T16:24:46.035ZMay 20 16:24:46.018 INFO cr1: installing frr
6362026-05-20T16:24:46.035ZMay 20 16:24:46.018 INFO ox: setting up npuvm
6372026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr2: starting
6382026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr2: connecting to [::1]:35648
6392026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr1: starting
6402026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr1: connecting to [::1]:63431
6412026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] ox: starting
6422026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] ox: connecting to [::1]:35507
6432026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr2 waiting for prompt
6442026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] cr1 waiting for prompt
6452026-05-20T16:24:46.069ZMay 20 16:24:46.018 DEBG [sc] ox waiting for prompt
6462026-05-20T16:24:46.069ZMay 20 16:24:46.029 DEBG [sc] ox: logging in
6472026-05-20T16:24:46.069ZMay 20 16:24:46.029 DEBG [sc] cr2: logging in
6482026-05-20T16:24:46.069ZMay 20 16:24:46.030 DEBG [sc] cr1: logging in
6492026-05-20T16:24:46.134ZMay 20 16:24:46.117 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
6502026-05-20T16:24:46.197ZMay 20 16:24:46.173 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6512026-05-20T16:24:46.439ZMay 20 16:24:46.420 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
6522026-05-20T16:24:48.492ZMay 20 16:24:48.462 INFO cr2: executing eos script show version
6532026-05-20T16:24:48.492ZMay 20 16:24:48.462 DEBG [sc] cr2: starting
6542026-05-20T16:24:48.492ZMay 20 16:24:48.462 DEBG [sc] cr2: connecting to [::1]:35648
6552026-05-20T16:24:48.520ZMay 20 16:24:48.463 DEBG [sc] cr2 waiting for prompt
6562026-05-20T16:24:48.520ZMay 20 16:24:48.473 DEBG [sc] cr2: logging in
6572026-05-20T16:24:48.635ZMay 20 16:24:48.617 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6582026-05-20T16:24:53.223ZMay 20 16:24:53.164 DEBG [sc] ox: starting
6592026-05-20T16:24:53.223ZMay 20 16:24:53.164 DEBG [sc] ox: connecting to [::1]:35507
6602026-05-20T16:24:53.298ZMay 20 16:24:53.164 DEBG [sc] ox waiting for prompt
6612026-05-20T16:24:53.298ZMay 20 16:24:53.175 DEBG [sc] ox: logging in
6622026-05-20T16:24:53.374ZMay 20 16:24:53.251 DEBG [sc] ox: executing command `chmod +x npuvm`
6632026-05-20T16:24:53.452ZMay 20 16:24:53.317 DEBG [sc] ox: starting
6642026-05-20T16:24:53.452ZMay 20 16:24:53.318 DEBG [sc] ox: connecting to [::1]:35507
6652026-05-20T16:24:53.452ZMay 20 16:24:53.318 DEBG [sc] ox waiting for prompt
6662026-05-20T16:24:53.452ZMay 20 16:24:53.328 DEBG [sc] ox: logging in
6672026-05-20T16:24:53.526ZMay 20 16:24:53.405 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
6682026-05-20T16:24:58.026ZMay 20 16:24:58.005 DEBG [sc] cr2: starting
6692026-05-20T16:24:58.026ZMay 20 16:24:58.005 DEBG [sc] cr2: connecting to [::1]:35648
6702026-05-20T16:24:58.061ZMay 20 16:24:58.006 DEBG [sc] cr2 waiting for prompt
6712026-05-20T16:24:58.061ZMay 20 16:24:58.016 DEBG [sc] cr2: logging in
6722026-05-20T16:24:58.195ZMay 20 16:24:58.171 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6732026-05-20T16:25:00.296ZMay 20 16:25:00.275 INFO cr2: executing eos script show version
6742026-05-20T16:25:00.296ZMay 20 16:25:00.275 DEBG [sc] cr2: starting
6752026-05-20T16:25:00.296ZMay 20 16:25:00.275 DEBG [sc] cr2: connecting to [::1]:35648
6762026-05-20T16:25:00.329ZMay 20 16:25:00.275 DEBG [sc] cr2 waiting for prompt
6772026-05-20T16:25:00.329ZMay 20 16:25:00.285 DEBG [sc] cr2: logging in
6782026-05-20T16:25:00.446ZMay 20 16:25:00.429 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6792026-05-20T16:25:02.808ZMay 20 16:25:02.785 INFO cr2: executing eos script
6802026-05-20T16:25:02.808Z enable
6812026-05-20T16:25:02.808Z configure
6822026-05-20T16:25:02.808Z ip routing
6832026-05-20T16:25:02.808Z ipv6 unicast-routing
6842026-05-20T16:25:02.808Z interface Ethernet1
6852026-05-20T16:25:02.808Z no switchport
6862026-05-20T16:25:02.808Z ip address 10.0.1.2/24
6872026-05-20T16:25:02.808Z ipv6 enable
6882026-05-20T16:25:02.808Z ipv6 address fd00:2::2/64
6892026-05-20T16:25:02.808Z bfd interval 300 min-rx 300 multiplier 3
6902026-05-20T16:25:02.808Z exit
6912026-05-20T16:25:02.808Z ip route 100.64.0.0/24 10.0.1.1 track bfd
6922026-05-20T16:25:02.808Z ipv6 route 3fff::/64 fd00:2::1 track bfd
6932026-05-20T16:25:02.808Z exit
6942026-05-20T16:25:02.808Z
6952026-05-20T16:25:02.808ZMay 20 16:25:02.785 DEBG [sc] cr2: starting
6962026-05-20T16:25:02.808ZMay 20 16:25:02.785 DEBG [sc] cr2: connecting to [::1]:35648
6972026-05-20T16:25:02.840ZMay 20 16:25:02.785 DEBG [sc] cr2 waiting for prompt
6982026-05-20T16:25:02.840ZMay 20 16:25:02.796 DEBG [sc] cr2: logging in
6992026-05-20T16:25:02.974ZMay 20 16:25:02.950 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
7002026-05-20T16:25:02.974Z enable
7012026-05-20T16:25:02.974Z configure
7022026-05-20T16:25:02.974Z ip routing
7032026-05-20T16:25:02.974Z ipv6 unicast-routing
7042026-05-20T16:25:02.974Z interface Ethernet1
7052026-05-20T16:25:02.974Z no switchport
7062026-05-20T16:25:02.974Z ip address 10.0.1.2/24
7072026-05-20T16:25:02.974Z ipv6 enable
7082026-05-20T16:25:02.974Z ipv6 address fd00:2::2/64
7092026-05-20T16:25:02.974Z bfd interval 300 min-rx 300 multiplier 3
7102026-05-20T16:25:02.974Z exit
7112026-05-20T16:25:02.974Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7122026-05-20T16:25:02.974Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7132026-05-20T16:25:02.974Z exit
7142026-05-20T16:25:02.974Z '`
7152026-05-20T16:25:24.383ZMay 20 16:25:24.366 INFO cr1: enabling frr daemon bfdd
7162026-05-20T16:25:24.383ZMay 20 16:25:24.366 DEBG [sc] cr1: starting
7172026-05-20T16:25:24.421ZMay 20 16:25:24.366 DEBG [sc] cr1: connecting to [::1]:63431
7182026-05-20T16:25:24.421ZMay 20 16:25:24.366 DEBG [sc] cr1 waiting for prompt
7192026-05-20T16:25:24.421ZMay 20 16:25:24.377 DEBG [sc] cr1: logging in
7202026-05-20T16:25:24.530ZMay 20 16:25:24.509 DEBG [sc] cr1: executing command `sed -i 's/bfdd=no/bfdd=yes/g' /etc/frr/daemons`
7212026-05-20T16:25:26.608ZMay 20 16:25:26.589 DEBG [sc] cr1: starting
7222026-05-20T16:25:26.608ZMay 20 16:25:26.589 DEBG [sc] cr1: connecting to [::1]:63431
7232026-05-20T16:25:26.643ZMay 20 16:25:26.589 DEBG [sc] cr1 waiting for prompt
7242026-05-20T16:25:26.643ZMay 20 16:25:26.599 DEBG [sc] cr1: logging in
7252026-05-20T16:25:26.759ZMay 20 16:25:26.731 DEBG [sc] cr1: executing command `systemctl restart frr`
7262026-05-20T16:25:34.331ZMay 20 16:25:34.313 INFO cr1: executing frr script
7272026-05-20T16:25:34.332Z configure
7282026-05-20T16:25:34.332Z interface enp0s8
7292026-05-20T16:25:34.332Z ip address 10.0.0.2/24
7302026-05-20T16:25:34.332Z ipv6 address fd00:1::2/64
7312026-05-20T16:25:34.332Z no shutdown
7322026-05-20T16:25:34.332Z exit
7332026-05-20T16:25:34.332Z bfd
7342026-05-20T16:25:34.332Z peer 10.0.0.1 local-address 10.0.0.2
7352026-05-20T16:25:34.332Z detect-multiplier 3
7362026-05-20T16:25:34.332Z receive-interval 300
7372026-05-20T16:25:34.332Z transmit-interval 300
7382026-05-20T16:25:34.332Z no shutdown
7392026-05-20T16:25:34.332Z exit
7402026-05-20T16:25:34.332Z peer fd00:1::1 local-address fd00:1::2
7412026-05-20T16:25:34.332Z detect-multiplier 3
7422026-05-20T16:25:34.332Z receive-interval 300
7432026-05-20T16:25:34.332Z transmit-interval 300
7442026-05-20T16:25:34.332Z no shutdown
7452026-05-20T16:25:34.332Z exit
7462026-05-20T16:25:34.332Z exit
7472026-05-20T16:25:34.332Z
7482026-05-20T16:25:34.369ZMay 20 16:25:34.313 DEBG [sc] cr1: starting
7492026-05-20T16:25:34.369ZMay 20 16:25:34.313 DEBG [sc] cr1: connecting to [::1]:63431
7502026-05-20T16:25:34.369ZMay 20 16:25:34.314 DEBG [sc] cr1 waiting for prompt
7512026-05-20T16:25:34.369ZMay 20 16:25:34.325 DEBG [sc] cr1: logging in
7522026-05-20T16:25:34.506ZMay 20 16:25:34.479 DEBG [sc] cr1: executing command `vtysh -c '' -c ' configure' -c ' interface enp0s8' -c ' ip address 10.0.0.2/24' -c ' ipv6 address fd00:1::2/64' -c ' no shutdown' -c ' exit' -c ' bfd' -c ' peer 10.0.0.1 local-address 10.0.0.2' -c ' detect-multiplier 3' -c ' receive-interval 300' -c ' transmit-interval 300' -c ' no shutdown' -c ' exit' -c ' peer fd00:1::1 local-address fd00:1::2' -c ' detect-multiplier 3' -c ' receive-interval 300' -c ' transmit-interval 300' -c ' no shutdown' -c ' exit' -c ' exit' -c ' '`
7532026-05-20T16:26:57.214ZMay 20 16:26:57.193 DEBG [sc] ox: starting
7542026-05-20T16:26:57.214ZMay 20 16:26:57.193 DEBG [sc] ox: connecting to [::1]:35507
7552026-05-20T16:26:57.248ZMay 20 16:26:57.194 DEBG [sc] ox waiting for prompt
7562026-05-20T16:26:57.248ZMay 20 16:26:57.204 DEBG [sc] ox: logging in
7572026-05-20T16:26:57.299ZMay 20 16:26:57.281 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
7582026-05-20T16:26:57.784ZMay 20 16:26:57.765 DEBG [sc] ox: starting
7592026-05-20T16:26:57.784ZMay 20 16:26:57.765 DEBG [sc] ox: connecting to [::1]:35507
7602026-05-20T16:26:57.821ZMay 20 16:26:57.766 DEBG [sc] ox waiting for prompt
7612026-05-20T16:26:57.822ZMay 20 16:26:57.777 DEBG [sc] ox: logging in
7622026-05-20T16:26:57.874ZMay 20 16:26:57.854 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7632026-05-20T16:26:57.928ZMay 20 16:26:57.910 DEBG [sc] ox: starting
7642026-05-20T16:26:57.928ZMay 20 16:26:57.910 DEBG [sc] ox: connecting to [::1]:35507
7652026-05-20T16:26:57.960ZMay 20 16:26:57.911 DEBG [sc] ox waiting for prompt
7662026-05-20T16:26:57.960ZMay 20 16:26:57.920 DEBG [sc] ox: logging in
7672026-05-20T16:26:58.015ZMay 20 16:26:57.998 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7682026-05-20T16:26:59.041ZMay 20 16:26:59.023 DEBG [sc] ox: starting
7692026-05-20T16:26:59.041ZMay 20 16:26:59.023 DEBG [sc] ox: connecting to [::1]:35507
7702026-05-20T16:26:59.080ZMay 20 16:26:59.024 DEBG [sc] ox waiting for prompt
7712026-05-20T16:26:59.080ZMay 20 16:26:59.024 DEBG [sc] ox: logging in
7722026-05-20T16:26:59.118ZMay 20 16:26:59.100 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7732026-05-20T16:26:59.508ZMay 20 16:26:59.488 DEBG [sc] ox: starting
7742026-05-20T16:26:59.508ZMay 20 16:26:59.488 DEBG [sc] ox: connecting to [::1]:35507
7752026-05-20T16:26:59.545ZMay 20 16:26:59.489 DEBG [sc] ox waiting for prompt
7762026-05-20T16:26:59.545ZMay 20 16:26:59.500 DEBG [sc] ox: logging in
7772026-05-20T16:26:59.597ZMay 20 16:26:59.577 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
7782026-05-20T16:26:59.652ZMay 20 16:26:59.633 DEBG [sc] ox: starting
7792026-05-20T16:26:59.652ZMay 20 16:26:59.633 DEBG [sc] ox: connecting to [::1]:35507
7802026-05-20T16:26:59.683ZMay 20 16:26:59.634 DEBG [sc] ox waiting for prompt
7812026-05-20T16:26:59.683ZMay 20 16:26:59.644 DEBG [sc] ox: logging in
7822026-05-20T16:26:59.739ZMay 20 16:26:59.721 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
7832026-05-20T16:26:59.794ZMay 20 16:26:59.777 DEBG [sc] ox: starting
7842026-05-20T16:26:59.794ZMay 20 16:26:59.777 DEBG [sc] ox: connecting to [::1]:35507
7852026-05-20T16:26:59.832ZMay 20 16:26:59.778 DEBG [sc] ox waiting for prompt
7862026-05-20T16:26:59.832ZMay 20 16:26:59.787 DEBG [sc] ox: logging in
7872026-05-20T16:26:59.880ZMay 20 16:26:59.865 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.0.1/24 tfportqsfp0_0/v4`
7882026-05-20T16:27:00.442ZMay 20 16:27:00.423 DEBG [sc] ox: starting
7892026-05-20T16:27:00.442ZMay 20 16:27:00.423 DEBG [sc] ox: connecting to [::1]:35507
7902026-05-20T16:27:00.478ZMay 20 16:27:00.424 DEBG [sc] ox waiting for prompt
7912026-05-20T16:27:00.478ZMay 20 16:27:00.433 DEBG [sc] ox: logging in
7922026-05-20T16:27:00.532ZMay 20 16:27:00.511 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v4 -p -o addr`
7932026-05-20T16:27:00.585ZMay 20 16:27:00.566 DEBG [sc] ox: starting
7942026-05-20T16:27:00.585ZMay 20 16:27:00.566 DEBG [sc] ox: connecting to [::1]:35507
7952026-05-20T16:27:00.617ZMay 20 16:27:00.566 DEBG [sc] ox waiting for prompt
7962026-05-20T16:27:00.617ZMay 20 16:27:00.577 DEBG [sc] ox: logging in
7972026-05-20T16:27:00.672ZMay 20 16:27:00.655 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:1::1/64 tfportqsfp0_0/v6`
7982026-05-20T16:27:01.188ZMay 20 16:27:01.169 DEBG [sc] ox: starting
7992026-05-20T16:27:01.188ZMay 20 16:27:01.169 DEBG [sc] ox: connecting to [::1]:35507
8002026-05-20T16:27:01.222ZMay 20 16:27:01.170 DEBG [sc] ox waiting for prompt
8012026-05-20T16:27:01.223ZMay 20 16:27:01.180 DEBG [sc] ox: logging in
8022026-05-20T16:27:01.277ZMay 20 16:27:01.256 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v6 -p -o addr`
8032026-05-20T16:27:01.330ZMay 20 16:27:01.312 DEBG [sc] ox: starting
8042026-05-20T16:27:01.330ZMay 20 16:27:01.312 DEBG [sc] ox: connecting to [::1]:35507
8052026-05-20T16:27:01.366ZMay 20 16:27:01.313 DEBG [sc] ox waiting for prompt
8062026-05-20T16:27:01.366ZMay 20 16:27:01.323 DEBG [sc] ox: logging in
8072026-05-20T16:27:01.418ZMay 20 16:27:01.400 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
8082026-05-20T16:27:01.475ZMay 20 16:27:01.455 DEBG [sc] ox: starting
8092026-05-20T16:27:01.475ZMay 20 16:27:01.455 DEBG [sc] ox: connecting to [::1]:35507
8102026-05-20T16:27:01.507ZMay 20 16:27:01.456 DEBG [sc] ox waiting for prompt
8112026-05-20T16:27:01.507ZMay 20 16:27:01.466 DEBG [sc] ox: logging in
8122026-05-20T16:27:01.563ZMay 20 16:27:01.544 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
8132026-05-20T16:27:01.632ZMay 20 16:27:01.609 DEBG [sc] ox: starting
8142026-05-20T16:27:01.632ZMay 20 16:27:01.609 DEBG [sc] ox: connecting to [::1]:35507
8152026-05-20T16:27:01.669ZMay 20 16:27:01.610 DEBG [sc] ox waiting for prompt
8162026-05-20T16:27:01.669ZMay 20 16:27:01.621 DEBG [sc] ox: logging in
8172026-05-20T16:27:01.716ZMay 20 16:27:01.698 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.1.1/24 tfportqsfp1_0/v4`
8182026-05-20T16:27:02.215ZMay 20 16:27:02.191 DEBG [sc] ox: starting
8192026-05-20T16:27:02.215ZMay 20 16:27:02.191 DEBG [sc] ox: connecting to [::1]:35507
8202026-05-20T16:27:02.246ZMay 20 16:27:02.192 DEBG [sc] ox waiting for prompt
8212026-05-20T16:27:02.246ZMay 20 16:27:02.202 DEBG [sc] ox: logging in
8222026-05-20T16:27:02.298ZMay 20 16:27:02.278 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v4 -p -o addr`
8232026-05-20T16:27:02.354ZMay 20 16:27:02.334 DEBG [sc] ox: starting
8242026-05-20T16:27:02.354ZMay 20 16:27:02.334 DEBG [sc] ox: connecting to [::1]:35507
8252026-05-20T16:27:02.391ZMay 20 16:27:02.335 DEBG [sc] ox waiting for prompt
8262026-05-20T16:27:02.391ZMay 20 16:27:02.345 DEBG [sc] ox: logging in
8272026-05-20T16:27:02.439ZMay 20 16:27:02.421 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:2::1/64 tfportqsfp1_0/v6`
8282026-05-20T16:27:02.956ZMay 20 16:27:02.935 DEBG [sc] ox: starting
8292026-05-20T16:27:02.956ZMay 20 16:27:02.935 DEBG [sc] ox: connecting to [::1]:35507
8302026-05-20T16:27:02.990ZMay 20 16:27:02.936 DEBG [sc] ox waiting for prompt
8312026-05-20T16:27:02.990ZMay 20 16:27:02.945 DEBG [sc] ox: logging in
8322026-05-20T16:27:03.045ZMay 20 16:27:03.023 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v6 -p -o addr`
8332026-05-20T16:27:03.099ZMay 20 16:27:03.078 DEBG [sc] ox: starting
8342026-05-20T16:27:03.100ZMay 20 16:27:03.078 DEBG [sc] ox: connecting to [::1]:35507
8352026-05-20T16:27:03.135ZMay 20 16:27:03.079 DEBG [sc] ox waiting for prompt
8362026-05-20T16:27:03.135ZMay 20 16:27:03.089 DEBG [sc] ox: logging in
8372026-05-20T16:27:03.186ZMay 20 16:27:03.166 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
8382026-05-20T16:27:03.239ZMay 20 16:27:03.221 DEBG [sc] ox: starting
8392026-05-20T16:27:03.239ZMay 20 16:27:03.221 DEBG [sc] ox: connecting to [::1]:35507
8402026-05-20T16:27:03.276ZMay 20 16:27:03.222 DEBG [sc] ox waiting for prompt
8412026-05-20T16:27:03.276ZMay 20 16:27:03.232 DEBG [sc] ox: logging in
8422026-05-20T16:27:03.332ZMay 20 16:27:03.309 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
8432026-05-20T16:27:03.389ZMay 20 16:27:03.368 INFO installing static v4 route 192.168.100.0/24
8442026-05-20T16:27:03.423ZMay 20 16:27:03.369 INFO installing static v6 route fd01::/64
8452026-05-20T16:27:03.423ZMay 20 16:27:03.370 INFO adding BFD peers for cr1 and cr2 (dual-stack)
8462026-05-20T16:27:03.423ZMay 20 16:27:03.372 INFO phase 1: both peers up
8472026-05-20T16:27:04.400ZMay 20 16:27:04.376 INFO cr1: executing frr script show bfd peers json
8482026-05-20T16:27:04.400ZMay 20 16:27:04.377 DEBG [sc] cr1: starting
8492026-05-20T16:27:04.400ZMay 20 16:27:04.377 DEBG [sc] cr1: connecting to [::1]:63431
8502026-05-20T16:27:04.439ZMay 20 16:27:04.377 DEBG [sc] cr1 waiting for prompt
8512026-05-20T16:27:04.439ZMay 20 16:27:04.389 DEBG [sc] cr1: logging in
8522026-05-20T16:27:04.763ZMay 20 16:27:04.744 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8532026-05-20T16:27:06.887ZMay 20 16:27:06.874 INFO cr1: executing frr script show bfd peers json
8542026-05-20T16:27:06.887ZMay 20 16:27:06.874 DEBG [sc] cr1: starting
8552026-05-20T16:27:06.887ZMay 20 16:27:06.874 DEBG [sc] cr1: connecting to [::1]:63431
8562026-05-20T16:27:06.940ZMay 20 16:27:06.875 DEBG [sc] cr1 waiting for prompt
8572026-05-20T16:27:06.940ZMay 20 16:27:06.886 DEBG [sc] cr1: logging in
8582026-05-20T16:27:07.046ZMay 20 16:27:07.030 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8592026-05-20T16:27:09.208ZMay 20 16:27:09.189 INFO cr2: executing eos script show bfd peers | json
8602026-05-20T16:27:09.208ZMay 20 16:27:09.189 DEBG [sc] cr2: starting
8612026-05-20T16:27:09.208ZMay 20 16:27:09.189 DEBG [sc] cr2: connecting to [::1]:35648
8622026-05-20T16:27:09.245ZMay 20 16:27:09.190 DEBG [sc] cr2 waiting for prompt
8632026-05-20T16:27:09.245ZMay 20 16:27:09.200 DEBG [sc] cr2: logging in
8642026-05-20T16:27:09.560ZMay 20 16:27:09.539 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8652026-05-20T16:27:11.970ZMay 20 16:27:11.952 INFO cr2: executing eos script show bfd peers | json
8662026-05-20T16:27:11.970ZMay 20 16:27:11.952 DEBG [sc] cr2: starting
8672026-05-20T16:27:12.008ZMay 20 16:27:11.953 DEBG [sc] cr2: connecting to [::1]:35648
8682026-05-20T16:27:12.008ZMay 20 16:27:11.953 DEBG [sc] cr2 waiting for prompt
8692026-05-20T16:27:12.008ZMay 20 16:27:11.964 DEBG [sc] cr2: logging in
8702026-05-20T16:27:12.106ZMay 20 16:27:12.086 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8712026-05-20T16:27:14.501ZMay 20 16:27:14.478 INFO phase 2: pause bfdd on cr1
8722026-05-20T16:27:14.501ZMay 20 16:27:14.478 INFO cr1: pausing frr bfdd
8732026-05-20T16:27:14.501ZMay 20 16:27:14.478 DEBG [sc] cr1: starting
8742026-05-20T16:27:14.501ZMay 20 16:27:14.478 DEBG [sc] cr1: connecting to [::1]:63431
8752026-05-20T16:27:14.536ZMay 20 16:27:14.479 DEBG [sc] cr1 waiting for prompt
8762026-05-20T16:27:14.536ZMay 20 16:27:14.490 DEBG [sc] cr1: logging in
8772026-05-20T16:27:14.665ZMay 20 16:27:14.645 DEBG [sc] cr1: executing command `pkill -STOP bfdd`
8782026-05-20T16:27:16.753ZMay 20 16:27:16.732 INFO cr2: executing eos script show bfd peers | json
8792026-05-20T16:27:16.753ZMay 20 16:27:16.732 DEBG [sc] cr2: starting
8802026-05-20T16:27:16.753ZMay 20 16:27:16.732 DEBG [sc] cr2: connecting to [::1]:35648
8812026-05-20T16:27:16.791ZMay 20 16:27:16.733 DEBG [sc] cr2 waiting for prompt
8822026-05-20T16:27:16.792ZMay 20 16:27:16.744 DEBG [sc] cr2: logging in
8832026-05-20T16:27:16.900ZMay 20 16:27:16.877 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8842026-05-20T16:27:19.222ZMay 20 16:27:19.200 INFO cr2: executing eos script show bfd peers | json
8852026-05-20T16:27:19.222ZMay 20 16:27:19.200 DEBG [sc] cr2: starting
8862026-05-20T16:27:19.222ZMay 20 16:27:19.200 DEBG [sc] cr2: connecting to [::1]:35648
8872026-05-20T16:27:19.256ZMay 20 16:27:19.201 DEBG [sc] cr2 waiting for prompt
8882026-05-20T16:27:19.256ZMay 20 16:27:19.211 DEBG [sc] cr2: logging in
8892026-05-20T16:27:19.386ZMay 20 16:27:19.366 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8902026-05-20T16:27:21.788ZMay 20 16:27:21.770 INFO phase 3: pause ceos on cr2
8912026-05-20T16:27:21.788ZMay 20 16:27:21.770 INFO cr2: pausing ceos
8922026-05-20T16:27:21.788ZMay 20 16:27:21.770 DEBG [sc] cr2: starting
8932026-05-20T16:27:21.788ZMay 20 16:27:21.770 DEBG [sc] cr2: connecting to [::1]:35648
8942026-05-20T16:27:21.819ZMay 20 16:27:21.770 DEBG [sc] cr2 waiting for prompt
8952026-05-20T16:27:21.819ZMay 20 16:27:21.780 DEBG [sc] cr2: logging in
8962026-05-20T16:27:21.941ZMay 20 16:27:21.924 DEBG [sc] cr2: executing command `docker pause ceos`
8972026-05-20T16:27:24.049ZMay 20 16:27:24.031 INFO phase 4: resume bfdd on cr1
8982026-05-20T16:27:24.049ZMay 20 16:27:24.031 INFO cr1: resuming frr bfdd
8992026-05-20T16:27:24.049ZMay 20 16:27:24.031 DEBG [sc] cr1: starting
9002026-05-20T16:27:24.049ZMay 20 16:27:24.031 DEBG [sc] cr1: connecting to [::1]:63431
9012026-05-20T16:27:24.082ZMay 20 16:27:24.031 DEBG [sc] cr1 waiting for prompt
9022026-05-20T16:27:24.083ZMay 20 16:27:24.043 DEBG [sc] cr1: logging in
9032026-05-20T16:27:24.192ZMay 20 16:27:24.175 DEBG [sc] cr1: executing command `pkill -CONT bfdd`
9042026-05-20T16:27:26.299ZMay 20 16:27:26.281 INFO cr1: executing frr script show bfd peers json
9052026-05-20T16:27:26.299ZMay 20 16:27:26.281 DEBG [sc] cr1: starting
9062026-05-20T16:27:26.299ZMay 20 16:27:26.281 DEBG [sc] cr1: connecting to [::1]:63431
9072026-05-20T16:27:26.338ZMay 20 16:27:26.281 DEBG [sc] cr1 waiting for prompt
9082026-05-20T16:27:26.338ZMay 20 16:27:26.289 DEBG [sc] cr1: logging in
9092026-05-20T16:27:26.452ZMay 20 16:27:26.432 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9102026-05-20T16:27:28.582ZMay 20 16:27:28.565 INFO cr1: executing frr script show bfd peers json
9112026-05-20T16:27:28.582ZMay 20 16:27:28.565 DEBG [sc] cr1: starting
9122026-05-20T16:27:28.582ZMay 20 16:27:28.565 DEBG [sc] cr1: connecting to [::1]:63431
9132026-05-20T16:27:28.615ZMay 20 16:27:28.565 DEBG [sc] cr1 waiting for prompt
9142026-05-20T16:27:28.615ZMay 20 16:27:28.576 DEBG [sc] cr1: logging in
9152026-05-20T16:27:28.720ZMay 20 16:27:28.698 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9162026-05-20T16:27:30.857ZMay 20 16:27:30.838 INFO phase 5: unpause ceos on cr2
9172026-05-20T16:27:30.857ZMay 20 16:27:30.838 INFO cr2: unpausing ceos
9182026-05-20T16:27:30.857ZMay 20 16:27:30.838 DEBG [sc] cr2: starting
9192026-05-20T16:27:30.857ZMay 20 16:27:30.838 DEBG [sc] cr2: connecting to [::1]:35648
9202026-05-20T16:27:30.890ZMay 20 16:27:30.839 DEBG [sc] cr2 waiting for prompt
9212026-05-20T16:27:30.890ZMay 20 16:27:30.850 DEBG [sc] cr2: logging in
9222026-05-20T16:27:31.014ZMay 20 16:27:30.993 DEBG [sc] cr2: executing command `docker unpause ceos`
9232026-05-20T16:27:33.121ZMay 20 16:27:33.102 INFO cr1: executing frr script show bfd peers json
9242026-05-20T16:27:33.121ZMay 20 16:27:33.103 DEBG [sc] cr1: starting
9252026-05-20T16:27:33.121ZMay 20 16:27:33.103 DEBG [sc] cr1: connecting to [::1]:63431
9262026-05-20T16:27:33.152ZMay 20 16:27:33.103 DEBG [sc] cr1 waiting for prompt
9272026-05-20T16:27:33.152ZMay 20 16:27:33.114 DEBG [sc] cr1: logging in
9282026-05-20T16:27:33.298ZMay 20 16:27:33.279 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9292026-05-20T16:27:35.441ZMay 20 16:27:35.418 INFO cr1: executing frr script show bfd peers json
9302026-05-20T16:27:35.441ZMay 20 16:27:35.418 DEBG [sc] cr1: starting
9312026-05-20T16:27:35.441ZMay 20 16:27:35.418 DEBG [sc] cr1: connecting to [::1]:63431
9322026-05-20T16:27:35.471ZMay 20 16:27:35.419 DEBG [sc] cr1 waiting for prompt
9332026-05-20T16:27:35.471ZMay 20 16:27:35.429 DEBG [sc] cr1: logging in
9342026-05-20T16:27:35.601ZMay 20 16:27:35.583 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9352026-05-20T16:27:37.740ZMay 20 16:27:37.720 INFO cr2: executing eos script show bfd peers | json
9362026-05-20T16:27:37.740ZMay 20 16:27:37.720 DEBG [sc] cr2: starting
9372026-05-20T16:27:37.740ZMay 20 16:27:37.720 DEBG [sc] cr2: connecting to [::1]:35648
9382026-05-20T16:27:37.775ZMay 20 16:27:37.721 DEBG [sc] cr2 waiting for prompt
9392026-05-20T16:27:37.775ZMay 20 16:27:37.732 DEBG [sc] cr2: logging in
9402026-05-20T16:27:37.893ZMay 20 16:27:37.875 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9412026-05-20T16:27:40.247ZMay 20 16:27:40.224 INFO cr2: executing eos script show bfd peers | json
9422026-05-20T16:27:40.247ZMay 20 16:27:40.224 DEBG [sc] cr2: starting
9432026-05-20T16:27:40.247ZMay 20 16:27:40.225 DEBG [sc] cr2: connecting to [::1]:35648
9442026-05-20T16:27:40.289ZMay 20 16:27:40.225 DEBG [sc] cr2 waiting for prompt
9452026-05-20T16:27:40.289ZMay 20 16:27:40.236 DEBG [sc] cr2: logging in
9462026-05-20T16:27:40.400ZMay 20 16:27:40.380 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9472026-05-20T16:27:42.750ZMay 20 16:27:42.730 INFO trio bfd static routing test passed 🎉
9482026-05-20T16:27:42.750ZMay 20 16:27:42.730 INFO destroying runner for deployment mgtriobfd
9492026-05-20T16:27:42.750ZMay 20 16:27:42.730 INFO destroying deployment mgtriobfd
9502026-05-20T16:27:42.750ZMay 20 16:27:42.730 INFO destroying nodes
9512026-05-20T16:27:42.849ZMay 20 16:27:42.828 INFO destroying links
9522026-05-20T16:27:42.850ZMay 20 16:27:42.828 INFO destroying link mgtriobfd_ox_sn_vnic0
9532026-05-20T16:27:42.885ZMay 20 16:27:42.830 INFO destroying link mgtriobfd_ox_sn_sim0
9542026-05-20T16:27:42.885ZMay 20 16:27:42.831 INFO destroying link mgtriobfd_cr1_vn_vnic0
9552026-05-20T16:27:43.851ZMay 20 16:27:43.833 INFO destroying link mgtriobfd_cr1_vn_sim0
9562026-05-20T16:27:43.884ZMay 20 16:27:43.834 INFO destroying link mgtriobfd_ox_sn_vnic1
9572026-05-20T16:27:43.884ZMay 20 16:27:43.835 INFO destroying link mgtriobfd_ox_sn_sim1
9582026-05-20T16:27:43.884ZMay 20 16:27:43.836 INFO destroying link mgtriobfd_cr2_vn_vnic0
9592026-05-20T16:27:43.884ZMay 20 16:27:43.837 INFO destroying link mgtriobfd_cr2_vn_sim0
9602026-05-20T16:27:43.884ZMay 20 16:27:43.838 INFO destroying external links
9612026-05-20T16:27:43.884ZMay 20 16:27:43.838 INFO destroying external link mgtriobfd_ox_vn_vnic2
9622026-05-20T16:27:43.884ZMay 20 16:27:43.839 INFO destroying external link mgtriobfd_cr1_vn_vnic1
9632026-05-20T16:27:43.884ZMay 20 16:27:43.841 INFO destroying external link mgtriobfd_cr2_vn_vnic1
9642026-05-20T16:27:43.884ZMay 20 16:27:43.842 INFO destroying images
9652026-05-20T16:27:44.370ZMay 20 16:27:44.353 INFO destroying workspace at .falcon
9662026-05-20T16:27:44.402Zprocess exited: duration 784371 ms, exit code 0
 
9672026-05-20T16:27:44.470Zfound 0 output files