01KS3XRWXHDX9M2Z9Q3JBWSQV9: falcon

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

Buildomat Job: 01KS3XSFETV3M9XGYCCZHF7CYH

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-05-21T00:21:58.223Zjob dependencies complete; ready to run (waiting for 13 m 28 s)
22026-05-21T00:35:21.580Zjob assigned to worker 01KS3Z4T37CQ16YVC75A7MJDV7 [factory edgar, gimlet/BRM42220060/592] (queued for 13 m 23 s)
32026-05-21T00:35:22.710Zdownloading input: /input/build/work/debug/ddmadm
42026-05-21T00:35:53.515Zdownloaded input: /input/build/work/debug/ddmadm
52026-05-21T00:35:53.515Zdownloading input: /input/build/work/debug/ddmd
62026-05-21T00:36:29.686Zdownloaded input: /input/build/work/debug/ddmd
72026-05-21T00:36:29.686Zdownloading input: /input/build/work/debug/mgadm
82026-05-21T00:37:05.146Zdownloaded input: /input/build/work/debug/mgadm
92026-05-21T00:37:05.146Zdownloading input: /input/build/work/debug/mgd
102026-05-21T00:37:46.412Zdownloaded input: /input/build/work/debug/mgd
112026-05-21T00:37:46.450Zdownloading input: /input/build/work/release/ddmadm
122026-05-21T00:37:49.938Zdownloaded input: /input/build/work/release/ddmadm
132026-05-21T00:37:49.938Zdownloading input: /input/build/work/release/ddmd
142026-05-21T00:37:53.237Zdownloaded input: /input/build/work/release/ddmd
152026-05-21T00:37:53.237Zdownloading input: /input/build/work/release/falcon-lab
162026-05-21T00:37:57.631Zdownloaded input: /input/build/work/release/falcon-lab
172026-05-21T00:37:57.631Zdownloading input: /input/build/work/release/mgadm
182026-05-21T00:38:01.170Zdownloaded input: /input/build/work/release/mgadm
192026-05-21T00:38:01.170Zdownloading input: /input/build/work/release/mgd
202026-05-21T00:38:05.695Zdownloaded input: /input/build/work/release/mgd
212026-05-21T00:38:05.731Zdownloading input: /input/build-interop/work/testbed.tar.gz
222026-05-21T00:38:18.884Zdownloaded input: /input/build-interop/work/testbed.tar.gz
232026-05-21T00:38:18.919Zdownloading input: /input/build-interop/work/dhcp-server
242026-05-21T00:38:22.252Zdownloaded input: /input/build-interop/work/dhcp-server
 
252026-05-21T00:38:22.252Zstarting task 0: "setup"
262026-05-21T00:38:22.288Z++ uname -s
272026-05-21T00:38:22.288Z+ kern=SunOS
282026-05-21T00:38:22.288Z+ build_user=build
292026-05-21T00:38:22.288Z+ build_uid=12345
302026-05-21T00:38:22.288Z+ work_dir=/work
312026-05-21T00:38:22.288Z+ input_dir=/input
322026-05-21T00:38:22.288Z+ [[ 0 == 12345 ]]
332026-05-21T00:38:22.288Z+ case "$kern" in
342026-05-21T00:38:22.288Z+ groupadd -g 12345 build
352026-05-21T00:38:22.288Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-05-21T00:38:24.296Z+ zfs create -o mountpoint=/work rpool/work
372026-05-21T00:38:24.582Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-05-21T00:38:24.618Z+ home_fs=
392026-05-21T00:38:24.618Z+ [[ '' == autofs ]]
402026-05-21T00:38:24.618Z+ mkdir -p /home/build
412026-05-21T00:38:24.618Z+ chown build:build /home/build /work
422026-05-21T00:38:26.596Z+ chmod 0700 /home/build /work
432026-05-21T00:38:26.632Zprocess exited: duration 4345 ms, exit code 0
 
442026-05-21T00:38:26.706Zstarting task 1: "authentication"
452026-05-21T00:38:26.807Zprocess exited: duration 107 ms, exit code 0
 
462026-05-21T00:38:26.883Zstarting task 2: "build"
472026-05-21T00:38:26.922Z+ set -e
482026-05-21T00:38:26.922Z+ banner zpool
492026-05-21T00:38:26.922Z
502026-05-21T00:38:26.922Z ###### ##### #### #### #
512026-05-21T00:38:26.922Z # # # # # # # #
522026-05-21T00:38:26.922Z # # # # # # # #
532026-05-21T00:38:26.922Z # ##### # # # # #
542026-05-21T00:38:26.922Z # # # # # # #
552026-05-21T00:38:26.922Z ###### # #### #### ######
562026-05-21T00:38:26.922Z
572026-05-21T00:38:26.922Z++ pfexec diskinfo -pH
582026-05-21T00:38:26.922Z++ sort -k8 -n -r
592026-05-21T00:38:26.922Z++ head -1
602026-05-21T00:38:26.922Z++ awk '{print $2}'
612026-05-21T00:38:26.960Z+ DISK=c9t0014EE81000BC57Cd0
622026-05-21T00:38:26.960Z+ export DISK
632026-05-21T00:38:26.960Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC57Cd0
642026-05-21T00:38:27.022Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-05-21T00:38:27.058Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-05-21T00:38:27.221Z+ [[ true =~ true ]]
672026-05-21T00:38:27.221Z+ pfexec zpool trim cpool
682026-05-21T00:38:27.259Z++ zpool status -t cpool
692026-05-21T00:38:27.259Z+ [[ ! pool: cpool
702026-05-21T00:38:27.259Z state: ONLINE
712026-05-21T00:38:27.259Z scan: none requested
722026-05-21T00:38:27.259Zconfig:
732026-05-21T00:38:27.259Z
742026-05-21T00:38:27.259Z NAME STATE READ WRITE CKSUM
752026-05-21T00:38:27.259Z cpool ONLINE 0 0 0
762026-05-21T00:38:27.259Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (1% trimmed, started at May 21, 2026 at 12:38:27 AM UTC)
772026-05-21T00:38:27.259Z
782026-05-21T00:38:27.259Zerrors: No known data errors =~ 100% ]]
792026-05-21T00:38:27.259Z+ sleep 10
802026-05-21T00:38:37.323Z++ zpool status -t cpool
812026-05-21T00:38:37.395Z+ [[ ! pool: cpool
822026-05-21T00:38:37.395Z state: ONLINE
832026-05-21T00:38:37.395Z scan: none requested
842026-05-21T00:38:37.395Zconfig:
852026-05-21T00:38:37.395Z
862026-05-21T00:38:37.395Z NAME STATE READ WRITE CKSUM
872026-05-21T00:38:37.395Z cpool ONLINE 0 0 0
882026-05-21T00:38:37.395Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (68% trimmed, started at May 21, 2026 at 12:38:27 AM UTC)
892026-05-21T00:38:37.395Z
902026-05-21T00:38:37.395Zerrors: No known data errors =~ 100% ]]
912026-05-21T00:38:37.395Z+ sleep 10
922026-05-21T00:38:47.272Z++ zpool status -t cpool
932026-05-21T00:38:47.335Z+ [[ ! pool: cpool
942026-05-21T00:38:47.335Z state: ONLINE
952026-05-21T00:38:47.335Z scan: none requested
962026-05-21T00:38:47.335Zconfig:
972026-05-21T00:38:47.335Z
982026-05-21T00:38:47.335Z NAME STATE READ WRITE CKSUM
992026-05-21T00:38:47.335Z cpool ONLINE 0 0 0
1002026-05-21T00:38:47.335Z c9t0014EE81000BC57Cd0 ONLINE 0 0 0 (100% trimmed, completed at May 21, 2026 at 12:38:41 AM UTC)
1012026-05-21T00:38:47.335Z
1022026-05-21T00:38:47.335Zerrors: No known data errors =~ 100% ]]
1032026-05-21T00:38:47.335Z+ pfexec chown 12345 /ci
1042026-05-21T00:38:47.335Z+ cd /ci
1052026-05-21T00:38:47.335Z+ export FALCON_DATASET=cpool/falcon
1062026-05-21T00:38:47.335Z+ FALCON_DATASET=cpool/falcon
1072026-05-21T00:38:47.335Z+ banner setup
1082026-05-21T00:38:47.335Z
1092026-05-21T00:38:47.335Z #### ###### ##### # # #####
1102026-05-21T00:38:47.335Z # # # # # # #
1112026-05-21T00:38:47.335Z #### ##### # # # # #
1122026-05-21T00:38:47.335Z # # # # # #####
1132026-05-21T00:38:47.335Z # # # # # # #
1142026-05-21T00:38:47.335Z #### ###### # #### #
1152026-05-21T00:38:47.335Z
1162026-05-21T00:38:47.335Z+ cp /input/build-interop/work/dhcp-server .
1172026-05-21T00:38:47.380Z+ cp /input/build/work/release/falcon-lab .
1182026-05-21T00:38:47.422Z+ cp /input/build/work/release/mgd .
1192026-05-21T00:38:47.486Z+ cp /input/build/work/release/ddmd .
1202026-05-21T00:38:47.563Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-05-21T00:38:47.600Z+ mkdir -p cargo-bay
1222026-05-21T00:38:47.600Z+ mv mgd cargo-bay/
1232026-05-21T00:38:47.600Z+ mv ddmd cargo-bay/
1242026-05-21T00:38:47.600Z+ export EXT_INTERFACE=igb0
1252026-05-21T00:38:47.600Z+ EXT_INTERFACE=igb0
1262026-05-21T00:38:47.600Z++ bmat address ls -f extra -Ho first
1272026-05-21T00:38:47.635Z+ first=10.151.7.164
1282026-05-21T00:38:47.635Z++ bmat address ls -f extra -Ho last
1292026-05-21T00:38:47.635Z+ last=10.151.7.227
1302026-05-21T00:38:47.635Z++ bmat address ls -f extra -Ho gateway
1312026-05-21T00:38:47.721Z+ gw=10.151.7.1
1322026-05-21T00:38:47.721Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-05-21T00:38:47.721Z++ sed 's#/.*##g'
1342026-05-21T00:38:47.721Z+ server=10.151.7.100
1352026-05-21T00:38:47.721Z+ RUST_LOG=debug
1362026-05-21T00:38:47.721Z+ pfexec ./falcon-lab run trio-unnumbered
1372026-05-21T00:38:47.721Z+ pfexec ./dhcp-server 10.151.7.164 10.151.7.227 10.151.7.1 10.151.7.100
1382026-05-21T00:38:47.759ZMay 21 00:38:47.673 DEBG using default route interface igb0
1392026-05-21T00:38:47.759ZMay 21 00:38:47.674 DEBG using default route interface igb0
1402026-05-21T00:38:47.759ZMay 21 00:38:47.674 DEBG using default route interface igb0
1412026-05-21T00:38:47.759ZMay 21 00:38:47.674 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1422026-05-21T00:38:47.759ZMay 21 00:38:47.674 INFO starting preflight for deployment mgtriou
1432026-05-21T00:38:47.759ZMay 21 00:38:47.674 INFO propolis-server binary not found
1442026-05-21T00:38:47.759ZMay 21 00:38:47.674 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1452026-05-21T00:38:52.774ZMay 21 00:38:52.756 INFO ovmf fd not found
1462026-05-21T00:38:52.774ZMay 21 00:38:52.756 INFO downloading ovmf
1472026-05-21T00:38:53.306ZMay 21 00:38:53.217 INFO base image for helios-2.9 does not exist, attempting to install
1482026-05-21T00:38:53.306ZMay 21 00:38:53.217 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1492026-05-21T00:39:29.259ZMay 21 00:39:29.236 INFO extracting image to /tmp/helios-2.9_0.raw
1502026-05-21T00:40:02.816ZMay 21 00:40:02.796 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1512026-05-21T00:40:02.869ZMay 21 00:40:02.850 INFO copying image data to zvol
1522026-05-21T00:40:13.176ZMay 21 00:40:13.158 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1532026-05-21T00:40:16.432ZMay 21 00:40:16.418 INFO base image for debian-13.2 does not exist, attempting to install
1542026-05-21T00:40:16.432ZMay 21 00:40:16.418 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1552026-05-21T00:40:46.922ZMay 21 00:40:46.901 INFO extracting image to /tmp/debian-13.2_0.raw
1562026-05-21T00:41:07.745ZMay 21 00:41:07.729 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1572026-05-21T00:41:07.779ZMay 21 00:41:07.755 INFO copying image data to zvol
1582026-05-21T00:41:13.963ZMay 21 00:41:13.948 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1592026-05-21T00:41:17.325ZMay 21 00:41:17.315 INFO base image for eos-4.35 does not exist, attempting to install
1602026-05-21T00:41:17.325ZMay 21 00:41:17.315 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1612026-05-21T00:42:23.488ZMay 21 00:42:23.467 INFO extracting image to /tmp/eos-4.35_0.raw
1622026-05-21T00:43:46.585ZMay 21 00:43:46.570 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1632026-05-21T00:43:46.621ZMay 21 00:43:46.596 INFO copying image data to zvol
1642026-05-21T00:44:34.919ZMay 21 00:44:34.901 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1652026-05-21T00:44:38.258ZMay 21 00:44:38.241 INFO creating links
1662026-05-21T00:44:38.258ZMay 21 00:44:38.241 DEBG destroying link mgtriou_ox_sn_vnic0
1672026-05-21T00:44:38.298ZMay 21 00:44:38.242 DEBG destroying link mgtriou_ox_sn_sim0
1682026-05-21T00:44:38.298ZMay 21 00:44:38.242 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1692026-05-21T00:44:38.298ZMay 21 00:44:38.244 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1702026-05-21T00:44:38.298ZMay 21 00:44:38.252 DEBG link pair created
1712026-05-21T00:44:38.298ZMay 21 00:44:38.252 DEBG destroying link mgtriou_cr1_vn_vnic0
1722026-05-21T00:44:38.298ZMay 21 00:44:38.252 DEBG destroying link mgtriou_cr1_vn_sim0
1732026-05-21T00:44:38.298ZMay 21 00:44:38.252 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1742026-05-21T00:44:38.299ZMay 21 00:44:38.253 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1752026-05-21T00:44:38.299ZMay 21 00:44:38.260 DEBG link pair created
1762026-05-21T00:44:38.299ZMay 21 00:44:38.260 DEBG destroying link mgtriou_ox_sn_vnic1
1772026-05-21T00:44:38.299ZMay 21 00:44:38.260 DEBG destroying link mgtriou_ox_sn_sim1
1782026-05-21T00:44:38.299ZMay 21 00:44:38.260 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1792026-05-21T00:44:38.299ZMay 21 00:44:38.261 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1802026-05-21T00:44:38.299ZMay 21 00:44:38.268 DEBG link pair created
1812026-05-21T00:44:38.299ZMay 21 00:44:38.268 DEBG destroying link mgtriou_cr2_vn_vnic0
1822026-05-21T00:44:38.299ZMay 21 00:44:38.268 DEBG destroying link mgtriou_cr2_vn_sim0
1832026-05-21T00:44:38.299ZMay 21 00:44:38.268 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1842026-05-21T00:44:38.299ZMay 21 00:44:38.269 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1852026-05-21T00:44:38.299ZMay 21 00:44:38.276 DEBG link pair created
1862026-05-21T00:44:38.299ZMay 21 00:44:38.276 INFO creating external links
1872026-05-21T00:44:38.299ZMay 21 00:44:38.276 DEBG destroying external link mgtriou_ox_vn_vnic2
1882026-05-21T00:44:38.299ZMay 21 00:44:38.276 INFO creating external link mgtriou_ox_vn_vnic2
1892026-05-21T00:44:38.299ZMay 21 00:44:38.278 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1902026-05-21T00:44:38.299ZMay 21 00:44:38.278 DEBG destroying external link mgtriou_cr1_vn_vnic1
1912026-05-21T00:44:38.299ZMay 21 00:44:38.278 INFO creating external link mgtriou_cr1_vn_vnic1
1922026-05-21T00:44:38.299ZMay 21 00:44:38.279 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1932026-05-21T00:44:38.299ZMay 21 00:44:38.279 DEBG destroying external link mgtriou_cr2_vn_vnic1
1942026-05-21T00:44:38.299ZMay 21 00:44:38.279 INFO creating external link mgtriou_cr2_vn_vnic1
1952026-05-21T00:44:38.335ZMay 21 00:44:38.281 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1962026-05-21T00:44:38.335ZMay 21 00:44:38.281 INFO creating nodes
1972026-05-21T00:44:38.335ZMay 21 00:44:38.281 INFO ox: launching node
1982026-05-21T00:44:38.335ZMay 21 00:44:38.283 INFO cr1: launching node
1992026-05-21T00:44:38.335ZMay 21 00:44:38.285 INFO cr2: launching node
2002026-05-21T00:44:38.335ZMay 21 00:44:38.299 INFO launched instance ox with pid 840 on port 37344
2012026-05-21T00:44:38.335ZMay 21 00:44:38.299 INFO ox: instance ensure
2022026-05-21T00:44:38.335ZMay 21 00:44:38.299 INFO launched instance cr1 with pid 841 on port 45916
2032026-05-21T00:44:38.335ZMay 21 00:44:38.300 INFO cr1: instance ensure
2042026-05-21T00:44:38.335ZMay 21 00:44:38.300 INFO launched instance cr2 with pid 842 on port 58115
2052026-05-21T00:44:38.335ZMay 21 00:44:38.300 INFO cr2: instance ensure
2062026-05-21T00:44:40.677ZMay 21 00:44:40.663 INFO cr1: instance ensure completed after 0 retries
2072026-05-21T00:44:40.677ZMay 21 00:44:40.663 INFO cr1: instance run
2082026-05-21T00:44:40.712ZMay 21 00:44:40.664 DEBG [sc] cr1: starting
2092026-05-21T00:44:40.712ZMay 21 00:44:40.664 DEBG [sc] cr1: connecting to [::1]:45916
2102026-05-21T00:44:40.712ZMay 21 00:44:40.665 DEBG [sc] cr1 waiting for prompt
2112026-05-21T00:44:40.712ZMay 21 00:44:40.678 INFO cr2: instance ensure completed after 0 retries
2122026-05-21T00:44:40.712ZMay 21 00:44:40.678 INFO cr2: instance run
2132026-05-21T00:44:40.712ZMay 21 00:44:40.679 DEBG [sc] cr2: starting
2142026-05-21T00:44:40.712ZMay 21 00:44:40.679 DEBG [sc] cr2: connecting to [::1]:58115
2152026-05-21T00:44:40.712ZMay 21 00:44:40.680 DEBG [sc] cr2 waiting for prompt
2162026-05-21T00:44:40.712ZMay 21 00:44:40.691 INFO ox: instance ensure completed after 0 retries
2172026-05-21T00:44:40.712ZMay 21 00:44:40.691 INFO ox: instance run
2182026-05-21T00:44:40.712ZMay 21 00:44:40.692 DEBG [sc] ox: starting
2192026-05-21T00:44:40.712ZMay 21 00:44:40.692 DEBG [sc] ox: connecting to [::1]:37344
2202026-05-21T00:44:40.712ZMay 21 00:44:40.693 DEBG [sc] ox waiting for prompt
2212026-05-21T00:44:57.749ZMay 21 00:44:57.732 DEBG [sc] cr1: logging in
2222026-05-21T00:44:58.151ZMay 21 00:44:58.137 INFO cr1: mounting /opt/cargo-bay
2232026-05-21T00:44:58.151ZMay 21 00:44:58.137 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2242026-05-21T00:44:58.189ZMay 21 00:44:58.159 DEBG [sc] cr1: executing command `cd`
2252026-05-21T00:44:58.189ZMay 21 00:44:58.171 INFO cr1: finished mounting /opt/cargo-bay
2262026-05-21T00:44:58.189ZMay 21 00:44:58.171 DEBG [sc] cr1: executing command `hostname cr1`
2272026-05-21T00:44:58.226ZMay 21 00:44:58.182 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2282026-05-21T00:44:58.226ZMay 21 00:44:58.193 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2292026-05-21T00:44:58.227ZMay 21 00:44:58.203 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2302026-05-21T00:44:58.261ZMay 21 00:44:58.214 INFO cr1: logging out
2312026-05-21T00:45:00.294ZMay 21 00:45:00.281 INFO cr1: logged out
2322026-05-21T00:45:00.951ZMay 21 00:45:00.933 DEBG [sc] ox: logging in
2332026-05-21T00:45:01.092ZMay 21 00:45:01.076 INFO ox: mounting /opt/cargo-bay
2342026-05-21T00:45:01.092ZMay 21 00:45:01.076 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2352026-05-21T00:45:02.106ZMay 21 00:45:02.093 DEBG [sc] ox: executing command `cd`
2362026-05-21T00:45:02.144ZMay 21 00:45:02.103 INFO ox: finished mounting /opt/cargo-bay
2372026-05-21T00:45:02.144ZMay 21 00:45:02.103 DEBG [sc] ox: executing command `hostname ox`
2382026-05-21T00:45:02.144ZMay 21 00:45:02.115 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2392026-05-21T00:45:02.144ZMay 21 00:45:02.126 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2402026-05-21T00:45:02.191ZMay 21 00:45:02.137 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2412026-05-21T00:45:02.191ZMay 21 00:45:02.148 INFO ox: logging out
2422026-05-21T00:45:02.254ZMay 21 00:45:02.235 INFO ox: logged out
2432026-05-21T00:45:02.332ZMay 21 00:45:02.316 DEBG [sc] cr2: logging in
2442026-05-21T00:45:02.743ZMay 21 00:45:02.727 INFO cr2: mounting /opt/cargo-bay
2452026-05-21T00:45:02.743ZMay 21 00:45:02.727 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2462026-05-21T00:45:02.778ZMay 21 00:45:02.750 DEBG [sc] cr2: executing command `cd`
2472026-05-21T00:45:02.778ZMay 21 00:45:02.761 INFO cr2: finished mounting /opt/cargo-bay
2482026-05-21T00:45:02.778ZMay 21 00:45:02.761 DEBG [sc] cr2: executing command `hostname cr2`
2492026-05-21T00:45:02.817ZMay 21 00:45:02.772 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2502026-05-21T00:45:02.817ZMay 21 00:45:02.783 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2512026-05-21T00:45:02.817ZMay 21 00:45:02.794 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2522026-05-21T00:45:02.852ZMay 21 00:45:02.805 INFO cr2: logging out
2532026-05-21T00:45:05.869ZMay 21 00:45:05.852 INFO cr2: logged out
2542026-05-21T00:45:05.908ZMay 21 00:45:05.852 DEBG [sc] ox: starting
2552026-05-21T00:45:05.908ZMay 21 00:45:05.852 DEBG [sc] ox: connecting to [::1]:37344
2562026-05-21T00:45:05.908ZMay 21 00:45:05.852 DEBG [sc] ox waiting for prompt
2572026-05-21T00:45:05.909ZMay 21 00:45:05.864 DEBG [sc] ox: logging in
2582026-05-21T00:45:05.974ZMay 21 00:45:05.953 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2592026-05-21T00:45:10.511ZMay 21 00:45:10.496 DEBG [sc] ox: starting
2602026-05-21T00:45:10.511ZMay 21 00:45:10.496 DEBG [sc] ox: connecting to [::1]:37344
2612026-05-21T00:45:10.553ZMay 21 00:45:10.497 DEBG [sc] ox waiting for prompt
2622026-05-21T00:45:10.553ZMay 21 00:45:10.507 DEBG [sc] ox: logging in
2632026-05-21T00:45:10.605ZMay 21 00:45:10.585 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2642026-05-21T00:45:10.688ZMay 21 00:45:10.672 DEBG [sc] ox: starting
2652026-05-21T00:45:10.689ZMay 21 00:45:10.672 DEBG [sc] ox: connecting to [::1]:37344
2662026-05-21T00:45:10.726ZMay 21 00:45:10.673 DEBG [sc] ox waiting for prompt
2672026-05-21T00:45:10.726ZMay 21 00:45:10.683 DEBG [sc] ox: logging in
2682026-05-21T00:45:10.790ZMay 21 00:45:10.771 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2692026-05-21T00:45:10.854ZMay 21 00:45:10.838 INFO cr1: installing frr
2702026-05-21T00:45:10.854ZMay 21 00:45:10.838 INFO waiting for ceos to initialize
2712026-05-21T00:45:10.854ZMay 21 00:45:10.838 INFO ox: setting up npuvm
2722026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] cr2: starting
2732026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] ox: starting
2742026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] cr2: connecting to [::1]:58115
2752026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] ox: connecting to [::1]:37344
2762026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] cr1: starting
2772026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] cr1: connecting to [::1]:45916
2782026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] cr2 waiting for prompt
2792026-05-21T00:45:10.891ZMay 21 00:45:10.838 DEBG [sc] ox waiting for prompt
2802026-05-21T00:45:10.892ZMay 21 00:45:10.839 DEBG [sc] cr1 waiting for prompt
2812026-05-21T00:45:10.892ZMay 21 00:45:10.848 DEBG [sc] ox: logging in
2822026-05-21T00:45:10.892ZMay 21 00:45:10.849 DEBG [sc] cr1: logging in
2832026-05-21T00:45:10.892ZMay 21 00:45:10.850 DEBG [sc] cr2: logging in
2842026-05-21T00:45:10.940ZMay 21 00:45:10.925 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2852026-05-21T00:45:11.008ZMay 21 00:45:10.994 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2862026-05-21T00:45:11.254ZMay 21 00:45:11.238 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2872026-05-21T00:45:13.254ZMay 21 00:45:13.233 INFO cr2: executing eos script show version
2882026-05-21T00:45:13.254ZMay 21 00:45:13.233 DEBG [sc] cr2: starting
2892026-05-21T00:45:13.254ZMay 21 00:45:13.233 DEBG [sc] cr2: connecting to [::1]:58115
2902026-05-21T00:45:13.291ZMay 21 00:45:13.234 DEBG [sc] cr2 waiting for prompt
2912026-05-21T00:45:13.291ZMay 21 00:45:13.244 DEBG [sc] cr2: logging in
2922026-05-21T00:45:13.390ZMay 21 00:45:13.376 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2932026-05-21T00:45:18.914ZMay 21 00:45:18.896 DEBG [sc] ox: starting
2942026-05-21T00:45:18.914ZMay 21 00:45:18.896 DEBG [sc] ox: connecting to [::1]:37344
2952026-05-21T00:45:18.947ZMay 21 00:45:18.897 DEBG [sc] ox waiting for prompt
2962026-05-21T00:45:18.947ZMay 21 00:45:18.907 DEBG [sc] ox: logging in
2972026-05-21T00:45:18.999ZMay 21 00:45:18.984 DEBG [sc] ox: executing command `chmod +x npuvm`
2982026-05-21T00:45:19.071ZMay 21 00:45:19.051 DEBG [sc] ox: starting
2992026-05-21T00:45:19.071ZMay 21 00:45:19.051 DEBG [sc] ox: connecting to [::1]:37344
3002026-05-21T00:45:19.107ZMay 21 00:45:19.052 DEBG [sc] ox waiting for prompt
3012026-05-21T00:45:19.107ZMay 21 00:45:19.062 DEBG [sc] ox: logging in
3022026-05-21T00:45:19.175ZMay 21 00:45:19.150 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3032026-05-21T00:45:22.755ZMay 21 00:45:22.742 DEBG [sc] cr2: starting
3042026-05-21T00:45:22.755ZMay 21 00:45:22.742 DEBG [sc] cr2: connecting to [::1]:58115
3052026-05-21T00:45:22.799ZMay 21 00:45:22.742 DEBG [sc] cr2 waiting for prompt
3062026-05-21T00:45:22.799ZMay 21 00:45:22.752 DEBG [sc] cr2: logging in
3072026-05-21T00:45:22.921ZMay 21 00:45:22.907 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3082026-05-21T00:45:25.030ZMay 21 00:45:25.011 INFO cr2: executing eos script show version
3092026-05-21T00:45:25.030ZMay 21 00:45:25.011 DEBG [sc] cr2: starting
3102026-05-21T00:45:25.030ZMay 21 00:45:25.011 DEBG [sc] cr2: connecting to [::1]:58115
3112026-05-21T00:45:25.067ZMay 21 00:45:25.012 DEBG [sc] cr2 waiting for prompt
3122026-05-21T00:45:25.067ZMay 21 00:45:25.023 DEBG [sc] cr2: logging in
3132026-05-21T00:45:25.201ZMay 21 00:45:25.187 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3142026-05-21T00:45:27.637ZMay 21 00:45:27.613 DEBG [sc] cr2: starting
3152026-05-21T00:45:27.637ZMay 21 00:45:27.613 DEBG [sc] cr2: connecting to [::1]:58115
3162026-05-21T00:45:27.711ZMay 21 00:45:27.613 DEBG [sc] cr2 waiting for prompt
3172026-05-21T00:45:27.711ZMay 21 00:45:27.623 DEBG [sc] cr2: logging in
3182026-05-21T00:45:27.782ZMay 21 00:45:27.756 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3192026-05-21T00:45:29.895ZMay 21 00:45:29.879 INFO cr2: executing eos script show version
3202026-05-21T00:45:29.895ZMay 21 00:45:29.879 DEBG [sc] cr2: starting
3212026-05-21T00:45:29.895ZMay 21 00:45:29.879 DEBG [sc] cr2: connecting to [::1]:58115
3222026-05-21T00:45:29.941ZMay 21 00:45:29.880 DEBG [sc] cr2 waiting for prompt
3232026-05-21T00:45:29.941ZMay 21 00:45:29.890 DEBG [sc] cr2: logging in
3242026-05-21T00:45:30.056ZMay 21 00:45:30.044 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3252026-05-21T00:45:39.676ZMay 21 00:45:32.500 INFO cr2: executing eos script
3262026-05-21T00:45:39.676Z enable
3272026-05-21T00:45:39.676Z configure
3282026-05-21T00:45:39.676Z ipv6 unicast-routing
3292026-05-21T00:45:39.676Z ip routing ipv6 interfaces
3302026-05-21T00:45:39.676Z ip routing
3312026-05-21T00:45:39.676Z ip route 1.2.3.0/24 null0
3322026-05-21T00:45:39.676Z ipv6 route fd99::/64 null0
3332026-05-21T00:45:39.676Z interface et1
3342026-05-21T00:45:39.676Z no switchport
3352026-05-21T00:45:39.676Z ipv6 enable
3362026-05-21T00:45:39.676Z
3372026-05-21T00:45:39.676Z router bgp 45
3382026-05-21T00:45:39.676Z router-id 1.2.3.1
3392026-05-21T00:45:39.677Z no bgp default ipv4-unicast
3402026-05-21T00:45:39.677Z timers bgp 2 6
3412026-05-21T00:45:39.677Z neighbor ebgp peer group
3422026-05-21T00:45:39.677Z neighbor ebgp remote-as 33
3432026-05-21T00:45:39.677Z neighbor interface Et1 peer-group ebgp
3442026-05-21T00:45:39.677Z address-family ipv4
3452026-05-21T00:45:39.677Z neighbor ebgp activate
3462026-05-21T00:45:39.677Z neighbor ebgp next-hop address-family ipv6 originate
3472026-05-21T00:45:39.677Z network 1.2.3.0/24
3482026-05-21T00:45:39.677Z exit
3492026-05-21T00:45:39.677Z address-family ipv6
3502026-05-21T00:45:39.677Z neighbor ebgp activate
3512026-05-21T00:45:39.677Z neighbor ebgp next-hop address-family ipv6 originate
3522026-05-21T00:45:39.677Z network fd99::/64
3532026-05-21T00:45:39.677Z exit
3542026-05-21T00:45:39.677Z exit
3552026-05-21T00:45:39.677Z
3562026-05-21T00:45:39.677ZMay 21 00:45:32.500 DEBG [sc] cr2: starting
3572026-05-21T00:45:39.677ZMay 21 00:45:32.500 DEBG [sc] cr2: connecting to [::1]:58115
3582026-05-21T00:45:39.743ZMay 21 00:45:32.501 DEBG [sc] cr2 waiting for prompt
3592026-05-21T00:45:39.743ZMay 21 00:45:32.511 DEBG [sc] cr2: logging in
3602026-05-21T00:45:39.743ZMay 21 00:45:32.643 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3612026-05-21T00:45:39.743Z enable
3622026-05-21T00:45:39.743Z configure
3632026-05-21T00:45:39.743Z ipv6 unicast-routing
3642026-05-21T00:45:39.743Z ip routing ipv6 interfaces
3652026-05-21T00:45:39.743Z ip routing
3662026-05-21T00:45:39.743Z ip route 1.2.3.0/24 null0
3672026-05-21T00:45:39.743Z ipv6 route fd99::/64 null0
3682026-05-21T00:45:39.743Z interface et1
3692026-05-21T00:45:39.743Z no switchport
3702026-05-21T00:45:39.743Z ipv6 enable
3712026-05-21T00:45:39.743Z
3722026-05-21T00:45:39.743Z router bgp 45
3732026-05-21T00:45:39.743Z router-id 1.2.3.1
3742026-05-21T00:45:39.743Z no bgp default ipv4-unicast
3752026-05-21T00:45:39.743Z timers bgp 2 6
3762026-05-21T00:45:39.743Z neighbor ebgp peer group
3772026-05-21T00:45:39.743Z neighbor ebgp remote-as 33
3782026-05-21T00:45:39.743Z neighbor interface Et1 peer-group ebgp
3792026-05-21T00:45:39.743Z address-family ipv4
3802026-05-21T00:45:39.743Z neighbor ebgp activate
3812026-05-21T00:45:39.743Z neighbor ebgp next-hop address-family ipv6 originate
3822026-05-21T00:45:39.743Z network 1.2.3.0/24
3832026-05-21T00:45:39.743Z exit
3842026-05-21T00:45:39.744Z address-family ipv6
3852026-05-21T00:45:39.744Z neighbor ebgp activate
3862026-05-21T00:45:39.744Z neighbor ebgp next-hop address-family ipv6 originate
3872026-05-21T00:45:39.744Z network fd99::/64
3882026-05-21T00:45:39.744Z exit
3892026-05-21T00:45:39.744Z exit
3902026-05-21T00:45:39.744Z '`
3912026-05-21T00:45:48.951ZMay 21 00:45:48.938 INFO cr1: enabling frr daemon bgpd
3922026-05-21T00:45:48.951ZMay 21 00:45:48.938 DEBG [sc] cr1: starting
3932026-05-21T00:45:48.951ZMay 21 00:45:48.938 DEBG [sc] cr1: connecting to [::1]:45916
3942026-05-21T00:45:48.991ZMay 21 00:45:48.939 DEBG [sc] cr1 waiting for prompt
3952026-05-21T00:45:48.991ZMay 21 00:45:48.949 DEBG [sc] cr1: logging in
3962026-05-21T00:45:49.097ZMay 21 00:45:49.082 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
3972026-05-21T00:45:51.184ZMay 21 00:45:51.170 DEBG [sc] cr1: starting
3982026-05-21T00:45:51.184ZMay 21 00:45:51.170 DEBG [sc] cr1: connecting to [::1]:45916
3992026-05-21T00:45:51.218ZMay 21 00:45:51.171 DEBG [sc] cr1 waiting for prompt
4002026-05-21T00:45:51.218ZMay 21 00:45:51.182 DEBG [sc] cr1: logging in
4012026-05-21T00:45:51.313ZMay 21 00:45:51.302 DEBG [sc] cr1: executing command `systemctl restart frr`
4022026-05-21T00:45:58.954ZMay 21 00:45:58.905 INFO cr1: executing frr script
4032026-05-21T00:45:58.954Z configure
4042026-05-21T00:45:58.954Z ip forwarding
4052026-05-21T00:45:58.954Z ipv6 forwarding
4062026-05-21T00:45:58.954Z ip route 1.2.3.0/24 null0
4072026-05-21T00:45:58.954Z ipv6 route fd99::/64 null0
4082026-05-21T00:45:58.954Z router bgp 44
4092026-05-21T00:45:58.954Z no bgp ebgp-requires-policy
4102026-05-21T00:45:58.954Z timers bgp 2 6
4112026-05-21T00:45:58.954Z neighbor enp0s8 interface remote-as external
4122026-05-21T00:45:58.954Z neighbor enp0s8 timers connect 1
4132026-05-21T00:45:58.954Z address-family ipv4 unicast
4142026-05-21T00:45:58.954Z network 1.2.3.0/24
4152026-05-21T00:45:58.954Z neighbor enp0s8 activate
4162026-05-21T00:45:58.954Z exit-address-family
4172026-05-21T00:45:58.954Z address-family ipv6 unicast
4182026-05-21T00:45:58.954Z network fd99::/64
4192026-05-21T00:45:58.955Z neighbor enp0s8 activate
4202026-05-21T00:45:58.955Z exit-address-family
4212026-05-21T00:45:58.955Z exit
4222026-05-21T00:45:58.955Z
4232026-05-21T00:45:58.955ZMay 21 00:45:58.905 DEBG [sc] cr1: starting
4242026-05-21T00:45:58.955ZMay 21 00:45:58.905 DEBG [sc] cr1: connecting to [::1]:45916
4252026-05-21T00:45:58.988ZMay 21 00:45:58.905 DEBG [sc] cr1 waiting for prompt
4262026-05-21T00:45:58.988ZMay 21 00:45:58.917 DEBG [sc] cr1: logging in
4272026-05-21T00:45:59.065ZMay 21 00:45:59.050 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 ' '`
4282026-05-21T00:47:57.447ZMay 21 00:47:57.430 DEBG [sc] ox: starting
4292026-05-21T00:47:57.447ZMay 21 00:47:57.430 DEBG [sc] ox: connecting to [::1]:37344
4302026-05-21T00:47:57.486ZMay 21 00:47:57.431 DEBG [sc] ox waiting for prompt
4312026-05-21T00:47:57.486ZMay 21 00:47:57.441 DEBG [sc] ox: logging in
4322026-05-21T00:47:57.552ZMay 21 00:47:57.529 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4332026-05-21T00:47:57.828ZMay 21 00:47:57.803 DEBG [sc] ox: starting
4342026-05-21T00:47:57.828ZMay 21 00:47:57.803 DEBG [sc] ox: connecting to [::1]:37344
4352026-05-21T00:47:57.867ZMay 21 00:47:57.804 DEBG [sc] ox waiting for prompt
4362026-05-21T00:47:57.867ZMay 21 00:47:57.814 DEBG [sc] ox: logging in
4372026-05-21T00:47:57.908ZMay 21 00:47:57.892 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4382026-05-21T00:47:58.933ZMay 21 00:47:58.915 DEBG [sc] ox: starting
4392026-05-21T00:47:58.933ZMay 21 00:47:58.915 DEBG [sc] ox: connecting to [::1]:37344
4402026-05-21T00:47:58.968ZMay 21 00:47:58.915 DEBG [sc] ox waiting for prompt
4412026-05-21T00:47:58.968ZMay 21 00:47:58.915 DEBG [sc] ox: logging in
4422026-05-21T00:47:59.013ZMay 21 00:47:58.994 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4432026-05-21T00:47:59.066ZMay 21 00:47:59.049 DEBG [sc] ox: starting
4442026-05-21T00:47:59.067ZMay 21 00:47:59.049 DEBG [sc] ox: connecting to [::1]:37344
4452026-05-21T00:47:59.099ZMay 21 00:47:59.049 DEBG [sc] ox waiting for prompt
4462026-05-21T00:47:59.099ZMay 21 00:47:59.059 DEBG [sc] ox: logging in
4472026-05-21T00:47:59.162ZMay 21 00:47:59.136 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4482026-05-21T00:47:59.211ZMay 21 00:47:59.192 DEBG [sc] ox: starting
4492026-05-21T00:47:59.211ZMay 21 00:47:59.192 DEBG [sc] ox: connecting to [::1]:37344
4502026-05-21T00:47:59.247ZMay 21 00:47:59.193 DEBG [sc] ox waiting for prompt
4512026-05-21T00:47:59.247ZMay 21 00:47:59.204 DEBG [sc] ox: logging in
4522026-05-21T00:47:59.300ZMay 21 00:47:59.281 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4532026-05-21T00:47:59.354ZMay 21 00:47:59.337 DEBG [sc] ox: starting
4542026-05-21T00:47:59.354ZMay 21 00:47:59.337 DEBG [sc] ox: connecting to [::1]:37344
4552026-05-21T00:47:59.384ZMay 21 00:47:59.338 DEBG [sc] ox waiting for prompt
4562026-05-21T00:47:59.384ZMay 21 00:47:59.348 DEBG [sc] ox: logging in
4572026-05-21T00:47:59.442ZMay 21 00:47:59.426 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4582026-05-21T00:47:59.499ZMay 21 00:47:59.481 DEBG [sc] ox: starting
4592026-05-21T00:47:59.499ZMay 21 00:47:59.481 DEBG [sc] ox: connecting to [::1]:37344
4602026-05-21T00:47:59.533ZMay 21 00:47:59.482 DEBG [sc] ox waiting for prompt
4612026-05-21T00:47:59.533ZMay 21 00:47:59.491 DEBG [sc] ox: logging in
4622026-05-21T00:47:59.599ZMay 21 00:47:59.579 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4632026-05-21T00:47:59.650ZMay 21 00:47:59.635 DEBG [sc] ox: starting
4642026-05-21T00:47:59.650ZMay 21 00:47:59.635 DEBG [sc] ox: connecting to [::1]:37344
4652026-05-21T00:47:59.684ZMay 21 00:47:59.636 DEBG [sc] ox waiting for prompt
4662026-05-21T00:47:59.684ZMay 21 00:47:59.645 DEBG [sc] ox: logging in
4672026-05-21T00:47:59.740ZMay 21 00:47:59.722 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4682026-05-21T00:47:59.792ZMay 21 00:47:59.777 DEBG [sc] ox: starting
4692026-05-21T00:47:59.792ZMay 21 00:47:59.777 DEBG [sc] ox: connecting to [::1]:37344
4702026-05-21T00:47:59.832ZMay 21 00:47:59.778 DEBG [sc] ox waiting for prompt
4712026-05-21T00:47:59.832ZMay 21 00:47:59.788 DEBG [sc] ox: logging in
4722026-05-21T00:47:59.887ZMay 21 00:47:59.867 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4732026-05-21T00:47:59.941ZMay 21 00:47:59.923 DEBG [sc] ox: starting
4742026-05-21T00:47:59.941ZMay 21 00:47:59.923 DEBG [sc] ox: connecting to [::1]:37344
4752026-05-21T00:47:59.981ZMay 21 00:47:59.924 DEBG [sc] ox waiting for prompt
4762026-05-21T00:47:59.982ZMay 21 00:47:59.934 DEBG [sc] ox: logging in
4772026-05-21T00:48:00.040ZMay 21 00:48:00.012 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4782026-05-21T00:48:00.101ZMay 21 00:48:00.083 INFO adding BGP router to mgd
4792026-05-21T00:48:02.730ZMay 21 00:48:02.685 INFO cr1: executing frr script show ip bgp json
4802026-05-21T00:48:02.730ZMay 21 00:48:02.685 DEBG [sc] cr1: starting
4812026-05-21T00:48:02.730ZMay 21 00:48:02.685 DEBG [sc] cr1: connecting to [::1]:45916
4822026-05-21T00:48:02.730ZMay 21 00:48:02.685 DEBG [sc] cr1 waiting for prompt
4832026-05-21T00:48:02.730ZMay 21 00:48:02.697 DEBG [sc] cr1: logging in
4842026-05-21T00:48:03.073ZMay 21 00:48:03.056 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4852026-05-21T00:48:05.203ZMay 21 00:48:05.186 INFO cr1: executing frr script show bgp json
4862026-05-21T00:48:05.236ZMay 21 00:48:05.187 DEBG [sc] cr1: starting
4872026-05-21T00:48:05.236ZMay 21 00:48:05.187 DEBG [sc] cr1: connecting to [::1]:45916
4882026-05-21T00:48:05.236ZMay 21 00:48:05.187 DEBG [sc] cr1 waiting for prompt
4892026-05-21T00:48:05.236ZMay 21 00:48:05.198 DEBG [sc] cr1: logging in
4902026-05-21T00:48:05.359ZMay 21 00:48:05.331 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
4912026-05-21T00:48:07.458ZMay 21 00:48:07.438 INFO cr2: executing eos script show ip bgp | json
4922026-05-21T00:48:07.459ZMay 21 00:48:07.438 DEBG [sc] cr2: starting
4932026-05-21T00:48:07.459ZMay 21 00:48:07.438 DEBG [sc] cr2: connecting to [::1]:58115
4942026-05-21T00:48:07.494ZMay 21 00:48:07.439 DEBG [sc] cr2 waiting for prompt
4952026-05-21T00:48:07.494ZMay 21 00:48:07.450 DEBG [sc] cr2: logging in
4962026-05-21T00:48:07.802ZMay 21 00:48:07.782 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
4972026-05-21T00:48:10.176ZMay 21 00:48:10.152 INFO cr2: executing eos script show ipv6 bgp | json
4982026-05-21T00:48:10.177ZMay 21 00:48:10.153 DEBG [sc] cr2: starting
4992026-05-21T00:48:10.177ZMay 21 00:48:10.153 DEBG [sc] cr2: connecting to [::1]:58115
5002026-05-21T00:48:10.209ZMay 21 00:48:10.153 DEBG [sc] cr2 waiting for prompt
5012026-05-21T00:48:10.210ZMay 21 00:48:10.163 DEBG [sc] cr2: logging in
5022026-05-21T00:48:10.324ZMay 21 00:48:10.307 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5032026-05-21T00:48:12.722ZMay 21 00:48:12.681 INFO trio bgp unnumbered test passed 🎉
5042026-05-21T00:48:12.722ZMay 21 00:48:12.681 INFO destroying runner for deployment mgtriou
5052026-05-21T00:48:12.722ZMay 21 00:48:12.681 INFO destroying deployment mgtriou
5062026-05-21T00:48:12.722ZMay 21 00:48:12.681 INFO destroying nodes
5072026-05-21T00:48:12.813ZMay 21 00:48:12.788 INFO destroying links
5082026-05-21T00:48:12.813ZMay 21 00:48:12.788 INFO destroying link mgtriou_ox_sn_vnic0
5092026-05-21T00:48:12.852ZMay 21 00:48:12.791 INFO destroying link mgtriou_ox_sn_sim0
5102026-05-21T00:48:12.852ZMay 21 00:48:12.792 INFO destroying link mgtriou_cr1_vn_vnic0
5112026-05-21T00:48:13.820ZMay 21 00:48:13.796 INFO destroying link mgtriou_cr1_vn_sim0
5122026-05-21T00:48:13.857ZMay 21 00:48:13.797 INFO destroying link mgtriou_ox_sn_vnic1
5132026-05-21T00:48:13.857ZMay 21 00:48:13.799 INFO destroying link mgtriou_ox_sn_sim1
5142026-05-21T00:48:13.857ZMay 21 00:48:13.800 INFO destroying link mgtriou_cr2_vn_vnic0
5152026-05-21T00:48:13.858ZMay 21 00:48:13.801 INFO destroying link mgtriou_cr2_vn_sim0
5162026-05-21T00:48:13.858ZMay 21 00:48:13.802 INFO destroying external links
5172026-05-21T00:48:13.858ZMay 21 00:48:13.802 INFO destroying external link mgtriou_ox_vn_vnic2
5182026-05-21T00:48:13.858ZMay 21 00:48:13.803 INFO destroying external link mgtriou_cr1_vn_vnic1
5192026-05-21T00:48:13.858ZMay 21 00:48:13.805 INFO destroying external link mgtriou_cr2_vn_vnic1
5202026-05-21T00:48:13.858ZMay 21 00:48:13.806 INFO destroying images
5212026-05-21T00:48:14.303ZMay 21 00:48:14.282 INFO destroying workspace at .falcon
5222026-05-21T00:48:14.348Z+ RUST_LOG=debug
5232026-05-21T00:48:14.348Z+ pfexec ./falcon-lab run trio-bfd-static-routing
5242026-05-21T00:48:14.385ZMay 21 00:48:14.325 DEBG using default route interface igb0
5252026-05-21T00:48:14.385ZMay 21 00:48:14.325 DEBG using default route interface igb0
5262026-05-21T00:48:14.385ZMay 21 00:48:14.325 DEBG using default route interface igb0
5272026-05-21T00:48:14.385ZMay 21 00:48:14.325 INFO launching runner: deployment(mgtriobfd) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
5282026-05-21T00:48:14.385ZMay 21 00:48:14.325 INFO starting preflight for deployment mgtriobfd
5292026-05-21T00:48:15.211ZMay 21 00:48:15.197 INFO creating links
5302026-05-21T00:48:15.212ZMay 21 00:48:15.197 DEBG destroying link mgtriobfd_ox_sn_vnic0
5312026-05-21T00:48:15.212ZMay 21 00:48:15.197 DEBG destroying link mgtriobfd_ox_sn_sim0
5322026-05-21T00:48:15.212ZMay 21 00:48:15.197 INFO creating simnet link 'mgtriobfd_ox_sn_sim0'
5332026-05-21T00:48:15.252ZMay 21 00:48:15.199 INFO creating vnic link 'mgtriobfd_ox_sn_vnic0'
5342026-05-21T00:48:15.252ZMay 21 00:48:15.206 DEBG link pair created
5352026-05-21T00:48:15.252ZMay 21 00:48:15.206 DEBG destroying link mgtriobfd_cr1_vn_vnic0
5362026-05-21T00:48:15.252ZMay 21 00:48:15.206 DEBG destroying link mgtriobfd_cr1_vn_sim0
5372026-05-21T00:48:15.252ZMay 21 00:48:15.206 INFO creating simnet link 'mgtriobfd_cr1_vn_sim0'
5382026-05-21T00:48:15.252ZMay 21 00:48:15.207 INFO creating vnic link 'mgtriobfd_cr1_vn_vnic0'
5392026-05-21T00:48:15.252ZMay 21 00:48:15.214 DEBG link pair created
5402026-05-21T00:48:15.252ZMay 21 00:48:15.214 DEBG destroying link mgtriobfd_ox_sn_vnic1
5412026-05-21T00:48:15.252ZMay 21 00:48:15.214 DEBG destroying link mgtriobfd_ox_sn_sim1
5422026-05-21T00:48:15.252ZMay 21 00:48:15.214 INFO creating simnet link 'mgtriobfd_ox_sn_sim1'
5432026-05-21T00:48:15.252ZMay 21 00:48:15.215 INFO creating vnic link 'mgtriobfd_ox_sn_vnic1'
5442026-05-21T00:48:15.252ZMay 21 00:48:15.221 DEBG link pair created
5452026-05-21T00:48:15.252ZMay 21 00:48:15.221 DEBG destroying link mgtriobfd_cr2_vn_vnic0
5462026-05-21T00:48:15.252ZMay 21 00:48:15.221 DEBG destroying link mgtriobfd_cr2_vn_sim0
5472026-05-21T00:48:15.252ZMay 21 00:48:15.221 INFO creating simnet link 'mgtriobfd_cr2_vn_sim0'
5482026-05-21T00:48:15.252ZMay 21 00:48:15.223 INFO creating vnic link 'mgtriobfd_cr2_vn_vnic0'
5492026-05-21T00:48:15.252ZMay 21 00:48:15.229 DEBG link pair created
5502026-05-21T00:48:15.252ZMay 21 00:48:15.229 INFO creating external links
5512026-05-21T00:48:15.252ZMay 21 00:48:15.229 DEBG destroying external link mgtriobfd_ox_vn_vnic2
5522026-05-21T00:48:15.253ZMay 21 00:48:15.229 INFO creating external link mgtriobfd_ox_vn_vnic2
5532026-05-21T00:48:15.289ZMay 21 00:48:15.230 DEBG external link mgtriobfd_ox_vn_vnic2@igb0 created
5542026-05-21T00:48:15.289ZMay 21 00:48:15.230 DEBG destroying external link mgtriobfd_cr1_vn_vnic1
5552026-05-21T00:48:15.289ZMay 21 00:48:15.230 INFO creating external link mgtriobfd_cr1_vn_vnic1
5562026-05-21T00:48:15.289ZMay 21 00:48:15.231 DEBG external link mgtriobfd_cr1_vn_vnic1@igb0 created
5572026-05-21T00:48:15.289ZMay 21 00:48:15.231 DEBG destroying external link mgtriobfd_cr2_vn_vnic1
5582026-05-21T00:48:15.289ZMay 21 00:48:15.231 INFO creating external link mgtriobfd_cr2_vn_vnic1
5592026-05-21T00:48:15.289ZMay 21 00:48:15.232 DEBG external link mgtriobfd_cr2_vn_vnic1@igb0 created
5602026-05-21T00:48:15.289ZMay 21 00:48:15.232 INFO creating nodes
5612026-05-21T00:48:15.289ZMay 21 00:48:15.232 INFO ox: launching node
5622026-05-21T00:48:15.289ZMay 21 00:48:15.235 INFO cr1: launching node
5632026-05-21T00:48:15.289ZMay 21 00:48:15.237 INFO cr2: launching node
5642026-05-21T00:48:15.290ZMay 21 00:48:15.250 INFO launched instance ox with pid 879 on port 34706
5652026-05-21T00:48:15.290ZMay 21 00:48:15.250 INFO ox: instance ensure
5662026-05-21T00:48:15.290ZMay 21 00:48:15.251 INFO launched instance cr1 with pid 880 on port 53071
5672026-05-21T00:48:15.290ZMay 21 00:48:15.251 INFO cr1: instance ensure
5682026-05-21T00:48:15.290ZMay 21 00:48:15.251 INFO launched instance cr2 with pid 881 on port 35931
5692026-05-21T00:48:15.290ZMay 21 00:48:15.251 INFO cr2: instance ensure
5702026-05-21T00:48:17.410ZMay 21 00:48:17.392 INFO cr2: instance ensure completed after 0 retries
5712026-05-21T00:48:17.410ZMay 21 00:48:17.392 INFO cr2: instance run
5722026-05-21T00:48:17.447ZMay 21 00:48:17.392 DEBG [sc] cr2: starting
5732026-05-21T00:48:17.447ZMay 21 00:48:17.392 DEBG [sc] cr2: connecting to [::1]:35931
5742026-05-21T00:48:17.447ZMay 21 00:48:17.393 DEBG [sc] cr2 waiting for prompt
5752026-05-21T00:48:17.501ZMay 21 00:48:17.484 INFO ox: instance ensure completed after 0 retries
5762026-05-21T00:48:17.501ZMay 21 00:48:17.484 INFO ox: instance run
5772026-05-21T00:48:17.534ZMay 21 00:48:17.485 DEBG [sc] ox: starting
5782026-05-21T00:48:17.534ZMay 21 00:48:17.485 DEBG [sc] ox: connecting to [::1]:34706
5792026-05-21T00:48:17.534ZMay 21 00:48:17.485 DEBG [sc] ox waiting for prompt
5802026-05-21T00:48:17.534ZMay 21 00:48:17.493 INFO cr1: instance ensure completed after 0 retries
5812026-05-21T00:48:17.534ZMay 21 00:48:17.493 INFO cr1: instance run
5822026-05-21T00:48:17.534ZMay 21 00:48:17.494 DEBG [sc] cr1: starting
5832026-05-21T00:48:17.534ZMay 21 00:48:17.494 DEBG [sc] cr1: connecting to [::1]:53071
5842026-05-21T00:48:17.534ZMay 21 00:48:17.495 DEBG [sc] cr1 waiting for prompt
5852026-05-21T00:48:34.531ZMay 21 00:48:34.513 DEBG [sc] cr1: logging in
5862026-05-21T00:48:34.906ZMay 21 00:48:34.884 INFO cr1: mounting /opt/cargo-bay
5872026-05-21T00:48:34.906ZMay 21 00:48:34.884 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5882026-05-21T00:48:34.947ZMay 21 00:48:34.906 DEBG [sc] cr1: executing command `cd`
5892026-05-21T00:48:34.947ZMay 21 00:48:34.918 INFO cr1: finished mounting /opt/cargo-bay
5902026-05-21T00:48:34.947ZMay 21 00:48:34.918 DEBG [sc] cr1: executing command `hostname cr1`
5912026-05-21T00:48:34.983ZMay 21 00:48:34.929 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
5922026-05-21T00:48:34.983ZMay 21 00:48:34.940 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
5932026-05-21T00:48:34.983ZMay 21 00:48:34.951 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
5942026-05-21T00:48:34.983ZMay 21 00:48:34.962 INFO cr1: logging out
5952026-05-21T00:48:37.053ZMay 21 00:48:37.020 INFO cr1: logged out
5962026-05-21T00:48:38.259ZMay 21 00:48:38.239 DEBG [sc] ox: logging in
5972026-05-21T00:48:38.467ZMay 21 00:48:38.449 INFO ox: mounting /opt/cargo-bay
5982026-05-21T00:48:38.467ZMay 21 00:48:38.449 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5992026-05-21T00:48:39.040ZMay 21 00:48:39.019 DEBG [sc] cr2: logging in
6002026-05-21T00:48:39.477ZMay 21 00:48:39.457 INFO cr2: mounting /opt/cargo-bay
6012026-05-21T00:48:39.477ZMay 21 00:48:39.457 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6022026-05-21T00:48:39.516ZMay 21 00:48:39.480 DEBG [sc] cr2: executing command `cd`
6032026-05-21T00:48:39.516ZMay 21 00:48:39.486 DEBG [sc] ox: executing command `cd`
6042026-05-21T00:48:39.516ZMay 21 00:48:39.491 INFO cr2: finished mounting /opt/cargo-bay
6052026-05-21T00:48:39.516ZMay 21 00:48:39.491 DEBG [sc] cr2: executing command `hostname cr2`
6062026-05-21T00:48:39.552ZMay 21 00:48:39.498 INFO ox: finished mounting /opt/cargo-bay
6072026-05-21T00:48:39.552ZMay 21 00:48:39.498 DEBG [sc] ox: executing command `hostname ox`
6082026-05-21T00:48:39.552ZMay 21 00:48:39.502 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
6092026-05-21T00:48:39.553ZMay 21 00:48:39.508 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
6102026-05-21T00:48:39.553ZMay 21 00:48:39.513 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
6112026-05-21T00:48:39.553ZMay 21 00:48:39.519 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
6122026-05-21T00:48:39.553ZMay 21 00:48:39.523 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
6132026-05-21T00:48:39.553ZMay 21 00:48:39.530 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
6142026-05-21T00:48:39.595ZMay 21 00:48:39.534 INFO cr2: logging out
6152026-05-21T00:48:39.595ZMay 21 00:48:39.541 INFO ox: logging out
6162026-05-21T00:48:39.654ZMay 21 00:48:39.630 INFO ox: logged out
6172026-05-21T00:48:42.483ZMay 21 00:48:42.463 INFO cr2: logged out
6182026-05-21T00:48:42.483ZMay 21 00:48:42.463 DEBG [sc] ox: starting
6192026-05-21T00:48:42.483ZMay 21 00:48:42.463 DEBG [sc] ox: connecting to [::1]:34706
6202026-05-21T00:48:42.518ZMay 21 00:48:42.464 DEBG [sc] ox waiting for prompt
6212026-05-21T00:48:42.518ZMay 21 00:48:42.475 DEBG [sc] ox: logging in
6222026-05-21T00:48:42.585ZMay 21 00:48:42.565 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
6232026-05-21T00:48:47.243ZMay 21 00:48:47.218 DEBG [sc] ox: starting
6242026-05-21T00:48:47.243ZMay 21 00:48:47.218 DEBG [sc] ox: connecting to [::1]:34706
6252026-05-21T00:48:47.276ZMay 21 00:48:47.218 DEBG [sc] ox waiting for prompt
6262026-05-21T00:48:47.276ZMay 21 00:48:47.229 DEBG [sc] ox: logging in
6272026-05-21T00:48:47.336ZMay 21 00:48:47.317 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
6282026-05-21T00:48:47.423ZMay 21 00:48:47.406 DEBG [sc] ox: starting
6292026-05-21T00:48:47.423ZMay 21 00:48:47.406 DEBG [sc] ox: connecting to [::1]:34706
6302026-05-21T00:48:47.460ZMay 21 00:48:47.406 DEBG [sc] ox waiting for prompt
6312026-05-21T00:48:47.460ZMay 21 00:48:47.416 DEBG [sc] ox: logging in
6322026-05-21T00:48:47.527ZMay 21 00:48:47.505 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
6332026-05-21T00:48:47.589ZMay 21 00:48:47.570 INFO cr1: installing frr
6342026-05-21T00:48:47.589ZMay 21 00:48:47.570 INFO waiting for ceos to initialize
6352026-05-21T00:48:47.590ZMay 21 00:48:47.570 INFO ox: setting up npuvm
6362026-05-21T00:48:47.629ZMay 21 00:48:47.571 DEBG [sc] cr1: starting
6372026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] cr1: connecting to [::1]:53071
6382026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] cr2: starting
6392026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] cr2: connecting to [::1]:35931
6402026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] ox: starting
6412026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] ox: connecting to [::1]:34706
6422026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] cr2 waiting for prompt
6432026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] cr1 waiting for prompt
6442026-05-21T00:48:47.630ZMay 21 00:48:47.571 DEBG [sc] ox waiting for prompt
6452026-05-21T00:48:47.630ZMay 21 00:48:47.581 DEBG [sc] cr1: logging in
6462026-05-21T00:48:47.630ZMay 21 00:48:47.582 DEBG [sc] ox: logging in
6472026-05-21T00:48:47.630ZMay 21 00:48:47.582 DEBG [sc] cr2: logging in
6482026-05-21T00:48:47.719ZMay 21 00:48:47.671 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
6492026-05-21T00:48:47.769ZMay 21 00:48:47.715 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6502026-05-21T00:48:47.972ZMay 21 00:48:47.911 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
6512026-05-21T00:48:49.943ZMay 21 00:48:49.923 INFO cr2: executing eos script show version
6522026-05-21T00:48:49.943ZMay 21 00:48:49.923 DEBG [sc] cr2: starting
6532026-05-21T00:48:49.943ZMay 21 00:48:49.923 DEBG [sc] cr2: connecting to [::1]:35931
6542026-05-21T00:48:49.982ZMay 21 00:48:49.923 DEBG [sc] cr2 waiting for prompt
6552026-05-21T00:48:49.982ZMay 21 00:48:49.934 DEBG [sc] cr2: logging in
6562026-05-21T00:48:50.097ZMay 21 00:48:50.076 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6572026-05-21T00:48:55.907ZMay 21 00:48:55.887 DEBG [sc] ox: starting
6582026-05-21T00:48:55.907ZMay 21 00:48:55.887 DEBG [sc] ox: connecting to [::1]:34706
6592026-05-21T00:48:55.943ZMay 21 00:48:55.887 DEBG [sc] ox waiting for prompt
6602026-05-21T00:48:55.943ZMay 21 00:48:55.898 DEBG [sc] ox: logging in
6612026-05-21T00:48:56.010ZMay 21 00:48:55.986 DEBG [sc] ox: executing command `chmod +x npuvm`
6622026-05-21T00:48:56.074ZMay 21 00:48:56.053 DEBG [sc] ox: starting
6632026-05-21T00:48:56.074ZMay 21 00:48:56.053 DEBG [sc] ox: connecting to [::1]:34706
6642026-05-21T00:48:56.109ZMay 21 00:48:56.053 DEBG [sc] ox waiting for prompt
6652026-05-21T00:48:56.109ZMay 21 00:48:56.063 DEBG [sc] ox: logging in
6662026-05-21T00:48:56.178ZMay 21 00:48:56.151 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
6672026-05-21T00:48:58.147ZMay 21 00:48:58.123 INFO cr1: enabling frr daemon bfdd
6682026-05-21T00:48:58.147ZMay 21 00:48:58.123 DEBG [sc] cr1: starting
6692026-05-21T00:48:58.147ZMay 21 00:48:58.123 DEBG [sc] cr1: connecting to [::1]:53071
6702026-05-21T00:48:58.183ZMay 21 00:48:58.124 DEBG [sc] cr1 waiting for prompt
6712026-05-21T00:48:58.183ZMay 21 00:48:58.135 DEBG [sc] cr1: logging in
6722026-05-21T00:48:58.295ZMay 21 00:48:58.266 DEBG [sc] cr1: executing command `sed -i 's/bfdd=no/bfdd=yes/g' /etc/frr/daemons`
6732026-05-21T00:48:59.691ZMay 21 00:48:59.672 DEBG [sc] cr2: starting
6742026-05-21T00:48:59.691ZMay 21 00:48:59.672 DEBG [sc] cr2: connecting to [::1]:35931
6752026-05-21T00:48:59.727ZMay 21 00:48:59.672 DEBG [sc] cr2 waiting for prompt
6762026-05-21T00:48:59.727ZMay 21 00:48:59.682 DEBG [sc] cr2: logging in
6772026-05-21T00:48:59.862ZMay 21 00:48:59.838 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6782026-05-21T00:49:00.367ZMay 21 00:49:00.347 DEBG [sc] cr1: starting
6792026-05-21T00:49:00.367ZMay 21 00:49:00.347 DEBG [sc] cr1: connecting to [::1]:53071
6802026-05-21T00:49:00.408ZMay 21 00:49:00.347 DEBG [sc] cr1 waiting for prompt
6812026-05-21T00:49:00.408ZMay 21 00:49:00.357 DEBG [sc] cr1: logging in
6822026-05-21T00:49:00.520ZMay 21 00:49:00.501 DEBG [sc] cr1: executing command `systemctl restart frr`
6832026-05-21T00:49:01.962ZMay 21 00:49:01.945 INFO cr2: executing eos script show version
6842026-05-21T00:49:01.962ZMay 21 00:49:01.945 DEBG [sc] cr2: starting
6852026-05-21T00:49:01.962ZMay 21 00:49:01.945 DEBG [sc] cr2: connecting to [::1]:35931
6862026-05-21T00:49:02.002ZMay 21 00:49:01.946 DEBG [sc] cr2 waiting for prompt
6872026-05-21T00:49:02.002ZMay 21 00:49:01.956 DEBG [sc] cr2: logging in
6882026-05-21T00:49:02.129ZMay 21 00:49:02.109 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6892026-05-21T00:49:04.450ZMay 21 00:49:04.430 DEBG [sc] cr2: starting
6902026-05-21T00:49:04.450ZMay 21 00:49:04.430 DEBG [sc] cr2: connecting to [::1]:35931
6912026-05-21T00:49:04.483ZMay 21 00:49:04.431 DEBG [sc] cr2 waiting for prompt
6922026-05-21T00:49:04.483ZMay 21 00:49:04.440 DEBG [sc] cr2: logging in
6932026-05-21T00:49:04.627ZMay 21 00:49:04.606 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6942026-05-21T00:49:06.756ZMay 21 00:49:06.732 INFO cr2: executing eos script show version
6952026-05-21T00:49:06.756ZMay 21 00:49:06.732 DEBG [sc] cr2: starting
6962026-05-21T00:49:06.756ZMay 21 00:49:06.732 DEBG [sc] cr2: connecting to [::1]:35931
6972026-05-21T00:49:06.790ZMay 21 00:49:06.732 DEBG [sc] cr2 waiting for prompt
6982026-05-21T00:49:06.790ZMay 21 00:49:06.744 DEBG [sc] cr2: logging in
6992026-05-21T00:49:06.924ZMay 21 00:49:06.900 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
7002026-05-21T00:49:08.121ZMay 21 00:49:08.096 INFO cr1: executing frr script
7012026-05-21T00:49:08.121Z configure
7022026-05-21T00:49:08.121Z interface enp0s8
7032026-05-21T00:49:08.122Z ip address 10.0.0.2/24
7042026-05-21T00:49:08.122Z ipv6 address fd00:1::2/64
7052026-05-21T00:49:08.122Z no shutdown
7062026-05-21T00:49:08.122Z exit
7072026-05-21T00:49:08.122Z bfd
7082026-05-21T00:49:08.122Z peer 10.0.0.1 local-address 10.0.0.2
7092026-05-21T00:49:08.122Z detect-multiplier 3
7102026-05-21T00:49:08.122Z receive-interval 300
7112026-05-21T00:49:08.122Z transmit-interval 300
7122026-05-21T00:49:08.122Z no shutdown
7132026-05-21T00:49:08.122Z exit
7142026-05-21T00:49:08.122Z peer fd00:1::1 local-address fd00:1::2
7152026-05-21T00:49:08.122Z detect-multiplier 3
7162026-05-21T00:49:08.122Z receive-interval 300
7172026-05-21T00:49:08.122Z transmit-interval 300
7182026-05-21T00:49:08.122Z no shutdown
7192026-05-21T00:49:08.122Z exit
7202026-05-21T00:49:08.122Z exit
7212026-05-21T00:49:08.122Z
7222026-05-21T00:49:08.163ZMay 21 00:49:08.096 DEBG [sc] cr1: starting
7232026-05-21T00:49:08.163ZMay 21 00:49:08.096 DEBG [sc] cr1: connecting to [::1]:53071
7242026-05-21T00:49:08.163ZMay 21 00:49:08.096 DEBG [sc] cr1 waiting for prompt
7252026-05-21T00:49:08.163ZMay 21 00:49:08.106 DEBG [sc] cr1: logging in
7262026-05-21T00:49:08.295ZMay 21 00:49:08.272 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 ' '`
7272026-05-21T00:49:09.383ZMay 21 00:49:09.356 INFO cr2: executing eos script
7282026-05-21T00:49:09.383Z enable
7292026-05-21T00:49:09.383Z configure
7302026-05-21T00:49:09.383Z ip routing
7312026-05-21T00:49:09.383Z ipv6 unicast-routing
7322026-05-21T00:49:09.383Z interface Ethernet1
7332026-05-21T00:49:09.383Z no switchport
7342026-05-21T00:49:09.383Z ip address 10.0.1.2/24
7352026-05-21T00:49:09.383Z ipv6 enable
7362026-05-21T00:49:09.383Z ipv6 address fd00:2::2/64
7372026-05-21T00:49:09.383Z bfd interval 300 min-rx 300 multiplier 3
7382026-05-21T00:49:09.383Z exit
7392026-05-21T00:49:09.383Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7402026-05-21T00:49:09.383Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7412026-05-21T00:49:09.383Z exit
7422026-05-21T00:49:09.383Z
7432026-05-21T00:49:09.383ZMay 21 00:49:09.357 DEBG [sc] cr2: starting
7442026-05-21T00:49:09.383ZMay 21 00:49:09.357 DEBG [sc] cr2: connecting to [::1]:35931
7452026-05-21T00:49:09.416ZMay 21 00:49:09.357 DEBG [sc] cr2 waiting for prompt
7462026-05-21T00:49:09.416ZMay 21 00:49:09.368 DEBG [sc] cr2: logging in
7472026-05-21T00:49:09.525ZMay 21 00:49:09.500 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
7482026-05-21T00:49:09.525Z enable
7492026-05-21T00:49:09.525Z configure
7502026-05-21T00:49:09.525Z ip routing
7512026-05-21T00:49:09.525Z ipv6 unicast-routing
7522026-05-21T00:49:09.525Z interface Ethernet1
7532026-05-21T00:49:09.525Z no switchport
7542026-05-21T00:49:09.525Z ip address 10.0.1.2/24
7552026-05-21T00:49:09.525Z ipv6 enable
7562026-05-21T00:49:09.525Z ipv6 address fd00:2::2/64
7572026-05-21T00:49:09.525Z bfd interval 300 min-rx 300 multiplier 3
7582026-05-21T00:49:09.525Z exit
7592026-05-21T00:49:09.525Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7602026-05-21T00:49:09.525Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7612026-05-21T00:49:09.525Z exit
7622026-05-21T00:49:09.525Z '`
7632026-05-21T00:51:07.386ZMay 21 00:51:07.360 DEBG [sc] ox: starting
7642026-05-21T00:51:07.387ZMay 21 00:51:07.360 DEBG [sc] ox: connecting to [::1]:34706
7652026-05-21T00:51:07.423ZMay 21 00:51:07.361 DEBG [sc] ox waiting for prompt
7662026-05-21T00:51:07.423ZMay 21 00:51:07.371 DEBG [sc] ox: logging in
7672026-05-21T00:51:07.466ZMay 21 00:51:07.448 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
7682026-05-21T00:51:07.802ZMay 21 00:51:07.780 DEBG [sc] ox: starting
7692026-05-21T00:51:07.802ZMay 21 00:51:07.780 DEBG [sc] ox: connecting to [::1]:34706
7702026-05-21T00:51:07.841ZMay 21 00:51:07.781 DEBG [sc] ox waiting for prompt
7712026-05-21T00:51:07.841ZMay 21 00:51:07.792 DEBG [sc] ox: logging in
7722026-05-21T00:51:07.890ZMay 21 00:51:07.869 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7732026-05-21T00:51:07.943ZMay 21 00:51:07.925 DEBG [sc] ox: starting
7742026-05-21T00:51:07.943ZMay 21 00:51:07.925 DEBG [sc] ox: connecting to [::1]:34706
7752026-05-21T00:51:07.975ZMay 21 00:51:07.926 DEBG [sc] ox waiting for prompt
7762026-05-21T00:51:07.975ZMay 21 00:51:07.936 DEBG [sc] ox: logging in
7772026-05-21T00:51:08.036ZMay 21 00:51:08.013 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7782026-05-21T00:51:09.069ZMay 21 00:51:09.035 DEBG [sc] ox: starting
7792026-05-21T00:51:09.069ZMay 21 00:51:09.036 DEBG [sc] ox: connecting to [::1]:34706
7802026-05-21T00:51:09.108ZMay 21 00:51:09.036 DEBG [sc] ox waiting for prompt
7812026-05-21T00:51:09.108ZMay 21 00:51:09.036 DEBG [sc] ox: logging in
7822026-05-21T00:51:09.143ZMay 21 00:51:09.114 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7832026-05-21T00:51:09.523ZMay 21 00:51:09.503 DEBG [sc] ox: starting
7842026-05-21T00:51:09.523ZMay 21 00:51:09.504 DEBG [sc] ox: connecting to [::1]:34706
7852026-05-21T00:51:09.566ZMay 21 00:51:09.504 DEBG [sc] ox waiting for prompt
7862026-05-21T00:51:09.566ZMay 21 00:51:09.516 DEBG [sc] ox: logging in
7872026-05-21T00:51:09.611ZMay 21 00:51:09.593 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
7882026-05-21T00:51:09.665ZMay 21 00:51:09.648 DEBG [sc] ox: starting
7892026-05-21T00:51:09.665ZMay 21 00:51:09.648 DEBG [sc] ox: connecting to [::1]:34706
7902026-05-21T00:51:09.708ZMay 21 00:51:09.649 DEBG [sc] ox waiting for prompt
7912026-05-21T00:51:09.709ZMay 21 00:51:09.659 DEBG [sc] ox: logging in
7922026-05-21T00:51:09.757ZMay 21 00:51:09.736 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
7932026-05-21T00:51:09.810ZMay 21 00:51:09.792 DEBG [sc] ox: starting
7942026-05-21T00:51:09.810ZMay 21 00:51:09.792 DEBG [sc] ox: connecting to [::1]:34706
7952026-05-21T00:51:09.845ZMay 21 00:51:09.793 DEBG [sc] ox waiting for prompt
7962026-05-21T00:51:09.845ZMay 21 00:51:09.802 DEBG [sc] ox: logging in
7972026-05-21T00:51:09.904ZMay 21 00:51:09.880 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.0.1/24 tfportqsfp0_0/v4`
7982026-05-21T00:51:10.506ZMay 21 00:51:10.489 DEBG [sc] ox: starting
7992026-05-21T00:51:10.506ZMay 21 00:51:10.489 DEBG [sc] ox: connecting to [::1]:34706
8002026-05-21T00:51:10.541ZMay 21 00:51:10.490 DEBG [sc] ox waiting for prompt
8012026-05-21T00:51:10.541ZMay 21 00:51:10.500 DEBG [sc] ox: logging in
8022026-05-21T00:51:10.602ZMay 21 00:51:10.577 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v4 -p -o addr`
8032026-05-21T00:51:10.650ZMay 21 00:51:10.633 DEBG [sc] ox: starting
8042026-05-21T00:51:10.650ZMay 21 00:51:10.633 DEBG [sc] ox: connecting to [::1]:34706
8052026-05-21T00:51:10.684ZMay 21 00:51:10.633 DEBG [sc] ox waiting for prompt
8062026-05-21T00:51:10.684ZMay 21 00:51:10.643 DEBG [sc] ox: logging in
8072026-05-21T00:51:10.754ZMay 21 00:51:10.731 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:1::1/64 tfportqsfp0_0/v6`
8082026-05-21T00:51:11.271ZMay 21 00:51:11.245 DEBG [sc] ox: starting
8092026-05-21T00:51:11.271ZMay 21 00:51:11.245 DEBG [sc] ox: connecting to [::1]:34706
8102026-05-21T00:51:11.307ZMay 21 00:51:11.245 DEBG [sc] ox waiting for prompt
8112026-05-21T00:51:11.307ZMay 21 00:51:11.255 DEBG [sc] ox: logging in
8122026-05-21T00:51:11.351ZMay 21 00:51:11.334 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v6 -p -o addr`
8132026-05-21T00:51:11.407ZMay 21 00:51:11.389 DEBG [sc] ox: starting
8142026-05-21T00:51:11.407ZMay 21 00:51:11.389 DEBG [sc] ox: connecting to [::1]:34706
8152026-05-21T00:51:11.440ZMay 21 00:51:11.390 DEBG [sc] ox waiting for prompt
8162026-05-21T00:51:11.440ZMay 21 00:51:11.400 DEBG [sc] ox: logging in
8172026-05-21T00:51:11.501ZMay 21 00:51:11.478 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
8182026-05-21T00:51:11.551ZMay 21 00:51:11.533 DEBG [sc] ox: starting
8192026-05-21T00:51:11.551ZMay 21 00:51:11.533 DEBG [sc] ox: connecting to [::1]:34706
8202026-05-21T00:51:11.584ZMay 21 00:51:11.534 DEBG [sc] ox waiting for prompt
8212026-05-21T00:51:11.584ZMay 21 00:51:11.544 DEBG [sc] ox: logging in
8222026-05-21T00:51:11.648ZMay 21 00:51:11.620 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
8232026-05-21T00:51:11.700ZMay 21 00:51:11.676 DEBG [sc] ox: starting
8242026-05-21T00:51:11.700ZMay 21 00:51:11.676 DEBG [sc] ox: connecting to [::1]:34706
8252026-05-21T00:51:11.733ZMay 21 00:51:11.677 DEBG [sc] ox waiting for prompt
8262026-05-21T00:51:11.733ZMay 21 00:51:11.687 DEBG [sc] ox: logging in
8272026-05-21T00:51:11.797ZMay 21 00:51:11.765 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.1.1/24 tfportqsfp1_0/v4`
8282026-05-21T00:51:12.454ZMay 21 00:51:12.435 DEBG [sc] ox: starting
8292026-05-21T00:51:12.454ZMay 21 00:51:12.435 DEBG [sc] ox: connecting to [::1]:34706
8302026-05-21T00:51:12.484ZMay 21 00:51:12.435 DEBG [sc] ox waiting for prompt
8312026-05-21T00:51:12.484ZMay 21 00:51:12.445 DEBG [sc] ox: logging in
8322026-05-21T00:51:12.547ZMay 21 00:51:12.522 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v4 -p -o addr`
8332026-05-21T00:51:12.616ZMay 21 00:51:12.588 DEBG [sc] ox: starting
8342026-05-21T00:51:12.616ZMay 21 00:51:12.588 DEBG [sc] ox: connecting to [::1]:34706
8352026-05-21T00:51:12.649ZMay 21 00:51:12.589 DEBG [sc] ox waiting for prompt
8362026-05-21T00:51:12.649ZMay 21 00:51:12.599 DEBG [sc] ox: logging in
8372026-05-21T00:51:12.727ZMay 21 00:51:12.676 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:2::1/64 tfportqsfp1_0/v6`
8382026-05-21T00:51:13.215ZMay 21 00:51:13.189 DEBG [sc] ox: starting
8392026-05-21T00:51:13.215ZMay 21 00:51:13.189 DEBG [sc] ox: connecting to [::1]:34706
8402026-05-21T00:51:13.248ZMay 21 00:51:13.190 DEBG [sc] ox waiting for prompt
8412026-05-21T00:51:13.249ZMay 21 00:51:13.201 DEBG [sc] ox: logging in
8422026-05-21T00:51:13.305ZMay 21 00:51:13.278 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v6 -p -o addr`
8432026-05-21T00:51:13.356ZMay 21 00:51:13.334 DEBG [sc] ox: starting
8442026-05-21T00:51:13.356ZMay 21 00:51:13.334 DEBG [sc] ox: connecting to [::1]:34706
8452026-05-21T00:51:13.394ZMay 21 00:51:13.335 DEBG [sc] ox waiting for prompt
8462026-05-21T00:51:13.394ZMay 21 00:51:13.345 DEBG [sc] ox: logging in
8472026-05-21T00:51:13.451ZMay 21 00:51:13.422 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
8482026-05-21T00:51:13.509ZMay 21 00:51:13.489 DEBG [sc] ox: starting
8492026-05-21T00:51:13.509ZMay 21 00:51:13.489 DEBG [sc] ox: connecting to [::1]:34706
8502026-05-21T00:51:13.540ZMay 21 00:51:13.489 DEBG [sc] ox waiting for prompt
8512026-05-21T00:51:13.540ZMay 21 00:51:13.500 DEBG [sc] ox: logging in
8522026-05-21T00:51:13.598ZMay 21 00:51:13.577 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
8532026-05-21T00:51:13.655ZMay 21 00:51:13.636 INFO installing static v4 route 192.168.100.0/24
8542026-05-21T00:51:13.699ZMay 21 00:51:13.636 INFO installing static v6 route fd01::/64
8552026-05-21T00:51:13.699ZMay 21 00:51:13.637 INFO adding BFD peers for cr1 and cr2 (dual-stack)
8562026-05-21T00:51:13.699ZMay 21 00:51:13.640 INFO phase 1: both peers up
8572026-05-21T00:51:14.663ZMay 21 00:51:14.646 INFO cr1: executing frr script show bfd peers json
8582026-05-21T00:51:14.663ZMay 21 00:51:14.646 DEBG [sc] cr1: starting
8592026-05-21T00:51:14.663ZMay 21 00:51:14.646 DEBG [sc] cr1: connecting to [::1]:53071
8602026-05-21T00:51:14.700ZMay 21 00:51:14.646 DEBG [sc] cr1 waiting for prompt
8612026-05-21T00:51:14.700ZMay 21 00:51:14.657 DEBG [sc] cr1: logging in
8622026-05-21T00:51:15.048ZMay 21 00:51:15.025 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8632026-05-21T00:51:17.191ZMay 21 00:51:17.167 INFO cr1: executing frr script show bfd peers json
8642026-05-21T00:51:17.191ZMay 21 00:51:17.167 DEBG [sc] cr1: starting
8652026-05-21T00:51:17.191ZMay 21 00:51:17.167 DEBG [sc] cr1: connecting to [::1]:53071
8662026-05-21T00:51:17.230ZMay 21 00:51:17.168 DEBG [sc] cr1 waiting for prompt
8672026-05-21T00:51:17.230ZMay 21 00:51:17.177 DEBG [sc] cr1: logging in
8682026-05-21T00:51:17.318ZMay 21 00:51:17.299 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8692026-05-21T00:51:19.463ZMay 21 00:51:19.446 INFO cr2: executing eos script show bfd peers | json
8702026-05-21T00:51:19.463ZMay 21 00:51:19.446 DEBG [sc] cr2: starting
8712026-05-21T00:51:19.463ZMay 21 00:51:19.446 DEBG [sc] cr2: connecting to [::1]:35931
8722026-05-21T00:51:19.495ZMay 21 00:51:19.447 DEBG [sc] cr2 waiting for prompt
8732026-05-21T00:51:19.496ZMay 21 00:51:19.458 DEBG [sc] cr2: logging in
8742026-05-21T00:51:19.839ZMay 21 00:51:19.820 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8752026-05-21T00:51:22.202ZMay 21 00:51:22.185 INFO cr2: executing eos script show bfd peers | json
8762026-05-21T00:51:22.202ZMay 21 00:51:22.185 DEBG [sc] cr2: starting
8772026-05-21T00:51:22.202ZMay 21 00:51:22.185 DEBG [sc] cr2: connecting to [::1]:35931
8782026-05-21T00:51:22.233ZMay 21 00:51:22.185 DEBG [sc] cr2 waiting for prompt
8792026-05-21T00:51:22.233ZMay 21 00:51:22.195 DEBG [sc] cr2: logging in
8802026-05-21T00:51:22.364ZMay 21 00:51:22.341 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8812026-05-21T00:51:24.747ZMay 21 00:51:24.720 INFO phase 2: pause bfdd on cr1
8822026-05-21T00:51:24.747ZMay 21 00:51:24.720 INFO cr1: pausing frr bfdd
8832026-05-21T00:51:24.747ZMay 21 00:51:24.720 DEBG [sc] cr1: starting
8842026-05-21T00:51:24.747ZMay 21 00:51:24.720 DEBG [sc] cr1: connecting to [::1]:53071
8852026-05-21T00:51:24.782ZMay 21 00:51:24.721 DEBG [sc] cr1 waiting for prompt
8862026-05-21T00:51:24.782ZMay 21 00:51:24.732 DEBG [sc] cr1: logging in
8872026-05-21T00:51:24.893ZMay 21 00:51:24.875 DEBG [sc] cr1: executing command `pkill -STOP bfdd`
8882026-05-21T00:51:26.980ZMay 21 00:51:26.955 INFO cr2: executing eos script show bfd peers | json
8892026-05-21T00:51:26.980ZMay 21 00:51:26.955 DEBG [sc] cr2: starting
8902026-05-21T00:51:26.980ZMay 21 00:51:26.955 DEBG [sc] cr2: connecting to [::1]:35931
8912026-05-21T00:51:27.014ZMay 21 00:51:26.956 DEBG [sc] cr2 waiting for prompt
8922026-05-21T00:51:27.014ZMay 21 00:51:26.966 DEBG [sc] cr2: logging in
8932026-05-21T00:51:27.119ZMay 21 00:51:27.099 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8942026-05-21T00:51:29.455ZMay 21 00:51:29.435 INFO cr2: executing eos script show bfd peers | json
8952026-05-21T00:51:29.455ZMay 21 00:51:29.435 DEBG [sc] cr2: starting
8962026-05-21T00:51:29.456ZMay 21 00:51:29.435 DEBG [sc] cr2: connecting to [::1]:35931
8972026-05-21T00:51:29.509ZMay 21 00:51:29.436 DEBG [sc] cr2 waiting for prompt
8982026-05-21T00:51:29.509ZMay 21 00:51:29.446 DEBG [sc] cr2: logging in
8992026-05-21T00:51:29.609ZMay 21 00:51:29.589 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9002026-05-21T00:51:31.947ZMay 21 00:51:31.925 INFO phase 3: pause ceos on cr2
9012026-05-21T00:51:31.947ZMay 21 00:51:31.925 INFO cr2: pausing ceos
9022026-05-21T00:51:31.947ZMay 21 00:51:31.925 DEBG [sc] cr2: starting
9032026-05-21T00:51:31.947ZMay 21 00:51:31.925 DEBG [sc] cr2: connecting to [::1]:35931
9042026-05-21T00:51:31.981ZMay 21 00:51:31.926 DEBG [sc] cr2 waiting for prompt
9052026-05-21T00:51:31.981ZMay 21 00:51:31.934 DEBG [sc] cr2: logging in
9062026-05-21T00:51:32.094ZMay 21 00:51:32.066 DEBG [sc] cr2: executing command `docker pause ceos`
9072026-05-21T00:51:34.199ZMay 21 00:51:34.176 INFO phase 4: resume bfdd on cr1
9082026-05-21T00:51:34.199ZMay 21 00:51:34.176 INFO cr1: resuming frr bfdd
9092026-05-21T00:51:34.199ZMay 21 00:51:34.177 DEBG [sc] cr1: starting
9102026-05-21T00:51:34.240ZMay 21 00:51:34.177 DEBG [sc] cr1: connecting to [::1]:53071
9112026-05-21T00:51:34.240ZMay 21 00:51:34.177 DEBG [sc] cr1 waiting for prompt
9122026-05-21T00:51:34.240ZMay 21 00:51:34.189 DEBG [sc] cr1: logging in
9132026-05-21T00:51:34.343ZMay 21 00:51:34.310 DEBG [sc] cr1: executing command `pkill -CONT bfdd`
9142026-05-21T00:51:36.428ZMay 21 00:51:36.402 INFO cr1: executing frr script show bfd peers json
9152026-05-21T00:51:36.428ZMay 21 00:51:36.402 DEBG [sc] cr1: starting
9162026-05-21T00:51:36.428ZMay 21 00:51:36.402 DEBG [sc] cr1: connecting to [::1]:53071
9172026-05-21T00:51:36.465ZMay 21 00:51:36.403 DEBG [sc] cr1 waiting for prompt
9182026-05-21T00:51:36.465ZMay 21 00:51:36.411 DEBG [sc] cr1: logging in
9192026-05-21T00:51:36.566ZMay 21 00:51:36.544 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9202026-05-21T00:51:38.701ZMay 21 00:51:38.684 INFO cr1: executing frr script show bfd peers json
9212026-05-21T00:51:38.739ZMay 21 00:51:38.685 DEBG [sc] cr1: starting
9222026-05-21T00:51:38.739ZMay 21 00:51:38.685 DEBG [sc] cr1: connecting to [::1]:53071
9232026-05-21T00:51:38.739ZMay 21 00:51:38.685 DEBG [sc] cr1 waiting for prompt
9242026-05-21T00:51:38.739ZMay 21 00:51:38.696 DEBG [sc] cr1: logging in
9252026-05-21T00:51:38.852ZMay 21 00:51:38.827 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9262026-05-21T00:51:40.983ZMay 21 00:51:40.958 INFO phase 5: unpause ceos on cr2
9272026-05-21T00:51:40.983ZMay 21 00:51:40.958 INFO cr2: unpausing ceos
9282026-05-21T00:51:40.983ZMay 21 00:51:40.958 DEBG [sc] cr2: starting
9292026-05-21T00:51:40.983ZMay 21 00:51:40.958 DEBG [sc] cr2: connecting to [::1]:35931
9302026-05-21T00:51:41.022ZMay 21 00:51:40.958 DEBG [sc] cr2 waiting for prompt
9312026-05-21T00:51:41.022ZMay 21 00:51:40.970 DEBG [sc] cr2: logging in
9322026-05-21T00:51:41.112ZMay 21 00:51:41.091 DEBG [sc] cr2: executing command `docker unpause ceos`
9332026-05-21T00:51:43.210ZMay 21 00:51:43.192 INFO cr1: executing frr script show bfd peers json
9342026-05-21T00:51:43.210ZMay 21 00:51:43.192 DEBG [sc] cr1: starting
9352026-05-21T00:51:43.210ZMay 21 00:51:43.192 DEBG [sc] cr1: connecting to [::1]:53071
9362026-05-21T00:51:43.244ZMay 21 00:51:43.193 DEBG [sc] cr1 waiting for prompt
9372026-05-21T00:51:43.244ZMay 21 00:51:43.204 DEBG [sc] cr1: logging in
9382026-05-21T00:51:43.360ZMay 21 00:51:43.338 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9392026-05-21T00:51:45.487ZMay 21 00:51:45.469 INFO cr1: executing frr script show bfd peers json
9402026-05-21T00:51:45.528ZMay 21 00:51:45.469 DEBG [sc] cr1: starting
9412026-05-21T00:51:45.528ZMay 21 00:51:45.469 DEBG [sc] cr1: connecting to [::1]:53071
9422026-05-21T00:51:45.528ZMay 21 00:51:45.469 DEBG [sc] cr1 waiting for prompt
9432026-05-21T00:51:45.528ZMay 21 00:51:45.480 DEBG [sc] cr1: logging in
9442026-05-21T00:51:45.680ZMay 21 00:51:45.657 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9452026-05-21T00:51:47.857ZMay 21 00:51:47.796 INFO cr2: executing eos script show bfd peers | json
9462026-05-21T00:51:47.857ZMay 21 00:51:47.796 DEBG [sc] cr2: starting
9472026-05-21T00:51:47.857ZMay 21 00:51:47.796 DEBG [sc] cr2: connecting to [::1]:35931
9482026-05-21T00:51:48.069ZMay 21 00:51:47.797 DEBG [sc] cr2 waiting for prompt
9492026-05-21T00:51:48.069ZMay 21 00:51:47.808 DEBG [sc] cr2: logging in
9502026-05-21T00:51:48.363ZMay 21 00:51:47.953 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9512026-05-21T00:51:50.315ZMay 21 00:51:50.293 INFO cr2: executing eos script show bfd peers | json
9522026-05-21T00:51:50.315ZMay 21 00:51:50.293 DEBG [sc] cr2: starting
9532026-05-21T00:51:50.315ZMay 21 00:51:50.293 DEBG [sc] cr2: connecting to [::1]:35931
9542026-05-21T00:51:50.347ZMay 21 00:51:50.294 DEBG [sc] cr2 waiting for prompt
9552026-05-21T00:51:50.347ZMay 21 00:51:50.304 DEBG [sc] cr2: logging in
9562026-05-21T00:51:50.456ZMay 21 00:51:50.436 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9572026-05-21T00:51:52.813ZMay 21 00:51:52.778 INFO trio bfd static routing test passed 🎉
9582026-05-21T00:51:52.814ZMay 21 00:51:52.778 INFO destroying runner for deployment mgtriobfd
9592026-05-21T00:51:52.814ZMay 21 00:51:52.778 INFO destroying deployment mgtriobfd
9602026-05-21T00:51:52.869ZMay 21 00:51:52.778 INFO destroying nodes
9612026-05-21T00:51:52.934ZMay 21 00:51:52.889 INFO destroying links
9622026-05-21T00:51:52.934ZMay 21 00:51:52.889 INFO destroying link mgtriobfd_ox_sn_vnic0
9632026-05-21T00:51:52.985ZMay 21 00:51:52.891 INFO destroying link mgtriobfd_ox_sn_sim0
9642026-05-21T00:51:52.985ZMay 21 00:51:52.893 INFO destroying link mgtriobfd_cr1_vn_vnic0
9652026-05-21T00:51:53.935ZMay 21 00:51:53.895 INFO destroying link mgtriobfd_cr1_vn_sim0
9662026-05-21T00:51:53.990ZMay 21 00:51:53.896 INFO destroying link mgtriobfd_ox_sn_vnic1
9672026-05-21T00:51:53.990ZMay 21 00:51:53.897 INFO destroying link mgtriobfd_ox_sn_sim1
9682026-05-21T00:51:53.990ZMay 21 00:51:53.898 INFO destroying link mgtriobfd_cr2_vn_vnic0
9692026-05-21T00:51:53.990ZMay 21 00:51:53.899 INFO destroying link mgtriobfd_cr2_vn_sim0
9702026-05-21T00:51:53.990ZMay 21 00:51:53.900 INFO destroying external links
9712026-05-21T00:51:53.990ZMay 21 00:51:53.900 INFO destroying external link mgtriobfd_ox_vn_vnic2
9722026-05-21T00:51:53.990ZMay 21 00:51:53.901 INFO destroying external link mgtriobfd_cr1_vn_vnic1
9732026-05-21T00:51:53.990ZMay 21 00:51:53.902 INFO destroying external link mgtriobfd_cr2_vn_vnic1
9742026-05-21T00:51:53.990ZMay 21 00:51:53.903 INFO destroying images
9752026-05-21T00:51:54.412ZMay 21 00:51:54.383 INFO destroying workspace at .falcon
9762026-05-21T00:51:54.464Zprocess exited: duration 807495 ms, exit code 0
 
9772026-05-21T00:51:54.567Zfound 0 output files