01KS1K83C8YCE7DMYGFP5YBTMB: falcon

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

Buildomat Job: 01KS1K8H99F3ZXZTDNPSXGXJPH

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-05-20T02:39:27.448Zjob dependencies complete; ready to run (waiting for 13 m 27 s)
22026-05-20T02:51:57.048Zjob assigned to worker 01KS1MJ4NQMSCA0CG5EY6TZY4B [factory edgar, gimlet/BRM42220010/973] (queued for 12 m 29 s)
32026-05-20T02:51:58.361Zdownloading input: /input/build/work/debug/ddmadm
42026-05-20T02:53:54.369Zdownloaded input: /input/build/work/debug/ddmadm
52026-05-20T02:53:54.369Zdownloading input: /input/build/work/debug/ddmd
62026-05-20T02:54:44.818Zdownloaded input: /input/build/work/debug/ddmd
72026-05-20T02:54:44.819Zdownloading input: /input/build/work/debug/mgadm
82026-05-20T02:56:19.844Zdownloaded input: /input/build/work/debug/mgadm
92026-05-20T02:56:19.877Zdownloading input: /input/build-interop/work/testbed.tar.gz
102026-05-20T02:56:34.148Zdownloaded input: /input/build-interop/work/testbed.tar.gz
112026-05-20T02:56:34.148Zdownloading input: /input/build/work/debug/mgd
122026-05-20T02:57:19.996Zdownloaded input: /input/build/work/debug/mgd
132026-05-20T02:57:20.028Zdownloading input: /input/build-interop/work/dhcp-server
142026-05-20T02:57:23.675Zdownloaded input: /input/build-interop/work/dhcp-server
152026-05-20T02:57:23.709Zdownloading input: /input/build/work/release/ddmadm
162026-05-20T02:57:30.636Zdownloaded input: /input/build/work/release/ddmadm
172026-05-20T02:57:30.636Zdownloading input: /input/build/work/release/ddmd
182026-05-20T02:57:38.369Zdownloaded input: /input/build/work/release/ddmd
192026-05-20T02:57:38.369Zdownloading input: /input/build/work/release/falcon-lab
202026-05-20T02:57:47.554Zdownloaded input: /input/build/work/release/falcon-lab
212026-05-20T02:57:47.554Zdownloading input: /input/build/work/release/mgadm
222026-05-20T02:57:53.743Zdownloaded input: /input/build/work/release/mgadm
232026-05-20T02:57:53.743Zdownloading input: /input/build/work/release/mgd
242026-05-20T02:58:02.109Zdownloaded input: /input/build/work/release/mgd
 
252026-05-20T02:58:02.109Zstarting task 0: "setup"
262026-05-20T02:58:02.149Z++ uname -s
272026-05-20T02:58:02.149Z+ kern=SunOS
282026-05-20T02:58:02.149Z+ build_user=build
292026-05-20T02:58:02.149Z+ build_uid=12345
302026-05-20T02:58:02.149Z+ work_dir=/work
312026-05-20T02:58:02.149Z+ input_dir=/input
322026-05-20T02:58:02.149Z+ [[ 0 == 12345 ]]
332026-05-20T02:58:02.149Z+ case "$kern" in
342026-05-20T02:58:02.149Z+ groupadd -g 12345 build
352026-05-20T02:58:02.149Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-05-20T02:58:04.144Z+ zfs create -o mountpoint=/work rpool/work
372026-05-20T02:58:04.177Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-05-20T02:58:04.211Z+ home_fs=
392026-05-20T02:58:04.211Z+ [[ '' == autofs ]]
402026-05-20T02:58:04.211Z+ mkdir -p /home/build
412026-05-20T02:58:04.211Z+ chown build:build /home/build /work
422026-05-20T02:58:06.189Z+ chmod 0700 /home/build /work
432026-05-20T02:58:06.225Zprocess exited: duration 4086 ms, exit code 0
 
442026-05-20T02:58:06.290Zstarting task 1: "authentication"
452026-05-20T02:58:06.401Zprocess exited: duration 103 ms, exit code 0
 
462026-05-20T02:58:06.472Zstarting task 2: "build"
472026-05-20T02:58:06.509Z+ set -e
482026-05-20T02:58:06.509Z+ banner zpool
492026-05-20T02:58:06.509Z
502026-05-20T02:58:06.509Z ###### ##### #### #### #
512026-05-20T02:58:06.509Z # # # # # # # #
522026-05-20T02:58:06.509Z # # # # # # # #
532026-05-20T02:58:06.509Z # ##### # # # # #
542026-05-20T02:58:06.509Z # # # # # # #
552026-05-20T02:58:06.509Z ###### # #### #### ######
562026-05-20T02:58:06.509Z
572026-05-20T02:58:06.509Z++ pfexec diskinfo -pH
582026-05-20T02:58:06.509Z++ sort -k8 -n -r
592026-05-20T02:58:06.509Z++ head -1
602026-05-20T02:58:06.509Z++ awk '{print $2}'
612026-05-20T02:58:06.543Z+ DISK=c9t0014EE81000BC3B1d0
622026-05-20T02:58:06.543Z+ export DISK
632026-05-20T02:58:06.543Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC3B1d0
642026-05-20T02:58:06.620Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-05-20T02:58:06.653Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-05-20T02:58:06.908Z+ [[ true =~ true ]]
672026-05-20T02:58:06.908Z+ pfexec zpool trim cpool
682026-05-20T02:58:06.942Z++ zpool status -t cpool
692026-05-20T02:58:06.942Z+ [[ ! pool: cpool
702026-05-20T02:58:06.943Z state: ONLINE
712026-05-20T02:58:06.943Z scan: none requested
722026-05-20T02:58:06.943Zconfig:
732026-05-20T02:58:06.943Z
742026-05-20T02:58:06.943Z NAME STATE READ WRITE CKSUM
752026-05-20T02:58:06.943Z cpool ONLINE 0 0 0
762026-05-20T02:58:06.943Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at May 20, 2026 at 02:58:06 AM UTC)
772026-05-20T02:58:06.943Z
782026-05-20T02:58:06.943Zerrors: No known data errors =~ 100% ]]
792026-05-20T02:58:06.943Z+ sleep 10
802026-05-20T02:58:16.942Z++ zpool status -t cpool
812026-05-20T02:58:16.975Z+ [[ ! pool: cpool
822026-05-20T02:58:16.975Z state: ONLINE
832026-05-20T02:58:16.975Z scan: none requested
842026-05-20T02:58:16.975Zconfig:
852026-05-20T02:58:16.975Z
862026-05-20T02:58:16.975Z NAME STATE READ WRITE CKSUM
872026-05-20T02:58:16.975Z cpool ONLINE 0 0 0
882026-05-20T02:58:16.975Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (72% trimmed, started at May 20, 2026 at 02:58:06 AM UTC)
892026-05-20T02:58:16.975Z
902026-05-20T02:58:16.976Zerrors: No known data errors =~ 100% ]]
912026-05-20T02:58:16.976Z+ sleep 10
922026-05-20T02:58:26.957Z++ zpool status -t cpool
932026-05-20T02:58:26.997Z+ [[ ! pool: cpool
942026-05-20T02:58:26.997Z state: ONLINE
952026-05-20T02:58:26.997Z scan: none requested
962026-05-20T02:58:26.997Zconfig:
972026-05-20T02:58:26.997Z
982026-05-20T02:58:26.997Z NAME STATE READ WRITE CKSUM
992026-05-20T02:58:26.997Z cpool ONLINE 0 0 0
1002026-05-20T02:58:26.997Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at May 20, 2026 at 02:58:21 AM UTC)
1012026-05-20T02:58:26.997Z
1022026-05-20T02:58:26.997Zerrors: No known data errors =~ 100% ]]
1032026-05-20T02:58:26.997Z+ pfexec chown 12345 /ci
1042026-05-20T02:58:26.997Z+ cd /ci
1052026-05-20T02:58:26.997Z+ export FALCON_DATASET=cpool/falcon
1062026-05-20T02:58:26.997Z+ FALCON_DATASET=cpool/falcon
1072026-05-20T02:58:26.997Z+ banner setup
1082026-05-20T02:58:26.997Z
1092026-05-20T02:58:26.997Z #### ###### ##### # # #####
1102026-05-20T02:58:26.997Z # # # # # # #
1112026-05-20T02:58:26.997Z #### ##### # # # # #
1122026-05-20T02:58:26.997Z # # # # # #####
1132026-05-20T02:58:26.997Z # # # # # # #
1142026-05-20T02:58:26.998Z #### ###### # #### #
1152026-05-20T02:58:26.998Z
1162026-05-20T02:58:26.998Z+ cp /input/build-interop/work/dhcp-server .
1172026-05-20T02:58:27.030Z+ cp /input/build/work/release/falcon-lab .
1182026-05-20T02:58:27.085Z+ cp /input/build/work/release/mgd .
1192026-05-20T02:58:27.147Z+ cp /input/build/work/release/ddmd .
1202026-05-20T02:58:27.201Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-05-20T02:58:27.232Z+ mkdir -p cargo-bay
1222026-05-20T02:58:27.232Z+ mv mgd cargo-bay/
1232026-05-20T02:58:27.232Z+ mv ddmd cargo-bay/
1242026-05-20T02:58:27.232Z+ export EXT_INTERFACE=igb0
1252026-05-20T02:58:27.232Z+ EXT_INTERFACE=igb0
1262026-05-20T02:58:27.232Z++ bmat address ls -f extra -Ho first
1272026-05-20T02:58:27.268Z+ first=10.151.6.164
1282026-05-20T02:58:27.268Z++ bmat address ls -f extra -Ho last
1292026-05-20T02:58:27.302Z+ last=10.151.6.227
1302026-05-20T02:58:27.302Z++ bmat address ls -f extra -Ho gateway
1312026-05-20T02:58:27.302Z+ gw=10.151.6.1
1322026-05-20T02:58:27.340Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-05-20T02:58:27.340Z++ sed 's#/.*##g'
1342026-05-20T02:58:27.340Z+ server=10.151.6.100
1352026-05-20T02:58:27.340Z+ RUST_LOG=debug
1362026-05-20T02:58:27.340Z+ pfexec ./falcon-lab run trio-unnumbered
1372026-05-20T02:58:27.340Z+ pfexec ./dhcp-server 10.151.6.164 10.151.6.227 10.151.6.1 10.151.6.100
1382026-05-20T02:58:27.340ZMay 20 02:58:27.316 DEBG using default route interface igb0
1392026-05-20T02:58:27.340ZMay 20 02:58:27.317 DEBG using default route interface igb0
1402026-05-20T02:58:27.340ZMay 20 02:58:27.317 DEBG using default route interface igb0
1412026-05-20T02:58:27.340ZMay 20 02:58:27.317 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1422026-05-20T02:58:27.340ZMay 20 02:58:27.317 INFO starting preflight for deployment mgtriou
1432026-05-20T02:58:27.340ZMay 20 02:58:27.317 INFO propolis-server binary not found
1442026-05-20T02:58:27.340ZMay 20 02:58:27.317 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1452026-05-20T02:58:34.106ZMay 20 02:58:34.089 INFO ovmf fd not found
1462026-05-20T02:58:34.106ZMay 20 02:58:34.089 INFO downloading ovmf
1472026-05-20T02:58:34.579ZMay 20 02:58:34.556 INFO base image for helios-2.9 does not exist, attempting to install
1482026-05-20T02:58:34.579ZMay 20 02:58:34.556 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1492026-05-20T02:58:49.575ZMay 20 02:58:49.558 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-20T02:59:32.300ZMay 20 02:59:32.280 INFO extracting image to /tmp/helios-2.9_0.raw
1512026-05-20T03:00:05.810ZMay 20 03:00:05.795 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1522026-05-20T03:00:05.860ZMay 20 03:00:05.844 INFO copying image data to zvol
1532026-05-20T03:00:16.120ZMay 20 03:00:16.098 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1542026-05-20T03:00:19.473ZMay 20 03:00:19.451 INFO base image for debian-13.2 does not exist, attempting to install
1552026-05-20T03:00:19.473ZMay 20 03:00:19.451 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1562026-05-20T03:00:49.531ZMay 20 03:00:49.507 INFO extracting image to /tmp/debian-13.2_0.raw
1572026-05-20T03:01:10.739ZMay 20 03:01:10.714 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1582026-05-20T03:01:10.772ZMay 20 03:01:10.741 INFO copying image data to zvol
1592026-05-20T03:01:17.861ZMay 20 03:01:17.067 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1602026-05-20T03:01:20.406ZMay 20 03:01:20.373 INFO base image for eos-4.35 does not exist, attempting to install
1612026-05-20T03:01:20.406ZMay 20 03:01:20.373 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1622026-05-20T03:02:23.616ZMay 20 03:02:23.595 INFO extracting image to /tmp/eos-4.35_0.raw
1632026-05-20T03:03:47.372ZMay 20 03:03:47.354 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1642026-05-20T03:03:47.405ZMay 20 03:03:47.378 INFO copying image data to zvol
1652026-05-20T03:04:47.240ZMay 20 03:04:47.224 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1662026-05-20T03:04:50.672ZMay 20 03:04:50.294 INFO creating links
1672026-05-20T03:04:50.672ZMay 20 03:04:50.295 DEBG destroying link mgtriou_ox_sn_vnic0
1682026-05-20T03:04:51.124ZMay 20 03:04:50.295 DEBG destroying link mgtriou_ox_sn_sim0
1692026-05-20T03:04:51.124ZMay 20 03:04:50.295 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1702026-05-20T03:04:51.124ZMay 20 03:04:50.297 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1712026-05-20T03:04:51.124ZMay 20 03:04:50.304 DEBG link pair created
1722026-05-20T03:04:51.124ZMay 20 03:04:50.304 DEBG destroying link mgtriou_cr1_vn_vnic0
1732026-05-20T03:04:51.124ZMay 20 03:04:50.304 DEBG destroying link mgtriou_cr1_vn_sim0
1742026-05-20T03:04:51.124ZMay 20 03:04:50.305 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1752026-05-20T03:04:51.124ZMay 20 03:04:50.306 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1762026-05-20T03:04:51.124ZMay 20 03:04:50.313 DEBG link pair created
1772026-05-20T03:04:51.124ZMay 20 03:04:50.313 DEBG destroying link mgtriou_ox_sn_vnic1
1782026-05-20T03:04:51.124ZMay 20 03:04:50.313 DEBG destroying link mgtriou_ox_sn_sim1
1792026-05-20T03:04:51.124ZMay 20 03:04:50.313 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1802026-05-20T03:04:51.124ZMay 20 03:04:50.314 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1812026-05-20T03:04:51.124ZMay 20 03:04:50.320 DEBG link pair created
1822026-05-20T03:04:51.124ZMay 20 03:04:50.320 DEBG destroying link mgtriou_cr2_vn_vnic0
1832026-05-20T03:04:51.124ZMay 20 03:04:50.320 DEBG destroying link mgtriou_cr2_vn_sim0
1842026-05-20T03:04:51.124ZMay 20 03:04:50.321 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1852026-05-20T03:04:51.124ZMay 20 03:04:50.322 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1862026-05-20T03:04:51.124ZMay 20 03:04:50.329 DEBG link pair created
1872026-05-20T03:04:51.124ZMay 20 03:04:50.329 INFO creating external links
1882026-05-20T03:04:51.125ZMay 20 03:04:50.329 DEBG destroying external link mgtriou_ox_vn_vnic2
1892026-05-20T03:04:51.125ZMay 20 03:04:50.329 INFO creating external link mgtriou_ox_vn_vnic2
1902026-05-20T03:04:51.125ZMay 20 03:04:50.332 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1912026-05-20T03:04:51.125ZMay 20 03:04:50.332 DEBG destroying external link mgtriou_cr1_vn_vnic1
1922026-05-20T03:04:51.125ZMay 20 03:04:50.332 INFO creating external link mgtriou_cr1_vn_vnic1
1932026-05-20T03:04:51.125ZMay 20 03:04:50.333 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1942026-05-20T03:04:51.125ZMay 20 03:04:50.333 DEBG destroying external link mgtriou_cr2_vn_vnic1
1952026-05-20T03:04:51.125ZMay 20 03:04:50.333 INFO creating external link mgtriou_cr2_vn_vnic1
1962026-05-20T03:04:51.125ZMay 20 03:04:50.334 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1972026-05-20T03:04:51.125ZMay 20 03:04:50.334 INFO creating nodes
1982026-05-20T03:04:51.125ZMay 20 03:04:50.334 INFO ox: launching node
1992026-05-20T03:04:51.125ZMay 20 03:04:50.337 INFO cr1: launching node
2002026-05-20T03:04:51.125ZMay 20 03:04:50.339 INFO cr2: launching node
2012026-05-20T03:04:51.125ZMay 20 03:04:50.353 INFO launched instance ox with pid 840 on port 55205
2022026-05-20T03:04:51.125ZMay 20 03:04:50.353 INFO ox: instance ensure
2032026-05-20T03:04:51.125ZMay 20 03:04:50.353 INFO launched instance cr1 with pid 841 on port 49602
2042026-05-20T03:04:51.125ZMay 20 03:04:50.353 INFO cr1: instance ensure
2052026-05-20T03:04:51.125ZMay 20 03:04:50.354 INFO launched instance cr2 with pid 842 on port 45800
2062026-05-20T03:04:51.125ZMay 20 03:04:50.354 INFO cr2: instance ensure
2072026-05-20T03:04:52.759ZMay 20 03:04:52.691 INFO ox: instance ensure completed after 0 retries
2082026-05-20T03:04:52.759ZMay 20 03:04:52.691 INFO ox: instance run
2092026-05-20T03:04:52.835ZMay 20 03:04:52.692 DEBG [sc] ox: starting
2102026-05-20T03:04:52.835ZMay 20 03:04:52.692 DEBG [sc] ox: connecting to [::1]:55205
2112026-05-20T03:04:52.835ZMay 20 03:04:52.694 DEBG [sc] ox waiting for prompt
2122026-05-20T03:04:52.835ZMay 20 03:04:52.730 INFO cr2: instance ensure completed after 0 retries
2132026-05-20T03:04:52.835ZMay 20 03:04:52.730 INFO cr2: instance run
2142026-05-20T03:04:52.835ZMay 20 03:04:52.731 DEBG [sc] cr2: starting
2152026-05-20T03:04:52.835ZMay 20 03:04:52.731 DEBG [sc] cr2: connecting to [::1]:45800
2162026-05-20T03:04:52.835ZMay 20 03:04:52.731 DEBG [sc] cr2 waiting for prompt
2172026-05-20T03:04:52.925ZMay 20 03:04:52.783 INFO cr1: instance ensure completed after 0 retries
2182026-05-20T03:04:52.925ZMay 20 03:04:52.783 INFO cr1: instance run
2192026-05-20T03:04:52.925ZMay 20 03:04:52.784 DEBG [sc] cr1: starting
2202026-05-20T03:04:52.925ZMay 20 03:04:52.784 DEBG [sc] cr1: connecting to [::1]:49602
2212026-05-20T03:04:52.925ZMay 20 03:04:52.785 DEBG [sc] cr1 waiting for prompt
2222026-05-20T03:05:10.029ZMay 20 03:05:10.008 DEBG [sc] cr1: logging in
2232026-05-20T03:05:10.438ZMay 20 03:05:10.422 INFO cr1: mounting /opt/cargo-bay
2242026-05-20T03:05:10.438ZMay 20 03:05:10.422 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2252026-05-20T03:05:10.469ZMay 20 03:05:10.445 DEBG [sc] cr1: executing command `cd`
2262026-05-20T03:05:10.503ZMay 20 03:05:10.456 INFO cr1: finished mounting /opt/cargo-bay
2272026-05-20T03:05:10.503ZMay 20 03:05:10.456 DEBG [sc] cr1: executing command `hostname cr1`
2282026-05-20T03:05:10.503ZMay 20 03:05:10.467 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2292026-05-20T03:05:10.503ZMay 20 03:05:10.478 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2302026-05-20T03:05:10.534ZMay 20 03:05:10.489 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2312026-05-20T03:05:10.534ZMay 20 03:05:10.500 INFO cr1: logging out
2322026-05-20T03:05:12.584ZMay 20 03:05:12.568 INFO cr1: logged out
2332026-05-20T03:05:13.105ZMay 20 03:05:13.086 DEBG [sc] ox: logging in
2342026-05-20T03:05:13.282ZMay 20 03:05:13.250 INFO ox: mounting /opt/cargo-bay
2352026-05-20T03:05:13.282ZMay 20 03:05:13.250 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2362026-05-20T03:05:14.375ZMay 20 03:05:14.356 DEBG [sc] ox: executing command `cd`
2372026-05-20T03:05:14.409ZMay 20 03:05:14.367 INFO ox: finished mounting /opt/cargo-bay
2382026-05-20T03:05:14.409ZMay 20 03:05:14.368 DEBG [sc] ox: executing command `hostname ox`
2392026-05-20T03:05:14.409ZMay 20 03:05:14.379 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2402026-05-20T03:05:14.409ZMay 20 03:05:14.382 DEBG [sc] cr2: logging in
2412026-05-20T03:05:14.409ZMay 20 03:05:14.390 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2422026-05-20T03:05:14.442ZMay 20 03:05:14.401 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2432026-05-20T03:05:14.442ZMay 20 03:05:14.412 INFO ox: logging out
2442026-05-20T03:05:14.509ZMay 20 03:05:14.489 INFO ox: logged out
2452026-05-20T03:05:14.832ZMay 20 03:05:14.813 INFO cr2: mounting /opt/cargo-bay
2462026-05-20T03:05:14.832ZMay 20 03:05:14.813 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2472026-05-20T03:05:14.864ZMay 20 03:05:14.835 DEBG [sc] cr2: executing command `cd`
2482026-05-20T03:05:14.864ZMay 20 03:05:14.846 INFO cr2: finished mounting /opt/cargo-bay
2492026-05-20T03:05:14.864ZMay 20 03:05:14.846 DEBG [sc] cr2: executing command `hostname cr2`
2502026-05-20T03:05:14.897ZMay 20 03:05:14.857 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2512026-05-20T03:05:14.897ZMay 20 03:05:14.868 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2522026-05-20T03:05:14.897ZMay 20 03:05:14.879 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2532026-05-20T03:05:14.928ZMay 20 03:05:14.890 INFO cr2: logging out
2542026-05-20T03:05:17.919ZMay 20 03:05:17.901 INFO cr2: logged out
2552026-05-20T03:05:17.952ZMay 20 03:05:17.901 DEBG [sc] ox: starting
2562026-05-20T03:05:17.952ZMay 20 03:05:17.901 DEBG [sc] ox: connecting to [::1]:55205
2572026-05-20T03:05:17.952ZMay 20 03:05:17.902 DEBG [sc] ox waiting for prompt
2582026-05-20T03:05:17.952ZMay 20 03:05:17.913 DEBG [sc] ox: logging in
2592026-05-20T03:05:18.019ZMay 20 03:05:18.002 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2602026-05-20T03:05:24.347ZMay 20 03:05:24.326 DEBG [sc] ox: starting
2612026-05-20T03:05:24.347ZMay 20 03:05:24.326 DEBG [sc] ox: connecting to [::1]:55205
2622026-05-20T03:05:24.384ZMay 20 03:05:24.327 DEBG [sc] ox waiting for prompt
2632026-05-20T03:05:24.384ZMay 20 03:05:24.337 DEBG [sc] ox: logging in
2642026-05-20T03:05:24.445ZMay 20 03:05:24.426 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2652026-05-20T03:05:24.530ZMay 20 03:05:24.514 DEBG [sc] ox: starting
2662026-05-20T03:05:24.530ZMay 20 03:05:24.514 DEBG [sc] ox: connecting to [::1]:55205
2672026-05-20T03:05:24.564ZMay 20 03:05:24.514 DEBG [sc] ox waiting for prompt
2682026-05-20T03:05:24.564ZMay 20 03:05:24.524 DEBG [sc] ox: logging in
2692026-05-20T03:05:24.630ZMay 20 03:05:24.613 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2702026-05-20T03:05:24.702ZMay 20 03:05:24.678 INFO waiting for ceos to initialize
2712026-05-20T03:05:24.702ZMay 20 03:05:24.678 INFO ox: setting up npuvm
2722026-05-20T03:05:24.702ZMay 20 03:05:24.678 INFO cr1: installing frr
2732026-05-20T03:05:24.736ZMay 20 03:05:24.678 DEBG [sc] cr2: starting
2742026-05-20T03:05:24.736ZMay 20 03:05:24.678 DEBG [sc] cr2: connecting to [::1]:45800
2752026-05-20T03:05:24.736ZMay 20 03:05:24.678 DEBG [sc] ox: starting
2762026-05-20T03:05:24.736ZMay 20 03:05:24.678 DEBG [sc] ox: connecting to [::1]:55205
2772026-05-20T03:05:24.736ZMay 20 03:05:24.679 DEBG [sc] cr1: starting
2782026-05-20T03:05:24.736ZMay 20 03:05:24.679 DEBG [sc] cr1: connecting to [::1]:49602
2792026-05-20T03:05:24.736ZMay 20 03:05:24.679 DEBG [sc] cr2 waiting for prompt
2802026-05-20T03:05:24.736ZMay 20 03:05:24.679 DEBG [sc] ox waiting for prompt
2812026-05-20T03:05:24.736ZMay 20 03:05:24.679 DEBG [sc] cr1 waiting for prompt
2822026-05-20T03:05:24.736ZMay 20 03:05:24.689 DEBG [sc] ox: logging in
2832026-05-20T03:05:24.736ZMay 20 03:05:24.690 DEBG [sc] cr2: logging in
2842026-05-20T03:05:24.737ZMay 20 03:05:24.690 DEBG [sc] cr1: logging in
2852026-05-20T03:05:24.794ZMay 20 03:05:24.778 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2862026-05-20T03:05:24.834ZMay 20 03:05:24.812 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2872026-05-20T03:05:25.105ZMay 20 03:05:25.083 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2882026-05-20T03:05:27.079ZMay 20 03:05:27.060 INFO cr2: executing eos script show version
2892026-05-20T03:05:27.079ZMay 20 03:05:27.060 DEBG [sc] cr2: starting
2902026-05-20T03:05:27.079ZMay 20 03:05:27.060 DEBG [sc] cr2: connecting to [::1]:45800
2912026-05-20T03:05:27.113ZMay 20 03:05:27.061 DEBG [sc] cr2 waiting for prompt
2922026-05-20T03:05:27.113ZMay 20 03:05:27.071 DEBG [sc] cr2: logging in
2932026-05-20T03:05:27.259ZMay 20 03:05:27.236 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2942026-05-20T03:05:34.748ZMay 20 03:05:34.728 DEBG [sc] cr2: starting
2952026-05-20T03:05:34.748ZMay 20 03:05:34.728 DEBG [sc] cr2: connecting to [::1]:45800
2962026-05-20T03:05:34.783ZMay 20 03:05:34.728 DEBG [sc] cr2 waiting for prompt
2972026-05-20T03:05:34.783ZMay 20 03:05:34.739 DEBG [sc] cr2: logging in
2982026-05-20T03:05:34.914ZMay 20 03:05:34.894 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2992026-05-20T03:05:37.048ZMay 20 03:05:37.026 INFO cr2: executing eos script show version
3002026-05-20T03:05:37.048ZMay 20 03:05:37.026 DEBG [sc] cr2: starting
3012026-05-20T03:05:37.048ZMay 20 03:05:37.026 DEBG [sc] cr2: connecting to [::1]:45800
3022026-05-20T03:05:37.079ZMay 20 03:05:37.027 DEBG [sc] cr2 waiting for prompt
3032026-05-20T03:05:37.079ZMay 20 03:05:37.037 DEBG [sc] cr2: logging in
3042026-05-20T03:05:37.211ZMay 20 03:05:37.191 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3052026-05-20T03:05:39.557ZMay 20 03:05:39.541 DEBG [sc] cr2: starting
3062026-05-20T03:05:39.557ZMay 20 03:05:39.541 DEBG [sc] cr2: connecting to [::1]:45800
3072026-05-20T03:05:39.591ZMay 20 03:05:39.541 DEBG [sc] cr2 waiting for prompt
3082026-05-20T03:05:39.592ZMay 20 03:05:39.551 DEBG [sc] cr2: logging in
3092026-05-20T03:05:39.718ZMay 20 03:05:39.695 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3102026-05-20T03:05:41.846ZMay 20 03:05:41.823 INFO cr2: executing eos script show version
3112026-05-20T03:05:41.846ZMay 20 03:05:41.823 DEBG [sc] cr2: starting
3122026-05-20T03:05:41.846ZMay 20 03:05:41.823 DEBG [sc] cr2: connecting to [::1]:45800
3132026-05-20T03:05:41.882ZMay 20 03:05:41.823 DEBG [sc] cr2 waiting for prompt
3142026-05-20T03:05:41.883ZMay 20 03:05:41.833 DEBG [sc] cr2: logging in
3152026-05-20T03:05:42.010ZMay 20 03:05:41.989 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3162026-05-20T03:05:51.293ZMay 20 03:05:44.380 INFO cr2: executing eos script
3172026-05-20T03:05:51.293Z enable
3182026-05-20T03:05:51.293Z configure
3192026-05-20T03:05:51.293Z ipv6 unicast-routing
3202026-05-20T03:05:51.293Z ip routing ipv6 interfaces
3212026-05-20T03:05:51.293Z ip routing
3222026-05-20T03:05:51.293Z ip route 1.2.3.0/24 null0
3232026-05-20T03:05:51.293Z ipv6 route fd99::/64 null0
3242026-05-20T03:05:51.293Z interface et1
3252026-05-20T03:05:51.293Z no switchport
3262026-05-20T03:05:51.293Z ipv6 enable
3272026-05-20T03:05:51.293Z
3282026-05-20T03:05:51.293Z router bgp 45
3292026-05-20T03:05:51.293Z router-id 1.2.3.1
3302026-05-20T03:05:51.293Z no bgp default ipv4-unicast
3312026-05-20T03:05:51.293Z timers bgp 2 6
3322026-05-20T03:05:51.293Z neighbor ebgp peer group
3332026-05-20T03:05:51.293Z neighbor ebgp remote-as 33
3342026-05-20T03:05:51.293Z neighbor interface Et1 peer-group ebgp
3352026-05-20T03:05:51.293Z address-family ipv4
3362026-05-20T03:05:51.293Z neighbor ebgp activate
3372026-05-20T03:05:51.293Z neighbor ebgp next-hop address-family ipv6 originate
3382026-05-20T03:05:51.293Z network 1.2.3.0/24
3392026-05-20T03:05:51.293Z exit
3402026-05-20T03:05:51.293Z address-family ipv6
3412026-05-20T03:05:51.293Z neighbor ebgp activate
3422026-05-20T03:05:51.294Z neighbor ebgp next-hop address-family ipv6 originate
3432026-05-20T03:05:51.294Z network fd99::/64
3442026-05-20T03:05:51.294Z exit
3452026-05-20T03:05:51.294Z exit
3462026-05-20T03:05:51.294Z
3472026-05-20T03:05:51.294ZMay 20 03:05:44.381 DEBG [sc] cr2: starting
3482026-05-20T03:05:51.294ZMay 20 03:05:44.381 DEBG [sc] cr2: connecting to [::1]:45800
3492026-05-20T03:05:51.373ZMay 20 03:05:44.381 DEBG [sc] cr2 waiting for prompt
3502026-05-20T03:05:51.373ZMay 20 03:05:44.392 DEBG [sc] cr2: logging in
3512026-05-20T03:05:51.373ZMay 20 03:05:44.535 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3522026-05-20T03:05:51.373Z enable
3532026-05-20T03:05:51.373Z configure
3542026-05-20T03:05:51.373Z ipv6 unicast-routing
3552026-05-20T03:05:51.373Z ip routing ipv6 interfaces
3562026-05-20T03:05:51.373Z ip routing
3572026-05-20T03:05:51.373Z ip route 1.2.3.0/24 null0
3582026-05-20T03:05:51.373Z ipv6 route fd99::/64 null0
3592026-05-20T03:05:51.373Z interface et1
3602026-05-20T03:05:51.373Z no switchport
3612026-05-20T03:05:51.373Z ipv6 enable
3622026-05-20T03:05:51.373Z
3632026-05-20T03:05:51.373Z router bgp 45
3642026-05-20T03:05:51.373Z router-id 1.2.3.1
3652026-05-20T03:05:51.373Z no bgp default ipv4-unicast
3662026-05-20T03:05:51.373Z timers bgp 2 6
3672026-05-20T03:05:51.373Z neighbor ebgp peer group
3682026-05-20T03:05:51.373Z neighbor ebgp remote-as 33
3692026-05-20T03:05:51.373Z neighbor interface Et1 peer-group ebgp
3702026-05-20T03:05:51.373Z address-family ipv4
3712026-05-20T03:05:51.373Z neighbor ebgp activate
3722026-05-20T03:05:51.373Z neighbor ebgp next-hop address-family ipv6 originate
3732026-05-20T03:05:51.373Z network 1.2.3.0/24
3742026-05-20T03:05:51.373Z exit
3752026-05-20T03:05:51.373Z address-family ipv6
3762026-05-20T03:05:51.373Z neighbor ebgp activate
3772026-05-20T03:05:51.374Z neighbor ebgp next-hop address-family ipv6 originate
3782026-05-20T03:05:51.374Z network fd99::/64
3792026-05-20T03:05:51.374Z exit
3802026-05-20T03:05:51.374Z exit
3812026-05-20T03:05:51.374Z '`
3822026-05-20T03:05:54.138ZMay 20 03:05:54.118 DEBG [sc] ox: starting
3832026-05-20T03:05:54.138ZMay 20 03:05:54.118 DEBG [sc] ox: connecting to [::1]:55205
3842026-05-20T03:05:54.170ZMay 20 03:05:54.119 DEBG [sc] ox waiting for prompt
3852026-05-20T03:05:54.170ZMay 20 03:05:54.129 DEBG [sc] ox: logging in
3862026-05-20T03:05:54.222ZMay 20 03:05:54.207 DEBG [sc] ox: executing command `chmod +x npuvm`
3872026-05-20T03:05:54.282ZMay 20 03:05:54.262 DEBG [sc] ox: starting
3882026-05-20T03:05:54.282ZMay 20 03:05:54.262 DEBG [sc] ox: connecting to [::1]:55205
3892026-05-20T03:05:54.318ZMay 20 03:05:54.263 DEBG [sc] ox waiting for prompt
3902026-05-20T03:05:54.318ZMay 20 03:05:54.274 DEBG [sc] ox: logging in
3912026-05-20T03:05:54.373ZMay 20 03:05:54.351 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3922026-05-20T03:06:03.655ZMay 20 03:06:03.635 INFO cr1: enabling frr daemon bgpd
3932026-05-20T03:06:03.689ZMay 20 03:06:03.635 DEBG [sc] cr1: starting
3942026-05-20T03:06:03.689ZMay 20 03:06:03.635 DEBG [sc] cr1: connecting to [::1]:49602
3952026-05-20T03:06:03.689ZMay 20 03:06:03.635 DEBG [sc] cr1 waiting for prompt
3962026-05-20T03:06:03.689ZMay 20 03:06:03.646 DEBG [sc] cr1: logging in
3972026-05-20T03:06:03.795ZMay 20 03:06:03.778 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
3982026-05-20T03:06:05.881ZMay 20 03:06:05.860 DEBG [sc] cr1: starting
3992026-05-20T03:06:05.881ZMay 20 03:06:05.860 DEBG [sc] cr1: connecting to [::1]:49602
4002026-05-20T03:06:05.914ZMay 20 03:06:05.861 DEBG [sc] cr1 waiting for prompt
4012026-05-20T03:06:05.914ZMay 20 03:06:05.871 DEBG [sc] cr1: logging in
4022026-05-20T03:06:06.020ZMay 20 03:06:06.004 DEBG [sc] cr1: executing command `systemctl restart frr`
4032026-05-20T03:06:13.939ZMay 20 03:06:13.640 INFO cr1: executing frr script
4042026-05-20T03:06:13.939Z configure
4052026-05-20T03:06:13.939Z ip forwarding
4062026-05-20T03:06:13.939Z ipv6 forwarding
4072026-05-20T03:06:13.939Z ip route 1.2.3.0/24 null0
4082026-05-20T03:06:13.939Z ipv6 route fd99::/64 null0
4092026-05-20T03:06:13.939Z router bgp 44
4102026-05-20T03:06:13.939Z no bgp ebgp-requires-policy
4112026-05-20T03:06:13.939Z timers bgp 2 6
4122026-05-20T03:06:13.939Z neighbor enp0s8 interface remote-as external
4132026-05-20T03:06:13.939Z neighbor enp0s8 timers connect 1
4142026-05-20T03:06:13.939Z address-family ipv4 unicast
4152026-05-20T03:06:13.939Z network 1.2.3.0/24
4162026-05-20T03:06:13.939Z neighbor enp0s8 activate
4172026-05-20T03:06:13.939Z exit-address-family
4182026-05-20T03:06:13.940Z address-family ipv6 unicast
4192026-05-20T03:06:13.940Z network fd99::/64
4202026-05-20T03:06:13.940Z neighbor enp0s8 activate
4212026-05-20T03:06:13.940Z exit-address-family
4222026-05-20T03:06:13.940Z exit
4232026-05-20T03:06:13.940Z
4242026-05-20T03:06:13.940ZMay 20 03:06:13.640 DEBG [sc] cr1: starting
4252026-05-20T03:06:13.940ZMay 20 03:06:13.640 DEBG [sc] cr1: connecting to [::1]:49602
4262026-05-20T03:06:13.978ZMay 20 03:06:13.641 DEBG [sc] cr1 waiting for prompt
4272026-05-20T03:06:13.978ZMay 20 03:06:13.652 DEBG [sc] cr1: logging in
4282026-05-20T03:06:13.978ZMay 20 03:06:13.784 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-20T03:08:02.720ZMay 20 03:08:02.699 DEBG [sc] ox: starting
4302026-05-20T03:08:02.720ZMay 20 03:08:02.699 DEBG [sc] ox: connecting to [::1]:55205
4312026-05-20T03:08:02.751ZMay 20 03:08:02.699 DEBG [sc] ox waiting for prompt
4322026-05-20T03:08:02.751ZMay 20 03:08:02.709 DEBG [sc] ox: logging in
4332026-05-20T03:08:02.803ZMay 20 03:08:02.786 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4342026-05-20T03:08:03.308ZMay 20 03:08:03.293 DEBG [sc] ox: starting
4352026-05-20T03:08:03.308ZMay 20 03:08:03.293 DEBG [sc] ox: connecting to [::1]:55205
4362026-05-20T03:08:03.339ZMay 20 03:08:03.293 DEBG [sc] ox waiting for prompt
4372026-05-20T03:08:03.340ZMay 20 03:08:03.305 DEBG [sc] ox: logging in
4382026-05-20T03:08:03.398ZMay 20 03:08:03.382 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4392026-05-20T03:08:03.454ZMay 20 03:08:03.437 DEBG [sc] ox: starting
4402026-05-20T03:08:03.454ZMay 20 03:08:03.437 DEBG [sc] ox: connecting to [::1]:55205
4412026-05-20T03:08:03.491ZMay 20 03:08:03.438 DEBG [sc] ox waiting for prompt
4422026-05-20T03:08:03.491ZMay 20 03:08:03.448 DEBG [sc] ox: logging in
4432026-05-20T03:08:03.541ZMay 20 03:08:03.526 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4442026-05-20T03:08:04.567ZMay 20 03:08:04.549 DEBG [sc] ox: starting
4452026-05-20T03:08:04.567ZMay 20 03:08:04.549 DEBG [sc] ox: connecting to [::1]:55205
4462026-05-20T03:08:04.599ZMay 20 03:08:04.550 DEBG [sc] ox waiting for prompt
4472026-05-20T03:08:04.599ZMay 20 03:08:04.550 DEBG [sc] ox: logging in
4482026-05-20T03:08:04.649ZMay 20 03:08:04.627 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4492026-05-20T03:08:04.698ZMay 20 03:08:04.682 DEBG [sc] ox: starting
4502026-05-20T03:08:04.698ZMay 20 03:08:04.682 DEBG [sc] ox: connecting to [::1]:55205
4512026-05-20T03:08:04.732ZMay 20 03:08:04.683 DEBG [sc] ox waiting for prompt
4522026-05-20T03:08:04.732ZMay 20 03:08:04.693 DEBG [sc] ox: logging in
4532026-05-20T03:08:04.787ZMay 20 03:08:04.770 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4542026-05-20T03:08:04.850ZMay 20 03:08:04.826 DEBG [sc] ox: starting
4552026-05-20T03:08:04.850ZMay 20 03:08:04.826 DEBG [sc] ox: connecting to [::1]:55205
4562026-05-20T03:08:04.884ZMay 20 03:08:04.826 DEBG [sc] ox waiting for prompt
4572026-05-20T03:08:04.884ZMay 20 03:08:04.837 DEBG [sc] ox: logging in
4582026-05-20T03:08:04.930ZMay 20 03:08:04.913 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4592026-05-20T03:08:04.989ZMay 20 03:08:04.969 DEBG [sc] ox: starting
4602026-05-20T03:08:04.989ZMay 20 03:08:04.969 DEBG [sc] ox: connecting to [::1]:55205
4612026-05-20T03:08:05.032ZMay 20 03:08:04.969 DEBG [sc] ox waiting for prompt
4622026-05-20T03:08:05.032ZMay 20 03:08:04.980 DEBG [sc] ox: logging in
4632026-05-20T03:08:05.076ZMay 20 03:08:05.057 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4642026-05-20T03:08:05.131ZMay 20 03:08:05.113 DEBG [sc] ox: starting
4652026-05-20T03:08:05.131ZMay 20 03:08:05.113 DEBG [sc] ox: connecting to [::1]:55205
4662026-05-20T03:08:05.167ZMay 20 03:08:05.114 DEBG [sc] ox waiting for prompt
4672026-05-20T03:08:05.167ZMay 20 03:08:05.124 DEBG [sc] ox: logging in
4682026-05-20T03:08:05.222ZMay 20 03:08:05.202 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4692026-05-20T03:08:05.283ZMay 20 03:08:05.267 DEBG [sc] ox: starting
4702026-05-20T03:08:05.283ZMay 20 03:08:05.267 DEBG [sc] ox: connecting to [::1]:55205
4712026-05-20T03:08:05.315ZMay 20 03:08:05.268 DEBG [sc] ox waiting for prompt
4722026-05-20T03:08:05.315ZMay 20 03:08:05.278 DEBG [sc] ox: logging in
4732026-05-20T03:08:05.374ZMay 20 03:08:05.356 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4742026-05-20T03:08:05.446ZMay 20 03:08:05.422 DEBG [sc] ox: starting
4752026-05-20T03:08:05.446ZMay 20 03:08:05.422 DEBG [sc] ox: connecting to [::1]:55205
4762026-05-20T03:08:05.479ZMay 20 03:08:05.423 DEBG [sc] ox waiting for prompt
4772026-05-20T03:08:05.479ZMay 20 03:08:05.433 DEBG [sc] ox: logging in
4782026-05-20T03:08:05.543ZMay 20 03:08:05.522 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4792026-05-20T03:08:05.607ZMay 20 03:08:05.592 INFO adding BGP router to mgd
4802026-05-20T03:08:08.090ZMay 20 03:08:08.075 INFO cr1: executing frr script show ip bgp json
4812026-05-20T03:08:08.090ZMay 20 03:08:08.075 DEBG [sc] cr1: starting
4822026-05-20T03:08:08.090ZMay 20 03:08:08.075 DEBG [sc] cr1: connecting to [::1]:49602
4832026-05-20T03:08:08.160ZMay 20 03:08:08.076 DEBG [sc] cr1 waiting for prompt
4842026-05-20T03:08:08.160ZMay 20 03:08:08.087 DEBG [sc] cr1: logging in
4852026-05-20T03:08:08.426ZMay 20 03:08:08.407 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4862026-05-20T03:08:10.549ZMay 20 03:08:10.533 INFO cr1: executing frr script show bgp json
4872026-05-20T03:08:10.549ZMay 20 03:08:10.533 DEBG [sc] cr1: starting
4882026-05-20T03:08:10.549ZMay 20 03:08:10.533 DEBG [sc] cr1: connecting to [::1]:49602
4892026-05-20T03:08:10.583ZMay 20 03:08:10.534 DEBG [sc] cr1 waiting for prompt
4902026-05-20T03:08:10.583ZMay 20 03:08:10.543 DEBG [sc] cr1: logging in
4912026-05-20T03:08:10.693ZMay 20 03:08:10.676 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
4922026-05-20T03:08:12.812ZMay 20 03:08:12.793 INFO cr2: executing eos script show ip bgp | json
4932026-05-20T03:08:12.812ZMay 20 03:08:12.793 DEBG [sc] cr2: starting
4942026-05-20T03:08:12.851ZMay 20 03:08:12.793 DEBG [sc] cr2: connecting to [::1]:45800
4952026-05-20T03:08:12.851ZMay 20 03:08:12.794 DEBG [sc] cr2 waiting for prompt
4962026-05-20T03:08:12.851ZMay 20 03:08:12.805 DEBG [sc] cr2: logging in
4972026-05-20T03:08:13.151ZMay 20 03:08:13.131 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
4982026-05-20T03:08:15.512ZMay 20 03:08:15.494 INFO cr2: executing eos script show ipv6 bgp | json
4992026-05-20T03:08:15.512ZMay 20 03:08:15.494 DEBG [sc] cr2: starting
5002026-05-20T03:08:15.512ZMay 20 03:08:15.494 DEBG [sc] cr2: connecting to [::1]:45800
5012026-05-20T03:08:15.545ZMay 20 03:08:15.494 DEBG [sc] cr2 waiting for prompt
5022026-05-20T03:08:15.545ZMay 20 03:08:15.504 DEBG [sc] cr2: logging in
5032026-05-20T03:08:15.664ZMay 20 03:08:15.648 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5042026-05-20T03:08:18.066ZMay 20 03:08:18.030 INFO trio bgp unnumbered test passed 🎉
5052026-05-20T03:08:18.100ZMay 20 03:08:18.030 INFO destroying runner for deployment mgtriou
5062026-05-20T03:08:18.101ZMay 20 03:08:18.030 INFO destroying deployment mgtriou
5072026-05-20T03:08:18.101ZMay 20 03:08:18.030 INFO destroying nodes
5082026-05-20T03:08:18.156ZMay 20 03:08:18.138 INFO destroying links
5092026-05-20T03:08:18.156ZMay 20 03:08:18.138 INFO destroying link mgtriou_ox_sn_vnic0
5102026-05-20T03:08:18.187ZMay 20 03:08:18.141 INFO destroying link mgtriou_ox_sn_sim0
5112026-05-20T03:08:18.187ZMay 20 03:08:18.143 INFO destroying link mgtriou_cr1_vn_vnic0
5122026-05-20T03:08:19.165ZMay 20 03:08:19.147 INFO destroying link mgtriou_cr1_vn_sim0
5132026-05-20T03:08:19.201ZMay 20 03:08:19.148 INFO destroying link mgtriou_ox_sn_vnic1
5142026-05-20T03:08:19.201ZMay 20 03:08:19.149 INFO destroying link mgtriou_ox_sn_sim1
5152026-05-20T03:08:19.201ZMay 20 03:08:19.150 INFO destroying link mgtriou_cr2_vn_vnic0
5162026-05-20T03:08:19.201ZMay 20 03:08:19.151 INFO destroying link mgtriou_cr2_vn_sim0
5172026-05-20T03:08:19.201ZMay 20 03:08:19.152 INFO destroying external links
5182026-05-20T03:08:19.201ZMay 20 03:08:19.152 INFO destroying external link mgtriou_ox_vn_vnic2
5192026-05-20T03:08:19.201ZMay 20 03:08:19.154 INFO destroying external link mgtriou_cr1_vn_vnic1
5202026-05-20T03:08:19.201ZMay 20 03:08:19.155 INFO destroying external link mgtriou_cr2_vn_vnic1
5212026-05-20T03:08:19.201ZMay 20 03:08:19.156 INFO destroying images
5222026-05-20T03:08:19.643ZMay 20 03:08:19.625 INFO destroying workspace at .falcon
5232026-05-20T03:08:19.679Z+ RUST_LOG=debug
5242026-05-20T03:08:19.679Z+ pfexec ./falcon-lab run trio-bfd-static-routing
5252026-05-20T03:08:19.717ZMay 20 03:08:19.667 DEBG using default route interface igb0
5262026-05-20T03:08:19.718ZMay 20 03:08:19.668 DEBG using default route interface igb0
5272026-05-20T03:08:19.718ZMay 20 03:08:19.668 DEBG using default route interface igb0
5282026-05-20T03:08:19.718ZMay 20 03:08:19.668 INFO launching runner: deployment(mgtriobfd) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
5292026-05-20T03:08:19.718ZMay 20 03:08:19.668 INFO starting preflight for deployment mgtriobfd
5302026-05-20T03:08:20.442ZMay 20 03:08:20.419 INFO creating links
5312026-05-20T03:08:20.442ZMay 20 03:08:20.419 DEBG destroying link mgtriobfd_ox_sn_vnic0
5322026-05-20T03:08:20.480ZMay 20 03:08:20.419 DEBG destroying link mgtriobfd_ox_sn_sim0
5332026-05-20T03:08:20.480ZMay 20 03:08:20.419 INFO creating simnet link 'mgtriobfd_ox_sn_sim0'
5342026-05-20T03:08:20.480ZMay 20 03:08:20.422 INFO creating vnic link 'mgtriobfd_ox_sn_vnic0'
5352026-05-20T03:08:20.480ZMay 20 03:08:20.429 DEBG link pair created
5362026-05-20T03:08:20.480ZMay 20 03:08:20.429 DEBG destroying link mgtriobfd_cr1_vn_vnic0
5372026-05-20T03:08:20.480ZMay 20 03:08:20.429 DEBG destroying link mgtriobfd_cr1_vn_sim0
5382026-05-20T03:08:20.480ZMay 20 03:08:20.429 INFO creating simnet link 'mgtriobfd_cr1_vn_sim0'
5392026-05-20T03:08:20.480ZMay 20 03:08:20.430 INFO creating vnic link 'mgtriobfd_cr1_vn_vnic0'
5402026-05-20T03:08:20.480ZMay 20 03:08:20.437 DEBG link pair created
5412026-05-20T03:08:20.480ZMay 20 03:08:20.437 DEBG destroying link mgtriobfd_ox_sn_vnic1
5422026-05-20T03:08:20.480ZMay 20 03:08:20.437 DEBG destroying link mgtriobfd_ox_sn_sim1
5432026-05-20T03:08:20.480ZMay 20 03:08:20.437 INFO creating simnet link 'mgtriobfd_ox_sn_sim1'
5442026-05-20T03:08:20.480ZMay 20 03:08:20.438 INFO creating vnic link 'mgtriobfd_ox_sn_vnic1'
5452026-05-20T03:08:20.481ZMay 20 03:08:20.445 DEBG link pair created
5462026-05-20T03:08:20.481ZMay 20 03:08:20.445 DEBG destroying link mgtriobfd_cr2_vn_vnic0
5472026-05-20T03:08:20.481ZMay 20 03:08:20.445 DEBG destroying link mgtriobfd_cr2_vn_sim0
5482026-05-20T03:08:20.481ZMay 20 03:08:20.445 INFO creating simnet link 'mgtriobfd_cr2_vn_sim0'
5492026-05-20T03:08:20.481ZMay 20 03:08:20.446 INFO creating vnic link 'mgtriobfd_cr2_vn_vnic0'
5502026-05-20T03:08:20.481ZMay 20 03:08:20.452 DEBG link pair created
5512026-05-20T03:08:20.481ZMay 20 03:08:20.453 INFO creating external links
5522026-05-20T03:08:20.481ZMay 20 03:08:20.453 DEBG destroying external link mgtriobfd_ox_vn_vnic2
5532026-05-20T03:08:20.481ZMay 20 03:08:20.453 INFO creating external link mgtriobfd_ox_vn_vnic2
5542026-05-20T03:08:20.481ZMay 20 03:08:20.454 DEBG external link mgtriobfd_ox_vn_vnic2@igb0 created
5552026-05-20T03:08:20.481ZMay 20 03:08:20.454 DEBG destroying external link mgtriobfd_cr1_vn_vnic1
5562026-05-20T03:08:20.481ZMay 20 03:08:20.454 INFO creating external link mgtriobfd_cr1_vn_vnic1
5572026-05-20T03:08:20.481ZMay 20 03:08:20.455 DEBG external link mgtriobfd_cr1_vn_vnic1@igb0 created
5582026-05-20T03:08:20.481ZMay 20 03:08:20.455 DEBG destroying external link mgtriobfd_cr2_vn_vnic1
5592026-05-20T03:08:20.481ZMay 20 03:08:20.455 INFO creating external link mgtriobfd_cr2_vn_vnic1
5602026-05-20T03:08:20.481ZMay 20 03:08:20.456 DEBG external link mgtriobfd_cr2_vn_vnic1@igb0 created
5612026-05-20T03:08:20.481ZMay 20 03:08:20.456 INFO creating nodes
5622026-05-20T03:08:20.481ZMay 20 03:08:20.456 INFO ox: launching node
5632026-05-20T03:08:20.520ZMay 20 03:08:20.458 INFO cr1: launching node
5642026-05-20T03:08:20.520ZMay 20 03:08:20.461 INFO cr2: launching node
5652026-05-20T03:08:20.520ZMay 20 03:08:20.474 INFO launched instance ox with pid 879 on port 43630
5662026-05-20T03:08:20.520ZMay 20 03:08:20.474 INFO ox: instance ensure
5672026-05-20T03:08:20.520ZMay 20 03:08:20.474 INFO launched instance cr1 with pid 880 on port 54296
5682026-05-20T03:08:20.520ZMay 20 03:08:20.474 INFO cr1: instance ensure
5692026-05-20T03:08:20.520ZMay 20 03:08:20.475 INFO launched instance cr2 with pid 881 on port 46047
5702026-05-20T03:08:20.520ZMay 20 03:08:20.475 INFO cr2: instance ensure
5712026-05-20T03:08:22.611ZMay 20 03:08:22.594 INFO ox: instance ensure completed after 0 retries
5722026-05-20T03:08:22.611ZMay 20 03:08:22.594 INFO ox: instance run
5732026-05-20T03:08:22.646ZMay 20 03:08:22.594 DEBG [sc] ox: starting
5742026-05-20T03:08:22.647ZMay 20 03:08:22.594 DEBG [sc] ox: connecting to [::1]:43630
5752026-05-20T03:08:22.647ZMay 20 03:08:22.595 DEBG [sc] ox waiting for prompt
5762026-05-20T03:08:22.699ZMay 20 03:08:22.681 INFO cr1: instance ensure completed after 0 retries
5772026-05-20T03:08:22.699ZMay 20 03:08:22.681 INFO cr1: instance run
5782026-05-20T03:08:22.731ZMay 20 03:08:22.682 DEBG [sc] cr1: starting
5792026-05-20T03:08:22.731ZMay 20 03:08:22.682 DEBG [sc] cr1: connecting to [::1]:54296
5802026-05-20T03:08:22.731ZMay 20 03:08:22.682 DEBG [sc] cr1 waiting for prompt
5812026-05-20T03:08:22.731ZMay 20 03:08:22.711 INFO cr2: instance ensure completed after 0 retries
5822026-05-20T03:08:22.731ZMay 20 03:08:22.711 INFO cr2: instance run
5832026-05-20T03:08:22.731ZMay 20 03:08:22.711 DEBG [sc] cr2: starting
5842026-05-20T03:08:22.731ZMay 20 03:08:22.711 DEBG [sc] cr2: connecting to [::1]:46047
5852026-05-20T03:08:22.731ZMay 20 03:08:22.712 DEBG [sc] cr2 waiting for prompt
5862026-05-20T03:08:39.840ZMay 20 03:08:39.822 DEBG [sc] cr1: logging in
5872026-05-20T03:08:40.225ZMay 20 03:08:40.210 INFO cr1: mounting /opt/cargo-bay
5882026-05-20T03:08:40.225ZMay 20 03:08:40.210 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5892026-05-20T03:08:40.256ZMay 20 03:08:40.231 DEBG [sc] cr1: executing command `cd`
5902026-05-20T03:08:40.297ZMay 20 03:08:40.242 INFO cr1: finished mounting /opt/cargo-bay
5912026-05-20T03:08:40.297ZMay 20 03:08:40.242 DEBG [sc] cr1: executing command `hostname cr1`
5922026-05-20T03:08:40.297ZMay 20 03:08:40.254 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
5932026-05-20T03:08:40.297ZMay 20 03:08:40.265 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
5942026-05-20T03:08:40.331ZMay 20 03:08:40.276 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
5952026-05-20T03:08:40.331ZMay 20 03:08:40.286 INFO cr1: logging out
5962026-05-20T03:08:42.369ZMay 20 03:08:42.353 INFO cr1: logged out
5972026-05-20T03:08:43.278ZMay 20 03:08:43.258 DEBG [sc] ox: logging in
5982026-05-20T03:08:43.473ZMay 20 03:08:43.457 INFO ox: mounting /opt/cargo-bay
5992026-05-20T03:08:43.473ZMay 20 03:08:43.457 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6002026-05-20T03:08:44.440ZMay 20 03:08:44.425 DEBG [sc] cr2: logging in
6012026-05-20T03:08:44.801ZMay 20 03:08:44.785 DEBG [sc] ox: executing command `cd`
6022026-05-20T03:08:44.833ZMay 20 03:08:44.796 INFO ox: finished mounting /opt/cargo-bay
6032026-05-20T03:08:44.833ZMay 20 03:08:44.796 DEBG [sc] ox: executing command `hostname ox`
6042026-05-20T03:08:44.833ZMay 20 03:08:44.807 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
6052026-05-20T03:08:44.879ZMay 20 03:08:44.819 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
6062026-05-20T03:08:44.879ZMay 20 03:08:44.821 INFO cr2: mounting /opt/cargo-bay
6072026-05-20T03:08:44.879ZMay 20 03:08:44.821 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6082026-05-20T03:08:44.879ZMay 20 03:08:44.830 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
6092026-05-20T03:08:44.880ZMay 20 03:08:44.832 DEBG [sc] cr2: executing command `cd`
6102026-05-20T03:08:44.880ZMay 20 03:08:44.841 INFO ox: logging out
6112026-05-20T03:08:44.880ZMay 20 03:08:44.843 INFO cr2: finished mounting /opt/cargo-bay
6122026-05-20T03:08:44.880ZMay 20 03:08:44.843 DEBG [sc] cr2: executing command `hostname cr2`
6132026-05-20T03:08:44.913ZMay 20 03:08:44.854 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
6142026-05-20T03:08:44.913ZMay 20 03:08:44.864 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
6152026-05-20T03:08:44.913ZMay 20 03:08:44.876 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
6162026-05-20T03:08:44.913ZMay 20 03:08:44.887 INFO cr2: logging out
6172026-05-20T03:08:44.967ZMay 20 03:08:44.948 INFO ox: logged out
6182026-05-20T03:08:48.036ZMay 20 03:08:47.772 INFO cr2: logged out
6192026-05-20T03:08:48.695ZMay 20 03:08:47.772 DEBG [sc] ox: starting
6202026-05-20T03:08:48.695ZMay 20 03:08:47.772 DEBG [sc] ox: connecting to [::1]:43630
6212026-05-20T03:08:48.695ZMay 20 03:08:47.773 DEBG [sc] ox waiting for prompt
6222026-05-20T03:08:48.695ZMay 20 03:08:47.784 DEBG [sc] ox: logging in
6232026-05-20T03:08:48.695ZMay 20 03:08:47.872 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
6242026-05-20T03:08:52.969ZMay 20 03:08:52.947 DEBG [sc] ox: starting
6252026-05-20T03:08:52.969ZMay 20 03:08:52.947 DEBG [sc] ox: connecting to [::1]:43630
6262026-05-20T03:08:53.002ZMay 20 03:08:52.947 DEBG [sc] ox waiting for prompt
6272026-05-20T03:08:53.002ZMay 20 03:08:52.957 DEBG [sc] ox: logging in
6282026-05-20T03:08:53.059ZMay 20 03:08:53.035 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
6292026-05-20T03:08:53.185ZMay 20 03:08:53.123 DEBG [sc] ox: starting
6302026-05-20T03:08:53.185ZMay 20 03:08:53.123 DEBG [sc] ox: connecting to [::1]:43630
6312026-05-20T03:08:53.185ZMay 20 03:08:53.124 DEBG [sc] ox waiting for prompt
6322026-05-20T03:08:53.185ZMay 20 03:08:53.134 DEBG [sc] ox: logging in
6332026-05-20T03:08:53.240ZMay 20 03:08:53.222 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
6342026-05-20T03:08:53.308ZMay 20 03:08:53.288 INFO cr1: installing frr
6352026-05-20T03:08:53.308ZMay 20 03:08:53.288 INFO waiting for ceos to initialize
6362026-05-20T03:08:53.308ZMay 20 03:08:53.288 INFO ox: setting up npuvm
6372026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr1: starting
6382026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr1: connecting to [::1]:54296
6392026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr2: starting
6402026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr2: connecting to [::1]:46047
6412026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] ox: starting
6422026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] ox: connecting to [::1]:43630
6432026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr2 waiting for prompt
6442026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] cr1 waiting for prompt
6452026-05-20T03:08:53.345ZMay 20 03:08:53.289 DEBG [sc] ox waiting for prompt
6462026-05-20T03:08:53.345ZMay 20 03:08:53.299 DEBG [sc] ox: logging in
6472026-05-20T03:08:53.345ZMay 20 03:08:53.300 DEBG [sc] cr1: logging in
6482026-05-20T03:08:53.345ZMay 20 03:08:53.301 DEBG [sc] cr2: logging in
6492026-05-20T03:08:53.392ZMay 20 03:08:53.377 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
6502026-05-20T03:08:53.450ZMay 20 03:08:53.433 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6512026-05-20T03:08:53.699ZMay 20 03:08:53.643 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
6522026-05-20T03:08:55.790ZMay 20 03:08:55.719 INFO cr2: executing eos script show version
6532026-05-20T03:08:55.790ZMay 20 03:08:55.720 DEBG [sc] cr2: starting
6542026-05-20T03:08:55.790ZMay 20 03:08:55.720 DEBG [sc] cr2: connecting to [::1]:46047
6552026-05-20T03:08:55.861ZMay 20 03:08:55.720 DEBG [sc] cr2 waiting for prompt
6562026-05-20T03:08:55.861ZMay 20 03:08:55.730 DEBG [sc] cr2: logging in
6572026-05-20T03:08:55.945ZMay 20 03:08:55.884 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6582026-05-20T03:09:00.495ZMay 20 03:09:00.479 DEBG [sc] ox: starting
6592026-05-20T03:09:00.495ZMay 20 03:09:00.479 DEBG [sc] ox: connecting to [::1]:43630
6602026-05-20T03:09:00.529ZMay 20 03:09:00.479 DEBG [sc] ox waiting for prompt
6612026-05-20T03:09:00.529ZMay 20 03:09:00.491 DEBG [sc] ox: logging in
6622026-05-20T03:09:00.594ZMay 20 03:09:00.578 DEBG [sc] ox: executing command `chmod +x npuvm`
6632026-05-20T03:09:00.660ZMay 20 03:09:00.644 DEBG [sc] ox: starting
6642026-05-20T03:09:00.660ZMay 20 03:09:00.644 DEBG [sc] ox: connecting to [::1]:43630
6652026-05-20T03:09:00.692ZMay 20 03:09:00.644 DEBG [sc] ox waiting for prompt
6662026-05-20T03:09:00.692ZMay 20 03:09:00.656 DEBG [sc] ox: logging in
6672026-05-20T03:09:00.759ZMay 20 03:09:00.743 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
6682026-05-20T03:09:03.929ZMay 20 03:09:03.911 INFO cr1: enabling frr daemon bfdd
6692026-05-20T03:09:03.929ZMay 20 03:09:03.911 DEBG [sc] cr1: starting
6702026-05-20T03:09:03.929ZMay 20 03:09:03.911 DEBG [sc] cr1: connecting to [::1]:54296
6712026-05-20T03:09:03.964ZMay 20 03:09:03.911 DEBG [sc] cr1 waiting for prompt
6722026-05-20T03:09:03.964ZMay 20 03:09:03.922 DEBG [sc] cr1: logging in
6732026-05-20T03:09:04.073ZMay 20 03:09:04.055 DEBG [sc] cr1: executing command `sed -i 's/bfdd=no/bfdd=yes/g' /etc/frr/daemons`
6742026-05-20T03:09:05.404ZMay 20 03:09:05.380 DEBG [sc] cr2: starting
6752026-05-20T03:09:05.404ZMay 20 03:09:05.380 DEBG [sc] cr2: connecting to [::1]:46047
6762026-05-20T03:09:05.437ZMay 20 03:09:05.381 DEBG [sc] cr2 waiting for prompt
6772026-05-20T03:09:05.437ZMay 20 03:09:05.391 DEBG [sc] cr2: logging in
6782026-05-20T03:09:05.530ZMay 20 03:09:05.513 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6792026-05-20T03:09:06.151ZMay 20 03:09:06.130 DEBG [sc] cr1: starting
6802026-05-20T03:09:06.151ZMay 20 03:09:06.130 DEBG [sc] cr1: connecting to [::1]:54296
6812026-05-20T03:09:06.185ZMay 20 03:09:06.130 DEBG [sc] cr1 waiting for prompt
6822026-05-20T03:09:06.185ZMay 20 03:09:06.141 DEBG [sc] cr1: logging in
6832026-05-20T03:09:06.295ZMay 20 03:09:06.273 DEBG [sc] cr1: executing command `systemctl restart frr`
6842026-05-20T03:09:07.647ZMay 20 03:09:07.632 INFO cr2: executing eos script show version
6852026-05-20T03:09:07.647ZMay 20 03:09:07.632 DEBG [sc] cr2: starting
6862026-05-20T03:09:07.647ZMay 20 03:09:07.632 DEBG [sc] cr2: connecting to [::1]:46047
6872026-05-20T03:09:07.680ZMay 20 03:09:07.632 DEBG [sc] cr2 waiting for prompt
6882026-05-20T03:09:07.680ZMay 20 03:09:07.642 DEBG [sc] cr2: logging in
6892026-05-20T03:09:07.814ZMay 20 03:09:07.797 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6902026-05-20T03:09:10.173ZMay 20 03:09:10.146 INFO cr2: executing eos script
6912026-05-20T03:09:10.173Z enable
6922026-05-20T03:09:10.173Z configure
6932026-05-20T03:09:10.173Z ip routing
6942026-05-20T03:09:10.173Z ipv6 unicast-routing
6952026-05-20T03:09:10.174Z interface Ethernet1
6962026-05-20T03:09:10.174Z no switchport
6972026-05-20T03:09:10.174Z ip address 10.0.1.2/24
6982026-05-20T03:09:10.174Z ipv6 enable
6992026-05-20T03:09:10.174Z ipv6 address fd00:2::2/64
7002026-05-20T03:09:10.174Z bfd interval 300 min-rx 300 multiplier 3
7012026-05-20T03:09:10.174Z exit
7022026-05-20T03:09:10.174Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7032026-05-20T03:09:10.174Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7042026-05-20T03:09:10.174Z exit
7052026-05-20T03:09:10.174Z
7062026-05-20T03:09:10.174ZMay 20 03:09:10.146 DEBG [sc] cr2: starting
7072026-05-20T03:09:10.174ZMay 20 03:09:10.146 DEBG [sc] cr2: connecting to [::1]:46047
7082026-05-20T03:09:10.207ZMay 20 03:09:10.147 DEBG [sc] cr2 waiting for prompt
7092026-05-20T03:09:10.207ZMay 20 03:09:10.157 DEBG [sc] cr2: logging in
7102026-05-20T03:09:10.345ZMay 20 03:09:10.322 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
7112026-05-20T03:09:10.345Z enable
7122026-05-20T03:09:10.346Z configure
7132026-05-20T03:09:10.346Z ip routing
7142026-05-20T03:09:10.346Z ipv6 unicast-routing
7152026-05-20T03:09:10.346Z interface Ethernet1
7162026-05-20T03:09:10.346Z no switchport
7172026-05-20T03:09:10.346Z ip address 10.0.1.2/24
7182026-05-20T03:09:10.346Z ipv6 enable
7192026-05-20T03:09:10.346Z ipv6 address fd00:2::2/64
7202026-05-20T03:09:10.346Z bfd interval 300 min-rx 300 multiplier 3
7212026-05-20T03:09:10.346Z exit
7222026-05-20T03:09:10.346Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7232026-05-20T03:09:10.346Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7242026-05-20T03:09:10.346Z exit
7252026-05-20T03:09:10.346Z '`
7262026-05-20T03:09:13.894ZMay 20 03:09:13.869 INFO cr1: executing frr script
7272026-05-20T03:09:13.894Z configure
7282026-05-20T03:09:13.894Z interface enp0s8
7292026-05-20T03:09:13.894Z ip address 10.0.0.2/24
7302026-05-20T03:09:13.894Z ipv6 address fd00:1::2/64
7312026-05-20T03:09:13.894Z no shutdown
7322026-05-20T03:09:13.894Z exit
7332026-05-20T03:09:13.894Z bfd
7342026-05-20T03:09:13.894Z peer 10.0.0.1 local-address 10.0.0.2
7352026-05-20T03:09:13.894Z detect-multiplier 3
7362026-05-20T03:09:13.894Z receive-interval 300
7372026-05-20T03:09:13.894Z transmit-interval 300
7382026-05-20T03:09:13.894Z no shutdown
7392026-05-20T03:09:13.894Z exit
7402026-05-20T03:09:13.894Z peer fd00:1::1 local-address fd00:1::2
7412026-05-20T03:09:13.894Z detect-multiplier 3
7422026-05-20T03:09:13.894Z receive-interval 300
7432026-05-20T03:09:13.894Z transmit-interval 300
7442026-05-20T03:09:13.894Z no shutdown
7452026-05-20T03:09:13.894Z exit
7462026-05-20T03:09:13.894Z exit
7472026-05-20T03:09:13.894Z
7482026-05-20T03:09:13.926ZMay 20 03:09:13.869 DEBG [sc] cr1: starting
7492026-05-20T03:09:13.926ZMay 20 03:09:13.869 DEBG [sc] cr1: connecting to [::1]:54296
7502026-05-20T03:09:13.926ZMay 20 03:09:13.869 DEBG [sc] cr1 waiting for prompt
7512026-05-20T03:09:13.926ZMay 20 03:09:13.881 DEBG [sc] cr1: logging in
7522026-05-20T03:09:14.046ZMay 20 03:09:14.023 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-20T03:11:08.645ZMay 20 03:11:08.629 DEBG [sc] ox: starting
7542026-05-20T03:11:08.645ZMay 20 03:11:08.629 DEBG [sc] ox: connecting to [::1]:43630
7552026-05-20T03:11:08.677ZMay 20 03:11:08.630 DEBG [sc] ox waiting for prompt
7562026-05-20T03:11:08.677ZMay 20 03:11:08.640 DEBG [sc] ox: logging in
7572026-05-20T03:11:08.743ZMay 20 03:11:08.728 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
7582026-05-20T03:11:09.011ZMay 20 03:11:08.993 DEBG [sc] ox: starting
7592026-05-20T03:11:09.011ZMay 20 03:11:08.993 DEBG [sc] ox: connecting to [::1]:43630
7602026-05-20T03:11:09.043ZMay 20 03:11:08.994 DEBG [sc] ox waiting for prompt
7612026-05-20T03:11:09.043ZMay 20 03:11:09.005 DEBG [sc] ox: logging in
7622026-05-20T03:11:09.099ZMay 20 03:11:09.083 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7632026-05-20T03:11:10.124ZMay 20 03:11:10.106 DEBG [sc] ox: starting
7642026-05-20T03:11:10.124ZMay 20 03:11:10.106 DEBG [sc] ox: connecting to [::1]:43630
7652026-05-20T03:11:10.162ZMay 20 03:11:10.107 DEBG [sc] ox waiting for prompt
7662026-05-20T03:11:10.162ZMay 20 03:11:10.107 DEBG [sc] ox: logging in
7672026-05-20T03:11:10.199ZMay 20 03:11:10.184 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7682026-05-20T03:11:10.256ZMay 20 03:11:10.239 DEBG [sc] ox: starting
7692026-05-20T03:11:10.256ZMay 20 03:11:10.240 DEBG [sc] ox: connecting to [::1]:43630
7702026-05-20T03:11:10.290ZMay 20 03:11:10.241 DEBG [sc] ox waiting for prompt
7712026-05-20T03:11:10.290ZMay 20 03:11:10.251 DEBG [sc] ox: logging in
7722026-05-20T03:11:10.345ZMay 20 03:11:10.329 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7732026-05-20T03:11:10.739ZMay 20 03:11:10.718 DEBG [sc] ox: starting
7742026-05-20T03:11:10.739ZMay 20 03:11:10.718 DEBG [sc] ox: connecting to [::1]:43630
7752026-05-20T03:11:10.772ZMay 20 03:11:10.719 DEBG [sc] ox waiting for prompt
7762026-05-20T03:11:10.772ZMay 20 03:11:10.730 DEBG [sc] ox: logging in
7772026-05-20T03:11:10.824ZMay 20 03:11:10.807 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
7782026-05-20T03:11:10.885ZMay 20 03:11:10.863 DEBG [sc] ox: starting
7792026-05-20T03:11:10.885ZMay 20 03:11:10.863 DEBG [sc] ox: connecting to [::1]:43630
7802026-05-20T03:11:10.917ZMay 20 03:11:10.864 DEBG [sc] ox waiting for prompt
7812026-05-20T03:11:10.917ZMay 20 03:11:10.874 DEBG [sc] ox: logging in
7822026-05-20T03:11:10.965ZMay 20 03:11:10.951 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
7832026-05-20T03:11:11.040ZMay 20 03:11:11.018 DEBG [sc] ox: starting
7842026-05-20T03:11:11.040ZMay 20 03:11:11.018 DEBG [sc] ox: connecting to [::1]:43630
7852026-05-20T03:11:11.074ZMay 20 03:11:11.019 DEBG [sc] ox waiting for prompt
7862026-05-20T03:11:11.074ZMay 20 03:11:11.028 DEBG [sc] ox: logging in
7872026-05-20T03:11:11.120ZMay 20 03:11:11.105 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.0.1/24 tfportqsfp0_0/v4`
7882026-05-20T03:11:11.833ZMay 20 03:11:11.818 DEBG [sc] ox: starting
7892026-05-20T03:11:11.833ZMay 20 03:11:11.818 DEBG [sc] ox: connecting to [::1]:43630
7902026-05-20T03:11:11.864ZMay 20 03:11:11.819 DEBG [sc] ox waiting for prompt
7912026-05-20T03:11:11.864ZMay 20 03:11:11.829 DEBG [sc] ox: logging in
7922026-05-20T03:11:11.923ZMay 20 03:11:11.906 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v4 -p -o addr`
7932026-05-20T03:11:11.992ZMay 20 03:11:11.973 DEBG [sc] ox: starting
7942026-05-20T03:11:11.992ZMay 20 03:11:11.973 DEBG [sc] ox: connecting to [::1]:43630
7952026-05-20T03:11:12.026ZMay 20 03:11:11.974 DEBG [sc] ox waiting for prompt
7962026-05-20T03:11:12.026ZMay 20 03:11:11.984 DEBG [sc] ox: logging in
7972026-05-20T03:11:12.079ZMay 20 03:11:12.062 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:1::1/64 tfportqsfp0_0/v6`
7982026-05-20T03:11:12.591ZMay 20 03:11:12.575 DEBG [sc] ox: starting
7992026-05-20T03:11:12.591ZMay 20 03:11:12.575 DEBG [sc] ox: connecting to [::1]:43630
8002026-05-20T03:11:12.628ZMay 20 03:11:12.576 DEBG [sc] ox waiting for prompt
8012026-05-20T03:11:12.628ZMay 20 03:11:12.586 DEBG [sc] ox: logging in
8022026-05-20T03:11:12.679ZMay 20 03:11:12.664 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v6 -p -o addr`
8032026-05-20T03:11:12.736ZMay 20 03:11:12.719 DEBG [sc] ox: starting
8042026-05-20T03:11:12.736ZMay 20 03:11:12.719 DEBG [sc] ox: connecting to [::1]:43630
8052026-05-20T03:11:12.772ZMay 20 03:11:12.720 DEBG [sc] ox waiting for prompt
8062026-05-20T03:11:12.772ZMay 20 03:11:12.730 DEBG [sc] ox: logging in
8072026-05-20T03:11:12.822ZMay 20 03:11:12.807 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
8082026-05-20T03:11:12.878ZMay 20 03:11:12.863 DEBG [sc] ox: starting
8092026-05-20T03:11:12.878ZMay 20 03:11:12.863 DEBG [sc] ox: connecting to [::1]:43630
8102026-05-20T03:11:12.911ZMay 20 03:11:12.864 DEBG [sc] ox waiting for prompt
8112026-05-20T03:11:12.911ZMay 20 03:11:12.874 DEBG [sc] ox: logging in
8122026-05-20T03:11:12.968ZMay 20 03:11:12.952 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
8132026-05-20T03:11:13.025ZMay 20 03:11:13.008 DEBG [sc] ox: starting
8142026-05-20T03:11:13.025ZMay 20 03:11:13.008 DEBG [sc] ox: connecting to [::1]:43630
8152026-05-20T03:11:13.059ZMay 20 03:11:13.008 DEBG [sc] ox waiting for prompt
8162026-05-20T03:11:13.059ZMay 20 03:11:13.019 DEBG [sc] ox: logging in
8172026-05-20T03:11:13.112ZMay 20 03:11:13.096 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.1.1/24 tfportqsfp1_0/v4`
8182026-05-20T03:11:13.735ZMay 20 03:11:13.716 DEBG [sc] ox: starting
8192026-05-20T03:11:13.735ZMay 20 03:11:13.716 DEBG [sc] ox: connecting to [::1]:43630
8202026-05-20T03:11:13.769ZMay 20 03:11:13.717 DEBG [sc] ox waiting for prompt
8212026-05-20T03:11:13.769ZMay 20 03:11:13.726 DEBG [sc] ox: logging in
8222026-05-20T03:11:13.821ZMay 20 03:11:13.805 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v4 -p -o addr`
8232026-05-20T03:11:13.878ZMay 20 03:11:13.861 DEBG [sc] ox: starting
8242026-05-20T03:11:13.878ZMay 20 03:11:13.861 DEBG [sc] ox: connecting to [::1]:43630
8252026-05-20T03:11:13.911ZMay 20 03:11:13.861 DEBG [sc] ox waiting for prompt
8262026-05-20T03:11:13.911ZMay 20 03:11:13.871 DEBG [sc] ox: logging in
8272026-05-20T03:11:13.965ZMay 20 03:11:13.949 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:2::1/64 tfportqsfp1_0/v6`
8282026-05-20T03:11:14.492ZMay 20 03:11:14.472 DEBG [sc] ox: starting
8292026-05-20T03:11:14.492ZMay 20 03:11:14.472 DEBG [sc] ox: connecting to [::1]:43630
8302026-05-20T03:11:14.524ZMay 20 03:11:14.473 DEBG [sc] ox waiting for prompt
8312026-05-20T03:11:14.524ZMay 20 03:11:14.483 DEBG [sc] ox: logging in
8322026-05-20T03:11:14.581ZMay 20 03:11:14.560 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v6 -p -o addr`
8332026-05-20T03:11:14.631ZMay 20 03:11:14.615 DEBG [sc] ox: starting
8342026-05-20T03:11:14.631ZMay 20 03:11:14.615 DEBG [sc] ox: connecting to [::1]:43630
8352026-05-20T03:11:14.664ZMay 20 03:11:14.616 DEBG [sc] ox waiting for prompt
8362026-05-20T03:11:14.664ZMay 20 03:11:14.625 DEBG [sc] ox: logging in
8372026-05-20T03:11:14.725ZMay 20 03:11:14.703 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
8382026-05-20T03:11:14.780ZMay 20 03:11:14.759 DEBG [sc] ox: starting
8392026-05-20T03:11:14.780ZMay 20 03:11:14.759 DEBG [sc] ox: connecting to [::1]:43630
8402026-05-20T03:11:14.814ZMay 20 03:11:14.759 DEBG [sc] ox waiting for prompt
8412026-05-20T03:11:14.814ZMay 20 03:11:14.770 DEBG [sc] ox: logging in
8422026-05-20T03:11:14.867ZMay 20 03:11:14.848 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
8432026-05-20T03:11:14.935ZMay 20 03:11:14.919 INFO installing static v4 route 192.168.100.0/24
8442026-05-20T03:11:14.969ZMay 20 03:11:14.920 INFO installing static v6 route fd01::/64
8452026-05-20T03:11:14.969ZMay 20 03:11:14.920 INFO adding BFD peers for cr1 and cr2 (dual-stack)
8462026-05-20T03:11:14.969ZMay 20 03:11:14.923 INFO phase 1: both peers up
8472026-05-20T03:11:15.942ZMay 20 03:11:15.926 INFO cr1: executing frr script show bfd peers json
8482026-05-20T03:11:15.942ZMay 20 03:11:15.926 DEBG [sc] cr1: starting
8492026-05-20T03:11:15.942ZMay 20 03:11:15.926 DEBG [sc] cr1: connecting to [::1]:54296
8502026-05-20T03:11:15.976ZMay 20 03:11:15.927 DEBG [sc] cr1 waiting for prompt
8512026-05-20T03:11:15.976ZMay 20 03:11:15.939 DEBG [sc] cr1: logging in
8522026-05-20T03:11:16.311ZMay 20 03:11:16.296 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8532026-05-20T03:11:18.458ZMay 20 03:11:18.437 INFO cr1: executing frr script show bfd peers json
8542026-05-20T03:11:18.458ZMay 20 03:11:18.438 DEBG [sc] cr1: starting
8552026-05-20T03:11:18.458ZMay 20 03:11:18.438 DEBG [sc] cr1: connecting to [::1]:54296
8562026-05-20T03:11:18.488ZMay 20 03:11:18.438 DEBG [sc] cr1 waiting for prompt
8572026-05-20T03:11:18.488ZMay 20 03:11:18.449 DEBG [sc] cr1: logging in
8582026-05-20T03:11:18.589ZMay 20 03:11:18.569 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8592026-05-20T03:11:20.728ZMay 20 03:11:20.710 INFO cr2: executing eos script show bfd peers | json
8602026-05-20T03:11:20.728ZMay 20 03:11:20.710 DEBG [sc] cr2: starting
8612026-05-20T03:11:20.728ZMay 20 03:11:20.710 DEBG [sc] cr2: connecting to [::1]:46047
8622026-05-20T03:11:20.760ZMay 20 03:11:20.711 DEBG [sc] cr2 waiting for prompt
8632026-05-20T03:11:20.760ZMay 20 03:11:20.723 DEBG [sc] cr2: logging in
8642026-05-20T03:11:21.080ZMay 20 03:11:21.059 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8652026-05-20T03:11:23.453ZMay 20 03:11:23.432 INFO cr2: executing eos script show bfd peers | json
8662026-05-20T03:11:23.453ZMay 20 03:11:23.432 DEBG [sc] cr2: starting
8672026-05-20T03:11:23.453ZMay 20 03:11:23.432 DEBG [sc] cr2: connecting to [::1]:46047
8682026-05-20T03:11:23.485ZMay 20 03:11:23.433 DEBG [sc] cr2 waiting for prompt
8692026-05-20T03:11:23.486ZMay 20 03:11:23.443 DEBG [sc] cr2: logging in
8702026-05-20T03:11:23.591ZMay 20 03:11:23.574 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8712026-05-20T03:11:25.969ZMay 20 03:11:25.948 INFO phase 2: pause bfdd on cr1
8722026-05-20T03:11:25.969ZMay 20 03:11:25.948 INFO cr1: pausing frr bfdd
8732026-05-20T03:11:25.969ZMay 20 03:11:25.948 DEBG [sc] cr1: starting
8742026-05-20T03:11:25.969ZMay 20 03:11:25.948 DEBG [sc] cr1: connecting to [::1]:54296
8752026-05-20T03:11:26.002ZMay 20 03:11:25.949 DEBG [sc] cr1 waiting for prompt
8762026-05-20T03:11:26.002ZMay 20 03:11:25.960 DEBG [sc] cr1: logging in
8772026-05-20T03:11:26.096ZMay 20 03:11:26.081 DEBG [sc] cr1: executing command `pkill -STOP bfdd`
8782026-05-20T03:11:28.184ZMay 20 03:11:28.167 INFO cr2: executing eos script show bfd peers | json
8792026-05-20T03:11:28.184ZMay 20 03:11:28.167 DEBG [sc] cr2: starting
8802026-05-20T03:11:28.184ZMay 20 03:11:28.167 DEBG [sc] cr2: connecting to [::1]:46047
8812026-05-20T03:11:28.220ZMay 20 03:11:28.168 DEBG [sc] cr2 waiting for prompt
8822026-05-20T03:11:28.220ZMay 20 03:11:28.179 DEBG [sc] cr2: logging in
8832026-05-20T03:11:28.330ZMay 20 03:11:28.312 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8842026-05-20T03:11:30.804ZMay 20 03:11:30.655 INFO cr2: executing eos script show bfd peers | json
8852026-05-20T03:11:30.804ZMay 20 03:11:30.655 DEBG [sc] cr2: starting
8862026-05-20T03:11:30.804ZMay 20 03:11:30.655 DEBG [sc] cr2: connecting to [::1]:46047
8872026-05-20T03:11:30.842ZMay 20 03:11:30.656 DEBG [sc] cr2 waiting for prompt
8882026-05-20T03:11:30.842ZMay 20 03:11:30.666 DEBG [sc] cr2: logging in
8892026-05-20T03:11:30.842ZMay 20 03:11:30.799 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8902026-05-20T03:11:33.171ZMay 20 03:11:33.126 INFO phase 3: pause ceos on cr2
8912026-05-20T03:11:33.172ZMay 20 03:11:33.126 INFO cr2: pausing ceos
8922026-05-20T03:11:33.172ZMay 20 03:11:33.126 DEBG [sc] cr2: starting
8932026-05-20T03:11:33.172ZMay 20 03:11:33.126 DEBG [sc] cr2: connecting to [::1]:46047
8942026-05-20T03:11:33.172ZMay 20 03:11:33.127 DEBG [sc] cr2 waiting for prompt
8952026-05-20T03:11:33.172ZMay 20 03:11:33.136 DEBG [sc] cr2: logging in
8962026-05-20T03:11:34.554ZMay 20 03:11:33.267 DEBG [sc] cr2: executing command `docker pause ceos`
8972026-05-20T03:11:35.405ZMay 20 03:11:35.389 INFO phase 4: resume bfdd on cr1
8982026-05-20T03:11:35.405ZMay 20 03:11:35.389 INFO cr1: resuming frr bfdd
8992026-05-20T03:11:35.405ZMay 20 03:11:35.390 DEBG [sc] cr1: starting
9002026-05-20T03:11:35.405ZMay 20 03:11:35.390 DEBG [sc] cr1: connecting to [::1]:54296
9012026-05-20T03:11:36.077ZMay 20 03:11:35.390 DEBG [sc] cr1 waiting for prompt
9022026-05-20T03:11:36.077ZMay 20 03:11:35.402 DEBG [sc] cr1: logging in
9032026-05-20T03:11:36.108ZMay 20 03:11:35.534 DEBG [sc] cr1: executing command `pkill -CONT bfdd`
9042026-05-20T03:11:37.635ZMay 20 03:11:37.620 INFO cr1: executing frr script show bfd peers json
9052026-05-20T03:11:37.635ZMay 20 03:11:37.620 DEBG [sc] cr1: starting
9062026-05-20T03:11:37.635ZMay 20 03:11:37.620 DEBG [sc] cr1: connecting to [::1]:54296
9072026-05-20T03:11:37.667ZMay 20 03:11:37.621 DEBG [sc] cr1 waiting for prompt
9082026-05-20T03:11:37.667ZMay 20 03:11:37.629 DEBG [sc] cr1: logging in
9092026-05-20T03:11:37.780ZMay 20 03:11:37.762 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9102026-05-20T03:11:39.921ZMay 20 03:11:39.905 INFO cr1: executing frr script show bfd peers json
9112026-05-20T03:11:39.921ZMay 20 03:11:39.906 DEBG [sc] cr1: starting
9122026-05-20T03:11:39.921ZMay 20 03:11:39.906 DEBG [sc] cr1: connecting to [::1]:54296
9132026-05-20T03:11:39.953ZMay 20 03:11:39.906 DEBG [sc] cr1 waiting for prompt
9142026-05-20T03:11:39.953ZMay 20 03:11:39.917 DEBG [sc] cr1: logging in
9152026-05-20T03:11:40.059ZMay 20 03:11:40.038 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9162026-05-20T03:11:42.194ZMay 20 03:11:42.178 INFO phase 5: unpause ceos on cr2
9172026-05-20T03:11:42.194ZMay 20 03:11:42.178 INFO cr2: unpausing ceos
9182026-05-20T03:11:42.194ZMay 20 03:11:42.178 DEBG [sc] cr2: starting
9192026-05-20T03:11:42.194ZMay 20 03:11:42.178 DEBG [sc] cr2: connecting to [::1]:46047
9202026-05-20T03:11:42.229ZMay 20 03:11:42.179 DEBG [sc] cr2 waiting for prompt
9212026-05-20T03:11:42.230ZMay 20 03:11:42.190 DEBG [sc] cr2: logging in
9222026-05-20T03:11:42.327ZMay 20 03:11:42.311 DEBG [sc] cr2: executing command `docker unpause ceos`
9232026-05-20T03:11:44.453ZMay 20 03:11:44.431 INFO cr1: executing frr script show bfd peers json
9242026-05-20T03:11:44.453ZMay 20 03:11:44.431 DEBG [sc] cr1: starting
9252026-05-20T03:11:44.453ZMay 20 03:11:44.431 DEBG [sc] cr1: connecting to [::1]:54296
9262026-05-20T03:11:44.497ZMay 20 03:11:44.432 DEBG [sc] cr1 waiting for prompt
9272026-05-20T03:11:44.497ZMay 20 03:11:44.442 DEBG [sc] cr1: logging in
9282026-05-20T03:11:44.581ZMay 20 03:11:44.563 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9292026-05-20T03:11:46.720ZMay 20 03:11:46.702 INFO cr1: executing frr script show bfd peers json
9302026-05-20T03:11:46.720ZMay 20 03:11:46.702 DEBG [sc] cr1: starting
9312026-05-20T03:11:46.720ZMay 20 03:11:46.702 DEBG [sc] cr1: connecting to [::1]:54296
9322026-05-20T03:11:46.752ZMay 20 03:11:46.703 DEBG [sc] cr1 waiting for prompt
9332026-05-20T03:11:46.752ZMay 20 03:11:46.713 DEBG [sc] cr1: logging in
9342026-05-20T03:11:46.867ZMay 20 03:11:46.846 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9352026-05-20T03:11:49.003ZMay 20 03:11:48.987 INFO cr2: executing eos script show bfd peers | json
9362026-05-20T03:11:49.003ZMay 20 03:11:48.987 DEBG [sc] cr2: starting
9372026-05-20T03:11:49.003ZMay 20 03:11:48.987 DEBG [sc] cr2: connecting to [::1]:46047
9382026-05-20T03:11:49.037ZMay 20 03:11:48.988 DEBG [sc] cr2 waiting for prompt
9392026-05-20T03:11:49.037ZMay 20 03:11:48.998 DEBG [sc] cr2: logging in
9402026-05-20T03:11:49.150ZMay 20 03:11:49.131 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9412026-05-20T03:11:51.624ZMay 20 03:11:51.530 INFO cr2: executing eos script show bfd peers | json
9422026-05-20T03:11:51.742ZMay 20 03:11:51.530 DEBG [sc] cr2: starting
9432026-05-20T03:11:51.742ZMay 20 03:11:51.530 DEBG [sc] cr2: connecting to [::1]:46047
9442026-05-20T03:11:51.742ZMay 20 03:11:51.531 DEBG [sc] cr2 waiting for prompt
9452026-05-20T03:11:51.742ZMay 20 03:11:51.541 DEBG [sc] cr2: logging in
9462026-05-20T03:11:51.854ZMay 20 03:11:51.663 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9472026-05-20T03:11:54.122ZMay 20 03:11:54.009 INFO trio bfd static routing test passed 🎉
9482026-05-20T03:11:54.122ZMay 20 03:11:54.009 INFO destroying runner for deployment mgtriobfd
9492026-05-20T03:11:54.122ZMay 20 03:11:54.009 INFO destroying deployment mgtriobfd
9502026-05-20T03:11:54.122ZMay 20 03:11:54.009 INFO destroying nodes
9512026-05-20T03:11:54.255ZMay 20 03:11:54.112 INFO destroying links
9522026-05-20T03:11:54.255ZMay 20 03:11:54.113 INFO destroying link mgtriobfd_ox_sn_vnic0
9532026-05-20T03:11:54.255ZMay 20 03:11:54.114 INFO destroying link mgtriobfd_ox_sn_sim0
9542026-05-20T03:11:54.255ZMay 20 03:11:54.116 INFO destroying link mgtriobfd_cr1_vn_vnic0
9552026-05-20T03:11:55.134ZMay 20 03:11:55.119 INFO destroying link mgtriobfd_cr1_vn_sim0
9562026-05-20T03:11:55.169ZMay 20 03:11:55.120 INFO destroying link mgtriobfd_ox_sn_vnic1
9572026-05-20T03:11:55.169ZMay 20 03:11:55.121 INFO destroying link mgtriobfd_ox_sn_sim1
9582026-05-20T03:11:55.169ZMay 20 03:11:55.122 INFO destroying link mgtriobfd_cr2_vn_vnic0
9592026-05-20T03:11:55.169ZMay 20 03:11:55.123 INFO destroying link mgtriobfd_cr2_vn_sim0
9602026-05-20T03:11:55.169ZMay 20 03:11:55.124 INFO destroying external links
9612026-05-20T03:11:55.169ZMay 20 03:11:55.124 INFO destroying external link mgtriobfd_ox_vn_vnic2
9622026-05-20T03:11:55.169ZMay 20 03:11:55.125 INFO destroying external link mgtriobfd_cr1_vn_vnic1
9632026-05-20T03:11:55.169ZMay 20 03:11:55.126 INFO destroying external link mgtriobfd_cr2_vn_vnic1
9642026-05-20T03:11:55.169ZMay 20 03:11:55.127 INFO destroying images
9652026-05-20T03:11:55.627ZMay 20 03:11:55.609 INFO destroying workspace at .falcon
9662026-05-20T03:11:55.660Zprocess exited: duration 829130 ms, exit code 0
 
9672026-05-20T03:11:55.730Zfound 0 output files