01KR2HHTAG1DV7J31341DY64RK: falcon

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

Buildomat Job: 01KR2HJAK7Q6SY549ENRTD8ZSD

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-05-08T01:13:39.371Zjob dependencies complete; ready to run (waiting for 13 m 43 s)
22026-05-08T01:16:54.997Zjob assigned to worker 01KR2JBF2J1A00YVBP8JN8HYDV [factory edgar, gimlet/BRM42220010/940] (queued for 3 m 15 s)
32026-05-08T01:16:55.581Zdownloading input: /input/build/work/debug/ddmadm
42026-05-08T01:17:18.463Zdownloaded input: /input/build/work/debug/ddmadm
52026-05-08T01:17:18.463Zdownloading input: /input/build/work/debug/ddmd
62026-05-08T01:17:45.900Zdownloaded input: /input/build/work/debug/ddmd
72026-05-08T01:17:45.924Zdownloading input: /input/build-interop/work/testbed.tar.gz
82026-05-08T01:17:54.927Zdownloaded input: /input/build-interop/work/testbed.tar.gz
92026-05-08T01:17:54.927Zdownloading input: /input/build/work/debug/mgadm
102026-05-08T01:18:22.356Zdownloaded input: /input/build/work/debug/mgadm
112026-05-08T01:18:22.356Zdownloading input: /input/build-interop/work/dhcp-server
122026-05-08T01:18:24.750Zdownloaded input: /input/build-interop/work/dhcp-server
132026-05-08T01:18:24.774Zdownloading input: /input/build/work/debug/mgd
142026-05-08T01:18:57.629Zdownloaded input: /input/build/work/debug/mgd
152026-05-08T01:18:57.659Zdownloading input: /input/build/work/release/ddmadm
162026-05-08T01:18:59.730Zdownloaded input: /input/build/work/release/ddmadm
172026-05-08T01:18:59.730Zdownloading input: /input/build/work/release/ddmd
182026-05-08T01:19:08.164Zdownloaded input: /input/build/work/release/ddmd
192026-05-08T01:19:08.188Zdownloading input: /input/build/work/release/falcon-lab
202026-05-08T01:19:10.086Zdownloaded input: /input/build/work/release/falcon-lab
212026-05-08T01:19:10.086Zdownloading input: /input/build/work/release/mgadm
222026-05-08T01:19:12.786Zdownloaded input: /input/build/work/release/mgadm
232026-05-08T01:19:12.786Zdownloading input: /input/build/work/release/mgd
242026-05-08T01:19:16.342Zdownloaded input: /input/build/work/release/mgd
 
252026-05-08T01:19:16.342Zstarting task 0: "setup"
262026-05-08T01:19:16.367Z++ uname -s
272026-05-08T01:19:16.367Z+ kern=SunOS
282026-05-08T01:19:16.367Z+ build_user=build
292026-05-08T01:19:16.367Z+ build_uid=12345
302026-05-08T01:19:16.367Z+ work_dir=/work
312026-05-08T01:19:16.368Z+ input_dir=/input
322026-05-08T01:19:16.368Z+ [[ 0 == 12345 ]]
332026-05-08T01:19:16.368Z+ case "$kern" in
342026-05-08T01:19:16.368Z+ groupadd -g 12345 build
352026-05-08T01:19:16.392Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-05-08T01:19:18.377Z+ zfs create -o mountpoint=/work rpool/work
372026-05-08T01:19:19.116Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-05-08T01:19:19.141Z+ home_fs=
392026-05-08T01:19:19.142Z+ [[ '' == autofs ]]
402026-05-08T01:19:19.142Z+ mkdir -p /home/build
412026-05-08T01:19:19.142Z+ chown build:build /home/build /work
422026-05-08T01:19:20.131Z+ chmod 0700 /home/build /work
432026-05-08T01:19:20.155Zprocess exited: duration 3791 ms, exit code 0
 
442026-05-08T01:19:20.205Zstarting task 1: "authentication"
452026-05-08T01:19:20.304Zprocess exited: duration 97 ms, exit code 0
 
462026-05-08T01:19:20.353Zstarting task 2: "build"
472026-05-08T01:19:20.378Z+ set -e
482026-05-08T01:19:20.378Z+ banner zpool
492026-05-08T01:19:20.378Z
502026-05-08T01:19:20.378Z ###### ##### #### #### #
512026-05-08T01:19:20.378Z # # # # # # # #
522026-05-08T01:19:20.378Z # # # # # # # #
532026-05-08T01:19:20.378Z # ##### # # # # #
542026-05-08T01:19:20.378Z # # # # # # #
552026-05-08T01:19:20.378Z ###### # #### #### ######
562026-05-08T01:19:20.378Z
572026-05-08T01:19:20.378Z++ pfexec diskinfo -pH
582026-05-08T01:19:20.403Z++ sort -k8 -n -r
592026-05-08T01:19:20.403Z++ head -1
602026-05-08T01:19:20.403Z++ awk '{print $2}'
612026-05-08T01:19:20.428Z+ DISK=c9t0014EE81000BC3B1d0
622026-05-08T01:19:20.428Z+ export DISK
632026-05-08T01:19:20.428Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC3B1d0
642026-05-08T01:19:20.493Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-05-08T01:19:20.520Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-05-08T01:19:20.632Z+ [[ true =~ true ]]
672026-05-08T01:19:20.658Z+ pfexec zpool trim cpool
682026-05-08T01:19:20.658Z++ zpool status -t cpool
692026-05-08T01:19:20.682Z+ [[ ! pool: cpool
702026-05-08T01:19:20.682Z state: ONLINE
712026-05-08T01:19:20.682Z scan: none requested
722026-05-08T01:19:20.682Zconfig:
732026-05-08T01:19:20.682Z
742026-05-08T01:19:20.682Z NAME STATE READ WRITE CKSUM
752026-05-08T01:19:20.682Z cpool ONLINE 0 0 0
762026-05-08T01:19:20.682Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at May 8, 2026 at 01:19:20 AM UTC)
772026-05-08T01:19:20.682Z
782026-05-08T01:19:20.682Zerrors: No known data errors =~ 100% ]]
792026-05-08T01:19:20.682Z+ sleep 10
802026-05-08T01:19:30.667Z++ zpool status -t cpool
812026-05-08T01:19:30.691Z+ [[ ! pool: cpool
822026-05-08T01:19:30.691Z state: ONLINE
832026-05-08T01:19:30.691Z scan: none requested
842026-05-08T01:19:30.691Zconfig:
852026-05-08T01:19:30.691Z
862026-05-08T01:19:30.691Z NAME STATE READ WRITE CKSUM
872026-05-08T01:19:30.691Z cpool ONLINE 0 0 0
882026-05-08T01:19:30.691Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (69% trimmed, started at May 8, 2026 at 01:19:20 AM UTC)
892026-05-08T01:19:30.691Z
902026-05-08T01:19:30.691Zerrors: No known data errors =~ 100% ]]
912026-05-08T01:19:30.691Z+ sleep 10
922026-05-08T01:19:40.682Z++ zpool status -t cpool
932026-05-08T01:19:40.706Z+ [[ ! pool: cpool
942026-05-08T01:19:40.706Z state: ONLINE
952026-05-08T01:19:40.706Z scan: none requested
962026-05-08T01:19:40.706Zconfig:
972026-05-08T01:19:40.706Z
982026-05-08T01:19:40.706Z NAME STATE READ WRITE CKSUM
992026-05-08T01:19:40.706Z cpool ONLINE 0 0 0
1002026-05-08T01:19:40.706Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at May 8, 2026 at 01:19:35 AM UTC)
1012026-05-08T01:19:40.706Z
1022026-05-08T01:19:40.706Zerrors: No known data errors =~ 100% ]]
1032026-05-08T01:19:40.706Z+ pfexec chown 12345 /ci
1042026-05-08T01:19:40.706Z+ cd /ci
1052026-05-08T01:19:40.706Z+ export FALCON_DATASET=cpool/falcon
1062026-05-08T01:19:40.706Z+ FALCON_DATASET=cpool/falcon
1072026-05-08T01:19:40.706Z+ banner setup
1082026-05-08T01:19:40.706Z
1092026-05-08T01:19:40.706Z #### ###### ##### # # #####
1102026-05-08T01:19:40.706Z # # # # # # #
1112026-05-08T01:19:40.706Z #### ##### # # # # #
1122026-05-08T01:19:40.707Z # # # # # #####
1132026-05-08T01:19:40.707Z # # # # # # #
1142026-05-08T01:19:40.707Z #### ###### # #### #
1152026-05-08T01:19:40.707Z
1162026-05-08T01:19:40.707Z+ cp /input/build-interop/work/dhcp-server .
1172026-05-08T01:19:40.914Z+ cp /input/build/work/release/falcon-lab .
1182026-05-08T01:19:40.946Z+ cp /input/build/work/release/mgd .
1192026-05-08T01:19:41.016Z+ cp /input/build/work/release/ddmd .
1202026-05-08T01:19:41.076Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-05-08T01:19:41.100Z+ mkdir -p cargo-bay
1222026-05-08T01:19:41.100Z+ mv mgd cargo-bay/
1232026-05-08T01:19:41.100Z+ mv ddmd cargo-bay/
1242026-05-08T01:19:41.100Z+ export EXT_INTERFACE=igb0
1252026-05-08T01:19:41.100Z+ EXT_INTERFACE=igb0
1262026-05-08T01:19:41.100Z++ bmat address ls -f extra -Ho first
1272026-05-08T01:19:41.124Z+ first=10.151.6.164
1282026-05-08T01:19:41.124Z++ bmat address ls -f extra -Ho last
1292026-05-08T01:19:41.149Z+ last=10.151.6.227
1302026-05-08T01:19:41.149Z++ bmat address ls -f extra -Ho gateway
1312026-05-08T01:19:41.173Z+ gw=10.151.6.1
1322026-05-08T01:19:41.198Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-05-08T01:19:41.198Z++ sed 's#/.*##g'
1342026-05-08T01:19:41.198Z+ server=10.151.6.100
1352026-05-08T01:19:41.198Z+ RUST_LOG=debug
1362026-05-08T01:19:41.198Z+ pfexec ./falcon-lab run trio-unnumbered
1372026-05-08T01:19:41.198Z+ pfexec ./dhcp-server 10.151.6.164 10.151.6.227 10.151.6.1 10.151.6.100
1382026-05-08T01:19:41.222ZMay 08 01:19:41.188 DEBG using default route interface igb0
1392026-05-08T01:19:41.222ZMay 08 01:19:41.188 DEBG using default route interface igb0
1402026-05-08T01:19:41.222ZMay 08 01:19:41.188 DEBG using default route interface igb0
1412026-05-08T01:19:41.222ZMay 08 01:19:41.188 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1422026-05-08T01:19:41.222ZMay 08 01:19:41.188 INFO starting preflight for deployment mgtriou
1432026-05-08T01:19:41.222ZMay 08 01:19:41.188 INFO propolis-server binary not found
1442026-05-08T01:19:41.222ZMay 08 01:19:41.188 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1452026-05-08T01:19:45.081ZMay 08 01:19:45.066 INFO ovmf fd not found
1462026-05-08T01:19:45.082ZMay 08 01:19:45.066 INFO downloading ovmf
1472026-05-08T01:19:45.453ZMay 08 01:19:45.439 INFO base image for helios-2.9 does not exist, attempting to install
1482026-05-08T01:19:45.454ZMay 08 01:19:45.439 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1492026-05-08T01:20:13.693ZMay 08 01:20:13.678 INFO extracting image to /tmp/helios-2.9_0.raw
1502026-05-08T01:20:47.389ZMay 08 01:20:47.374 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1512026-05-08T01:20:47.439ZMay 08 01:20:47.424 INFO copying image data to zvol
1522026-05-08T01:21:00.134ZMay 08 01:21:00.120 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1532026-05-08T01:21:03.688ZMay 08 01:21:03.674 INFO base image for debian-13.2 does not exist, attempting to install
1542026-05-08T01:21:03.688ZMay 08 01:21:03.674 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1552026-05-08T01:21:24.494ZMay 08 01:21:24.480 INFO extracting image to /tmp/debian-13.2_0.raw
1562026-05-08T01:21:45.476ZMay 08 01:21:45.461 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1572026-05-08T01:21:45.500ZMay 08 01:21:45.486 INFO copying image data to zvol
1582026-05-08T01:21:52.175ZMay 08 01:21:52.161 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1592026-05-08T01:21:55.746ZMay 08 01:21:55.732 INFO base image for eos-4.35 does not exist, attempting to install
1602026-05-08T01:21:55.746ZMay 08 01:21:55.732 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1612026-05-08T01:22:39.473ZMay 08 01:22:39.459 INFO extracting image to /tmp/eos-4.35_0.raw
1622026-05-08T01:24:03.320ZMay 08 01:24:03.304 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1632026-05-08T01:24:03.376ZMay 08 01:24:03.331 INFO copying image data to zvol
1642026-05-08T01:24:52.156ZMay 08 01:24:52.143 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1652026-05-08T01:24:55.544ZMay 08 01:24:55.531 INFO creating links
1662026-05-08T01:24:55.544ZMay 08 01:24:55.531 DEBG destroying link mgtriou_ox_sn_vnic0
1672026-05-08T01:24:55.593ZMay 08 01:24:55.531 DEBG destroying link mgtriou_ox_sn_sim0
1682026-05-08T01:24:55.593ZMay 08 01:24:55.531 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1692026-05-08T01:24:55.593ZMay 08 01:24:55.533 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1702026-05-08T01:24:55.593ZMay 08 01:24:55.541 DEBG link pair created
1712026-05-08T01:24:55.593ZMay 08 01:24:55.541 DEBG destroying link mgtriou_cr1_vn_vnic0
1722026-05-08T01:24:55.593ZMay 08 01:24:55.541 DEBG destroying link mgtriou_cr1_vn_sim0
1732026-05-08T01:24:55.593ZMay 08 01:24:55.541 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1742026-05-08T01:24:55.593ZMay 08 01:24:55.542 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1752026-05-08T01:24:55.620ZMay 08 01:24:55.549 DEBG link pair created
1762026-05-08T01:24:55.620ZMay 08 01:24:55.549 DEBG destroying link mgtriou_ox_sn_vnic1
1772026-05-08T01:24:55.620ZMay 08 01:24:55.549 DEBG destroying link mgtriou_ox_sn_sim1
1782026-05-08T01:24:55.620ZMay 08 01:24:55.549 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1792026-05-08T01:24:55.620ZMay 08 01:24:55.551 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1802026-05-08T01:24:55.620ZMay 08 01:24:55.558 DEBG link pair created
1812026-05-08T01:24:55.620ZMay 08 01:24:55.558 DEBG destroying link mgtriou_cr2_vn_vnic0
1822026-05-08T01:24:55.620ZMay 08 01:24:55.558 DEBG destroying link mgtriou_cr2_vn_sim0
1832026-05-08T01:24:55.621ZMay 08 01:24:55.558 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1842026-05-08T01:24:55.621ZMay 08 01:24:55.559 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1852026-05-08T01:24:55.621ZMay 08 01:24:55.566 DEBG link pair created
1862026-05-08T01:24:55.621ZMay 08 01:24:55.566 INFO creating external links
1872026-05-08T01:24:55.621ZMay 08 01:24:55.566 DEBG destroying external link mgtriou_ox_vn_vnic2
1882026-05-08T01:24:55.621ZMay 08 01:24:55.566 INFO creating external link mgtriou_ox_vn_vnic2
1892026-05-08T01:24:55.621ZMay 08 01:24:55.568 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1902026-05-08T01:24:55.621ZMay 08 01:24:55.568 DEBG destroying external link mgtriou_cr1_vn_vnic1
1912026-05-08T01:24:55.621ZMay 08 01:24:55.568 INFO creating external link mgtriou_cr1_vn_vnic1
1922026-05-08T01:24:55.621ZMay 08 01:24:55.570 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1932026-05-08T01:24:55.621ZMay 08 01:24:55.570 DEBG destroying external link mgtriou_cr2_vn_vnic1
1942026-05-08T01:24:55.621ZMay 08 01:24:55.570 INFO creating external link mgtriou_cr2_vn_vnic1
1952026-05-08T01:24:55.621ZMay 08 01:24:55.571 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1962026-05-08T01:24:55.621ZMay 08 01:24:55.571 INFO creating nodes
1972026-05-08T01:24:55.621ZMay 08 01:24:55.571 INFO ox: launching node
1982026-05-08T01:24:55.621ZMay 08 01:24:55.573 INFO cr1: launching node
1992026-05-08T01:24:55.621ZMay 08 01:24:55.575 INFO cr2: launching node
2002026-05-08T01:24:55.621ZMay 08 01:24:55.588 INFO launched instance cr1 with pid 849 on port 47876
2012026-05-08T01:24:55.621ZMay 08 01:24:55.589 INFO cr1: instance ensure
2022026-05-08T01:24:55.621ZMay 08 01:24:55.589 INFO launched instance cr2 with pid 850 on port 36475
2032026-05-08T01:24:55.621ZMay 08 01:24:55.589 INFO cr2: instance ensure
2042026-05-08T01:24:55.621ZMay 08 01:24:55.589 INFO launched instance ox with pid 848 on port 57534
2052026-05-08T01:24:55.621ZMay 08 01:24:55.589 INFO ox: instance ensure
2062026-05-08T01:24:57.953ZMay 08 01:24:57.940 INFO cr2: instance run
2072026-05-08T01:24:57.986ZMay 08 01:24:57.941 DEBG [sc] cr2: starting
2082026-05-08T01:24:57.986ZMay 08 01:24:57.941 DEBG [sc] cr2: connecting to [::1]:36475
2092026-05-08T01:24:57.986ZMay 08 01:24:57.942 DEBG [sc] cr2 waiting for prompt
2102026-05-08T01:24:58.017ZMay 08 01:24:57.997 INFO cr1: instance run
2112026-05-08T01:24:58.018ZMay 08 01:24:57.998 DEBG [sc] cr1: starting
2122026-05-08T01:24:58.018ZMay 08 01:24:57.998 DEBG [sc] cr1: connecting to [::1]:47876
2132026-05-08T01:24:58.018ZMay 08 01:24:57.998 DEBG [sc] cr1 waiting for prompt
2142026-05-08T01:24:58.043ZMay 08 01:24:58.011 INFO ox: instance run
2152026-05-08T01:24:58.043ZMay 08 01:24:58.011 DEBG [sc] ox: starting
2162026-05-08T01:24:58.043ZMay 08 01:24:58.011 DEBG [sc] ox: connecting to [::1]:57534
2172026-05-08T01:24:58.043ZMay 08 01:24:58.018 DEBG [sc] ox waiting for prompt
2182026-05-08T01:25:15.136ZMay 08 01:25:15.093 DEBG [sc] cr1: logging in
2192026-05-08T01:25:15.515ZMay 08 01:25:15.494 INFO cr1: mounting /opt/cargo-bay
2202026-05-08T01:25:15.515ZMay 08 01:25:15.494 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2212026-05-08T01:25:15.551ZMay 08 01:25:15.505 DEBG [sc] cr1: executing command `cd`
2222026-05-08T01:25:15.551ZMay 08 01:25:15.516 INFO cr1: finished mounting /opt/cargo-bay
2232026-05-08T01:25:15.551ZMay 08 01:25:15.516 DEBG [sc] cr1: executing command `hostname cr1`
2242026-05-08T01:25:15.552ZMay 08 01:25:15.527 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2252026-05-08T01:25:15.610ZMay 08 01:25:15.539 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2262026-05-08T01:25:15.643ZMay 08 01:25:15.550 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2272026-05-08T01:25:15.643ZMay 08 01:25:15.561 INFO cr1: logging out
2282026-05-08T01:25:17.656ZMay 08 01:25:17.641 INFO cr1: logged out
2292026-05-08T01:25:18.634ZMay 08 01:25:18.621 DEBG [sc] ox: logging in
2302026-05-08T01:25:18.805ZMay 08 01:25:18.792 INFO ox: mounting /opt/cargo-bay
2312026-05-08T01:25:18.805ZMay 08 01:25:18.792 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2322026-05-08T01:25:19.465ZMay 08 01:25:19.452 DEBG [sc] cr2: logging in
2332026-05-08T01:25:19.859ZMay 08 01:25:19.846 INFO cr2: mounting /opt/cargo-bay
2342026-05-08T01:25:19.859ZMay 08 01:25:19.846 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2352026-05-08T01:25:19.888ZMay 08 01:25:19.857 DEBG [sc] cr2: executing command `cd`
2362026-05-08T01:25:19.889ZMay 08 01:25:19.868 INFO cr2: finished mounting /opt/cargo-bay
2372026-05-08T01:25:19.889ZMay 08 01:25:19.868 DEBG [sc] cr2: executing command `hostname cr2`
2382026-05-08T01:25:19.922ZMay 08 01:25:19.879 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2392026-05-08T01:25:19.922ZMay 08 01:25:19.890 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2402026-05-08T01:25:19.923ZMay 08 01:25:19.900 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2412026-05-08T01:25:19.963ZMay 08 01:25:19.912 INFO cr2: logging out
2422026-05-08T01:25:20.130ZMay 08 01:25:20.095 DEBG [sc] ox: executing command `cd`
2432026-05-08T01:25:20.164ZMay 08 01:25:20.106 INFO ox: finished mounting /opt/cargo-bay
2442026-05-08T01:25:20.164ZMay 08 01:25:20.106 DEBG [sc] ox: executing command `hostname ox`
2452026-05-08T01:25:20.164ZMay 08 01:25:20.118 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2462026-05-08T01:25:20.164ZMay 08 01:25:20.128 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2472026-05-08T01:25:20.164ZMay 08 01:25:20.139 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2482026-05-08T01:25:20.250ZMay 08 01:25:20.150 INFO ox: logging out
2492026-05-08T01:25:20.289ZMay 08 01:25:20.239 INFO ox: logged out
2502026-05-08T01:25:22.931ZMay 08 01:25:22.909 INFO cr2: logged out
2512026-05-08T01:25:22.974ZMay 08 01:25:22.909 DEBG [sc] ox: starting
2522026-05-08T01:25:22.974ZMay 08 01:25:22.909 DEBG [sc] ox: connecting to [::1]:57534
2532026-05-08T01:25:22.974ZMay 08 01:25:22.910 DEBG [sc] ox waiting for prompt
2542026-05-08T01:25:22.974ZMay 08 01:25:22.920 DEBG [sc] ox: logging in
2552026-05-08T01:25:23.027ZMay 08 01:25:23.009 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2562026-05-08T01:25:28.430ZMay 08 01:25:28.416 DEBG [sc] ox: starting
2572026-05-08T01:25:28.430ZMay 08 01:25:28.416 DEBG [sc] ox: connecting to [::1]:57534
2582026-05-08T01:25:28.455ZMay 08 01:25:28.416 DEBG [sc] ox waiting for prompt
2592026-05-08T01:25:28.455ZMay 08 01:25:28.427 DEBG [sc] ox: logging in
2602026-05-08T01:25:28.518ZMay 08 01:25:28.505 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2612026-05-08T01:25:28.615ZMay 08 01:25:28.593 DEBG [sc] ox: starting
2622026-05-08T01:25:28.615ZMay 08 01:25:28.593 DEBG [sc] ox: connecting to [::1]:57534
2632026-05-08T01:25:28.658ZMay 08 01:25:28.594 DEBG [sc] ox waiting for prompt
2642026-05-08T01:25:28.658ZMay 08 01:25:28.605 DEBG [sc] ox: logging in
2652026-05-08T01:25:28.706ZMay 08 01:25:28.693 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2662026-05-08T01:25:28.774ZMay 08 01:25:28.760 INFO cr1: installing frr
2672026-05-08T01:25:28.775ZMay 08 01:25:28.760 INFO waiting for ceos to initialize
2682026-05-08T01:25:28.775ZMay 08 01:25:28.760 INFO ox: setting up npuvm
2692026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] cr1: starting
2702026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] cr2: starting
2712026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] cr1: connecting to [::1]:47876
2722026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] cr2: connecting to [::1]:36475
2732026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] ox: starting
2742026-05-08T01:25:28.805ZMay 08 01:25:28.760 DEBG [sc] ox: connecting to [::1]:57534
2752026-05-08T01:25:28.805ZMay 08 01:25:28.761 DEBG [sc] ox waiting for prompt
2762026-05-08T01:25:28.805ZMay 08 01:25:28.761 DEBG [sc] cr1 waiting for prompt
2772026-05-08T01:25:28.805ZMay 08 01:25:28.761 DEBG [sc] cr2 waiting for prompt
2782026-05-08T01:25:28.805ZMay 08 01:25:28.771 DEBG [sc] ox: logging in
2792026-05-08T01:25:28.805ZMay 08 01:25:28.771 DEBG [sc] cr1: logging in
2802026-05-08T01:25:28.805ZMay 08 01:25:28.772 DEBG [sc] cr2: logging in
2812026-05-08T01:25:28.861ZMay 08 01:25:28.848 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2822026-05-08T01:25:28.928ZMay 08 01:25:28.915 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2832026-05-08T01:25:29.135ZMay 08 01:25:29.120 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2842026-05-08T01:25:31.223ZMay 08 01:25:31.206 INFO cr2: executing eos script show version
2852026-05-08T01:25:31.223ZMay 08 01:25:31.206 DEBG [sc] cr2: starting
2862026-05-08T01:25:31.223ZMay 08 01:25:31.206 DEBG [sc] cr2: connecting to [::1]:36475
2872026-05-08T01:25:31.256ZMay 08 01:25:31.206 DEBG [sc] cr2 waiting for prompt
2882026-05-08T01:25:31.256ZMay 08 01:25:31.217 DEBG [sc] cr2: logging in
2892026-05-08T01:25:31.355ZMay 08 01:25:31.338 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2902026-05-08T01:25:34.376ZMay 08 01:25:34.362 DEBG [sc] ox: starting
2912026-05-08T01:25:34.376ZMay 08 01:25:34.362 DEBG [sc] ox: connecting to [::1]:57534
2922026-05-08T01:25:34.401ZMay 08 01:25:34.363 DEBG [sc] ox waiting for prompt
2932026-05-08T01:25:34.401ZMay 08 01:25:34.373 DEBG [sc] ox: logging in
2942026-05-08T01:25:34.476ZMay 08 01:25:34.462 DEBG [sc] ox: executing command `chmod +x npuvm`
2952026-05-08T01:25:34.540ZMay 08 01:25:34.527 DEBG [sc] ox: starting
2962026-05-08T01:25:34.541ZMay 08 01:25:34.527 DEBG [sc] ox: connecting to [::1]:57534
2972026-05-08T01:25:34.565ZMay 08 01:25:34.528 DEBG [sc] ox waiting for prompt
2982026-05-08T01:25:34.565ZMay 08 01:25:34.538 DEBG [sc] ox: logging in
2992026-05-08T01:25:34.641ZMay 08 01:25:34.627 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3002026-05-08T01:25:39.983ZMay 08 01:25:39.970 DEBG [sc] cr2: starting
3012026-05-08T01:25:39.983ZMay 08 01:25:39.970 DEBG [sc] cr2: connecting to [::1]:36475
3022026-05-08T01:25:40.010ZMay 08 01:25:39.970 DEBG [sc] cr2 waiting for prompt
3032026-05-08T01:25:40.010ZMay 08 01:25:39.980 DEBG [sc] cr2: logging in
3042026-05-08T01:25:40.126ZMay 08 01:25:40.113 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3052026-05-08T01:25:42.244ZMay 08 01:25:42.225 INFO cr2: executing eos script show version
3062026-05-08T01:25:42.244ZMay 08 01:25:42.225 DEBG [sc] cr2: starting
3072026-05-08T01:25:42.245ZMay 08 01:25:42.225 DEBG [sc] cr2: connecting to [::1]:36475
3082026-05-08T01:25:42.277ZMay 08 01:25:42.225 DEBG [sc] cr2 waiting for prompt
3092026-05-08T01:25:42.277ZMay 08 01:25:42.236 DEBG [sc] cr2: logging in
3102026-05-08T01:25:42.430ZMay 08 01:25:42.412 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3112026-05-08T01:25:44.835ZMay 08 01:25:44.804 DEBG [sc] cr2: starting
3122026-05-08T01:25:44.835ZMay 08 01:25:44.804 DEBG [sc] cr2: connecting to [::1]:36475
3132026-05-08T01:25:44.868ZMay 08 01:25:44.804 DEBG [sc] cr2 waiting for prompt
3142026-05-08T01:25:44.868ZMay 08 01:25:44.814 DEBG [sc] cr2: logging in
3152026-05-08T01:25:44.962ZMay 08 01:25:44.936 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3162026-05-08T01:25:47.088ZMay 08 01:25:47.074 INFO cr2: executing eos script show version
3172026-05-08T01:25:47.088ZMay 08 01:25:47.074 DEBG [sc] cr2: starting
3182026-05-08T01:25:47.088ZMay 08 01:25:47.074 DEBG [sc] cr2: connecting to [::1]:36475
3192026-05-08T01:25:47.114ZMay 08 01:25:47.075 DEBG [sc] cr2 waiting for prompt
3202026-05-08T01:25:47.114ZMay 08 01:25:47.086 DEBG [sc] cr2: logging in
3212026-05-08T01:25:47.256ZMay 08 01:25:47.228 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3222026-05-08T01:25:49.667ZMay 08 01:25:49.654 DEBG [sc] cr2: starting
3232026-05-08T01:25:49.667ZMay 08 01:25:49.654 DEBG [sc] cr2: connecting to [::1]:36475
3242026-05-08T01:25:49.696ZMay 08 01:25:49.654 DEBG [sc] cr2 waiting for prompt
3252026-05-08T01:25:49.696ZMay 08 01:25:49.665 DEBG [sc] cr2: logging in
3262026-05-08T01:25:49.822ZMay 08 01:25:49.809 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3272026-05-08T01:25:51.920ZMay 08 01:25:51.906 INFO cr2: executing eos script show version
3282026-05-08T01:25:51.920ZMay 08 01:25:51.906 DEBG [sc] cr2: starting
3292026-05-08T01:25:51.920ZMay 08 01:25:51.906 DEBG [sc] cr2: connecting to [::1]:36475
3302026-05-08T01:25:51.944ZMay 08 01:25:51.906 DEBG [sc] cr2 waiting for prompt
3312026-05-08T01:25:51.944ZMay 08 01:25:51.916 DEBG [sc] cr2: logging in
3322026-05-08T01:25:52.073ZMay 08 01:25:52.060 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3332026-05-08T01:25:54.422ZMay 08 01:25:54.405 INFO cr2: executing eos script
3342026-05-08T01:25:54.422Z enable
3352026-05-08T01:25:54.422Z configure
3362026-05-08T01:25:54.422Z ipv6 unicast-routing
3372026-05-08T01:25:54.422Z ip routing ipv6 interfaces
3382026-05-08T01:25:54.423Z ip routing
3392026-05-08T01:25:54.423Z ip route 1.2.3.0/24 null0
3402026-05-08T01:25:54.423Z ipv6 route fd99::/64 null0
3412026-05-08T01:25:54.423Z interface et1
3422026-05-08T01:25:54.423Z no switchport
3432026-05-08T01:25:54.423Z ipv6 enable
3442026-05-08T01:25:54.423Z
3452026-05-08T01:25:54.423Z router bgp 45
3462026-05-08T01:25:54.423Z router-id 1.2.3.1
3472026-05-08T01:25:54.423Z no bgp default ipv4-unicast
3482026-05-08T01:25:54.423Z timers bgp 2 6
3492026-05-08T01:25:54.423Z neighbor ebgp peer group
3502026-05-08T01:25:54.423Z neighbor ebgp remote-as 33
3512026-05-08T01:25:54.423Z neighbor interface Et1 peer-group ebgp
3522026-05-08T01:25:54.423Z address-family ipv4
3532026-05-08T01:25:54.423Z neighbor ebgp activate
3542026-05-08T01:25:54.423Z neighbor ebgp next-hop address-family ipv6 originate
3552026-05-08T01:25:54.423Z network 1.2.3.0/24
3562026-05-08T01:25:54.423Z exit
3572026-05-08T01:25:54.423Z address-family ipv6
3582026-05-08T01:25:54.423Z neighbor ebgp activate
3592026-05-08T01:25:54.423Z neighbor ebgp next-hop address-family ipv6 originate
3602026-05-08T01:25:54.423Z network fd99::/64
3612026-05-08T01:25:54.423Z exit
3622026-05-08T01:25:54.423Z exit
3632026-05-08T01:25:54.423Z
3642026-05-08T01:25:54.423ZMay 08 01:25:54.405 DEBG [sc] cr2: starting
3652026-05-08T01:25:54.423ZMay 08 01:25:54.405 DEBG [sc] cr2: connecting to [::1]:36475
3662026-05-08T01:25:54.448ZMay 08 01:25:54.406 DEBG [sc] cr2 waiting for prompt
3672026-05-08T01:25:54.448ZMay 08 01:25:54.416 DEBG [sc] cr2: logging in
3682026-05-08T01:25:54.584ZMay 08 01:25:54.571 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3692026-05-08T01:25:54.584Z enable
3702026-05-08T01:25:54.584Z configure
3712026-05-08T01:25:54.584Z ipv6 unicast-routing
3722026-05-08T01:25:54.584Z ip routing ipv6 interfaces
3732026-05-08T01:25:54.584Z ip routing
3742026-05-08T01:25:54.584Z ip route 1.2.3.0/24 null0
3752026-05-08T01:25:54.584Z ipv6 route fd99::/64 null0
3762026-05-08T01:25:54.584Z interface et1
3772026-05-08T01:25:54.584Z no switchport
3782026-05-08T01:25:54.584Z ipv6 enable
3792026-05-08T01:25:54.584Z
3802026-05-08T01:25:54.584Z router bgp 45
3812026-05-08T01:25:54.584Z router-id 1.2.3.1
3822026-05-08T01:25:54.584Z no bgp default ipv4-unicast
3832026-05-08T01:25:54.584Z timers bgp 2 6
3842026-05-08T01:25:54.585Z neighbor ebgp peer group
3852026-05-08T01:25:54.585Z neighbor ebgp remote-as 33
3862026-05-08T01:25:54.585Z neighbor interface Et1 peer-group ebgp
3872026-05-08T01:25:54.585Z address-family ipv4
3882026-05-08T01:25:54.585Z neighbor ebgp activate
3892026-05-08T01:25:54.585Z neighbor ebgp next-hop address-family ipv6 originate
3902026-05-08T01:25:54.585Z network 1.2.3.0/24
3912026-05-08T01:25:54.585Z exit
3922026-05-08T01:25:54.585Z address-family ipv6
3932026-05-08T01:25:54.585Z neighbor ebgp activate
3942026-05-08T01:25:54.585Z neighbor ebgp next-hop address-family ipv6 originate
3952026-05-08T01:25:54.585Z network fd99::/64
3962026-05-08T01:25:54.585Z exit
3972026-05-08T01:25:54.585Z exit
3982026-05-08T01:25:54.585Z '`
3992026-05-08T01:26:06.662ZMay 08 01:26:06.649 INFO cr1: enabling frr daemon bgpd
4002026-05-08T01:26:06.662ZMay 08 01:26:06.649 DEBG [sc] cr1: starting
4012026-05-08T01:26:06.662ZMay 08 01:26:06.649 DEBG [sc] cr1: connecting to [::1]:47876
4022026-05-08T01:26:06.686ZMay 08 01:26:06.650 DEBG [sc] cr1 waiting for prompt
4032026-05-08T01:26:06.686ZMay 08 01:26:06.660 DEBG [sc] cr1: logging in
4042026-05-08T01:26:06.804ZMay 08 01:26:06.792 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
4052026-05-08T01:26:08.878ZMay 08 01:26:08.865 DEBG [sc] cr1: starting
4062026-05-08T01:26:08.878ZMay 08 01:26:08.865 DEBG [sc] cr1: connecting to [::1]:47876
4072026-05-08T01:26:08.903ZMay 08 01:26:08.865 DEBG [sc] cr1 waiting for prompt
4082026-05-08T01:26:08.903ZMay 08 01:26:08.875 DEBG [sc] cr1: logging in
4092026-05-08T01:26:09.054ZMay 08 01:26:09.041 DEBG [sc] cr1: executing command `systemctl restart frr`
4102026-05-08T01:26:16.668ZMay 08 01:26:16.655 INFO cr1: executing frr script
4112026-05-08T01:26:16.668Z configure
4122026-05-08T01:26:16.668Z ip forwarding
4132026-05-08T01:26:16.668Z ipv6 forwarding
4142026-05-08T01:26:16.668Z ip route 1.2.3.0/24 null0
4152026-05-08T01:26:16.668Z ipv6 route fd99::/64 null0
4162026-05-08T01:26:16.668Z router bgp 44
4172026-05-08T01:26:16.669Z no bgp ebgp-requires-policy
4182026-05-08T01:26:16.669Z timers bgp 2 6
4192026-05-08T01:26:16.669Z neighbor enp0s8 interface remote-as external
4202026-05-08T01:26:16.669Z neighbor enp0s8 timers connect 1
4212026-05-08T01:26:16.669Z address-family ipv4 unicast
4222026-05-08T01:26:16.669Z network 1.2.3.0/24
4232026-05-08T01:26:16.669Z neighbor enp0s8 activate
4242026-05-08T01:26:16.669Z exit-address-family
4252026-05-08T01:26:16.669Z address-family ipv6 unicast
4262026-05-08T01:26:16.669Z network fd99::/64
4272026-05-08T01:26:16.669Z neighbor enp0s8 activate
4282026-05-08T01:26:16.669Z exit-address-family
4292026-05-08T01:26:16.669Z exit
4302026-05-08T01:26:16.669Z
4312026-05-08T01:26:16.669ZMay 08 01:26:16.655 DEBG [sc] cr1: starting
4322026-05-08T01:26:16.669ZMay 08 01:26:16.655 DEBG [sc] cr1: connecting to [::1]:47876
4332026-05-08T01:26:16.694ZMay 08 01:26:16.656 DEBG [sc] cr1 waiting for prompt
4342026-05-08T01:26:16.694ZMay 08 01:26:16.667 DEBG [sc] cr1: logging in
4352026-05-08T01:26:16.812ZMay 08 01:26:16.799 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 ' '`
4362026-05-08T01:27:23.404ZMay 08 01:27:23.391 DEBG [sc] ox: starting
4372026-05-08T01:27:23.404ZMay 08 01:27:23.391 DEBG [sc] ox: connecting to [::1]:57534
4382026-05-08T01:27:23.430ZMay 08 01:27:23.391 DEBG [sc] ox waiting for prompt
4392026-05-08T01:27:23.430ZMay 08 01:27:23.401 DEBG [sc] ox: logging in
4402026-05-08T01:27:23.494ZMay 08 01:27:23.478 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4412026-05-08T01:27:24.011ZMay 08 01:27:23.998 DEBG [sc] ox: starting
4422026-05-08T01:27:24.011ZMay 08 01:27:23.998 DEBG [sc] ox: connecting to [::1]:57534
4432026-05-08T01:27:24.040ZMay 08 01:27:23.999 DEBG [sc] ox waiting for prompt
4442026-05-08T01:27:24.040ZMay 08 01:27:24.010 DEBG [sc] ox: logging in
4452026-05-08T01:27:24.102ZMay 08 01:27:24.088 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4462026-05-08T01:27:24.157ZMay 08 01:27:24.144 DEBG [sc] ox: starting
4472026-05-08T01:27:24.157ZMay 08 01:27:24.144 DEBG [sc] ox: connecting to [::1]:57534
4482026-05-08T01:27:24.184ZMay 08 01:27:24.145 DEBG [sc] ox waiting for prompt
4492026-05-08T01:27:24.184ZMay 08 01:27:24.155 DEBG [sc] ox: logging in
4502026-05-08T01:27:24.246ZMay 08 01:27:24.232 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4512026-05-08T01:27:24.301ZMay 08 01:27:24.288 DEBG [sc] ox: starting
4522026-05-08T01:27:24.301ZMay 08 01:27:24.288 DEBG [sc] ox: connecting to [::1]:57534
4532026-05-08T01:27:24.327ZMay 08 01:27:24.288 DEBG [sc] ox waiting for prompt
4542026-05-08T01:27:24.327ZMay 08 01:27:24.299 DEBG [sc] ox: logging in
4552026-05-08T01:27:24.390ZMay 08 01:27:24.375 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4562026-05-08T01:27:24.444ZMay 08 01:27:24.430 DEBG [sc] ox: starting
4572026-05-08T01:27:24.444ZMay 08 01:27:24.430 DEBG [sc] ox: connecting to [::1]:57534
4582026-05-08T01:27:24.470ZMay 08 01:27:24.431 DEBG [sc] ox waiting for prompt
4592026-05-08T01:27:24.470ZMay 08 01:27:24.442 DEBG [sc] ox: logging in
4602026-05-08T01:27:24.532ZMay 08 01:27:24.519 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4612026-05-08T01:27:24.586ZMay 08 01:27:24.573 DEBG [sc] ox: starting
4622026-05-08T01:27:24.586ZMay 08 01:27:24.573 DEBG [sc] ox: connecting to [::1]:57534
4632026-05-08T01:27:24.617ZMay 08 01:27:24.574 DEBG [sc] ox waiting for prompt
4642026-05-08T01:27:24.617ZMay 08 01:27:24.585 DEBG [sc] ox: logging in
4652026-05-08T01:27:24.676ZMay 08 01:27:24.662 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4662026-05-08T01:27:24.730ZMay 08 01:27:24.717 DEBG [sc] ox: starting
4672026-05-08T01:27:24.730ZMay 08 01:27:24.717 DEBG [sc] ox: connecting to [::1]:57534
4682026-05-08T01:27:24.757ZMay 08 01:27:24.718 DEBG [sc] ox waiting for prompt
4692026-05-08T01:27:24.757ZMay 08 01:27:24.728 DEBG [sc] ox: logging in
4702026-05-08T01:27:24.824ZMay 08 01:27:24.807 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4712026-05-08T01:27:24.876ZMay 08 01:27:24.862 DEBG [sc] ox: starting
4722026-05-08T01:27:24.876ZMay 08 01:27:24.862 DEBG [sc] ox: connecting to [::1]:57534
4732026-05-08T01:27:24.901ZMay 08 01:27:24.862 DEBG [sc] ox waiting for prompt
4742026-05-08T01:27:24.901ZMay 08 01:27:24.873 DEBG [sc] ox: logging in
4752026-05-08T01:27:25.016ZMay 08 01:27:24.952 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4762026-05-08T01:27:25.058ZMay 08 01:27:25.007 DEBG [sc] ox: starting
4772026-05-08T01:27:25.058ZMay 08 01:27:25.007 DEBG [sc] ox: connecting to [::1]:57534
4782026-05-08T01:27:25.058ZMay 08 01:27:25.008 DEBG [sc] ox waiting for prompt
4792026-05-08T01:27:25.058ZMay 08 01:27:25.017 DEBG [sc] ox: logging in
4802026-05-08T01:27:25.109ZMay 08 01:27:25.094 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4812026-05-08T01:27:25.177ZMay 08 01:27:25.164 INFO adding BGP router to mgd
4822026-05-08T01:27:27.695ZMay 08 01:27:27.682 INFO cr1: executing frr script show ip bgp json
4832026-05-08T01:27:27.695ZMay 08 01:27:27.682 DEBG [sc] cr1: starting
4842026-05-08T01:27:27.695ZMay 08 01:27:27.682 DEBG [sc] cr1: connecting to [::1]:47876
4852026-05-08T01:27:27.722ZMay 08 01:27:27.683 DEBG [sc] cr1 waiting for prompt
4862026-05-08T01:27:27.722ZMay 08 01:27:27.694 DEBG [sc] cr1: logging in
4872026-05-08T01:27:28.015ZMay 08 01:27:28.001 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4882026-05-08T01:27:30.143ZMay 08 01:27:30.130 INFO cr1: executing frr script show bgp json
4892026-05-08T01:27:30.143ZMay 08 01:27:30.130 DEBG [sc] cr1: starting
4902026-05-08T01:27:30.143ZMay 08 01:27:30.130 DEBG [sc] cr1: connecting to [::1]:47876
4912026-05-08T01:27:30.168ZMay 08 01:27:30.131 DEBG [sc] cr1 waiting for prompt
4922026-05-08T01:27:30.168ZMay 08 01:27:30.141 DEBG [sc] cr1: logging in
4932026-05-08T01:27:30.286ZMay 08 01:27:30.273 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
4942026-05-08T01:27:32.417ZMay 08 01:27:32.405 INFO cr2: executing eos script show ip bgp | json
4952026-05-08T01:27:32.417ZMay 08 01:27:32.405 DEBG [sc] cr2: starting
4962026-05-08T01:27:32.418ZMay 08 01:27:32.405 DEBG [sc] cr2: connecting to [::1]:36475
4972026-05-08T01:27:32.450ZMay 08 01:27:32.406 DEBG [sc] cr2 waiting for prompt
4982026-05-08T01:27:32.450ZMay 08 01:27:32.416 DEBG [sc] cr2: logging in
4992026-05-08T01:27:32.762ZMay 08 01:27:32.728 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
5002026-05-08T01:27:35.145ZMay 08 01:27:35.132 INFO cr2: executing eos script show ipv6 bgp | json
5012026-05-08T01:27:35.145ZMay 08 01:27:35.132 DEBG [sc] cr2: starting
5022026-05-08T01:27:35.145ZMay 08 01:27:35.132 DEBG [sc] cr2: connecting to [::1]:36475
5032026-05-08T01:27:35.177ZMay 08 01:27:35.133 DEBG [sc] cr2 waiting for prompt
5042026-05-08T01:27:35.177ZMay 08 01:27:35.144 DEBG [sc] cr2: logging in
5052026-05-08T01:27:35.299ZMay 08 01:27:35.276 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5062026-05-08T01:27:37.673ZMay 08 01:27:37.659 INFO trio bgp unnumbered test passed 🎉
5072026-05-08T01:27:37.673ZMay 08 01:27:37.660 INFO destroying runner for deployment mgtriou
5082026-05-08T01:27:37.673ZMay 08 01:27:37.660 INFO destroying deployment mgtriou
5092026-05-08T01:27:37.673ZMay 08 01:27:37.660 INFO destroying nodes
5102026-05-08T01:27:37.796ZMay 08 01:27:37.783 INFO destroying links
5112026-05-08T01:27:37.796ZMay 08 01:27:37.783 INFO destroying link mgtriou_ox_sn_vnic0
5122026-05-08T01:27:37.827ZMay 08 01:27:37.785 INFO destroying link mgtriou_ox_sn_sim0
5132026-05-08T01:27:37.827ZMay 08 01:27:37.787 INFO destroying link mgtriou_cr1_vn_vnic0
5142026-05-08T01:27:42.410ZMay 08 01:27:38.790 INFO destroying link mgtriou_cr1_vn_sim0
5152026-05-08T01:27:42.641ZMay 08 01:27:38.791 INFO destroying link mgtriou_ox_sn_vnic1
5162026-05-08T01:27:42.641ZMay 08 01:27:38.792 INFO destroying link mgtriou_ox_sn_sim1
5172026-05-08T01:27:42.641ZMay 08 01:27:38.793 INFO destroying link mgtriou_cr2_vn_vnic0
5182026-05-08T01:27:42.641ZMay 08 01:27:38.795 INFO destroying link mgtriou_cr2_vn_sim0
5192026-05-08T01:27:42.641ZMay 08 01:27:38.796 INFO destroying external links
5202026-05-08T01:27:42.641ZMay 08 01:27:38.796 INFO destroying external link mgtriou_ox_vn_vnic2
5212026-05-08T01:27:42.641ZMay 08 01:27:38.797 INFO destroying external link mgtriou_cr1_vn_vnic1
5222026-05-08T01:27:42.641ZMay 08 01:27:38.798 INFO destroying external link mgtriou_cr2_vn_vnic1
5232026-05-08T01:27:42.641ZMay 08 01:27:38.800 INFO destroying images
5242026-05-08T01:27:42.641ZMay 08 01:27:39.255 INFO destroying workspace at .falcon
5252026-05-08T01:27:42.641Z+ RUST_LOG=debug
5262026-05-08T01:27:42.641Z+ pfexec ./falcon-lab run trio-bfd-static-routing
5272026-05-08T01:27:42.641ZMay 08 01:27:39.295 DEBG using default route interface igb0
5282026-05-08T01:27:42.641ZMay 08 01:27:39.295 DEBG using default route interface igb0
5292026-05-08T01:27:42.641ZMay 08 01:27:39.295 DEBG using default route interface igb0
5302026-05-08T01:27:42.641ZMay 08 01:27:39.295 INFO launching runner: deployment(mgtriobfd) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
5312026-05-08T01:27:42.641ZMay 08 01:27:39.295 INFO starting preflight for deployment mgtriobfd
5322026-05-08T01:27:43.121ZMay 08 01:27:43.109 INFO creating links
5332026-05-08T01:27:43.122ZMay 08 01:27:43.109 DEBG destroying link mgtriobfd_ox_sn_vnic0
5342026-05-08T01:27:43.148ZMay 08 01:27:43.109 DEBG destroying link mgtriobfd_ox_sn_sim0
5352026-05-08T01:27:43.149ZMay 08 01:27:43.109 INFO creating simnet link 'mgtriobfd_ox_sn_sim0'
5362026-05-08T01:27:43.149ZMay 08 01:27:43.112 INFO creating vnic link 'mgtriobfd_ox_sn_vnic0'
5372026-05-08T01:27:43.149ZMay 08 01:27:43.119 DEBG link pair created
5382026-05-08T01:27:43.149ZMay 08 01:27:43.119 DEBG destroying link mgtriobfd_cr1_vn_vnic0
5392026-05-08T01:27:43.149ZMay 08 01:27:43.119 DEBG destroying link mgtriobfd_cr1_vn_sim0
5402026-05-08T01:27:43.149ZMay 08 01:27:43.119 INFO creating simnet link 'mgtriobfd_cr1_vn_sim0'
5412026-05-08T01:27:43.149ZMay 08 01:27:43.120 INFO creating vnic link 'mgtriobfd_cr1_vn_vnic0'
5422026-05-08T01:27:43.149ZMay 08 01:27:43.126 DEBG link pair created
5432026-05-08T01:27:43.149ZMay 08 01:27:43.126 DEBG destroying link mgtriobfd_ox_sn_vnic1
5442026-05-08T01:27:43.149ZMay 08 01:27:43.126 DEBG destroying link mgtriobfd_ox_sn_sim1
5452026-05-08T01:27:43.149ZMay 08 01:27:43.126 INFO creating simnet link 'mgtriobfd_ox_sn_sim1'
5462026-05-08T01:27:43.149ZMay 08 01:27:43.128 INFO creating vnic link 'mgtriobfd_ox_sn_vnic1'
5472026-05-08T01:27:43.174ZMay 08 01:27:43.134 DEBG link pair created
5482026-05-08T01:27:43.174ZMay 08 01:27:43.134 DEBG destroying link mgtriobfd_cr2_vn_vnic0
5492026-05-08T01:27:43.174ZMay 08 01:27:43.134 DEBG destroying link mgtriobfd_cr2_vn_sim0
5502026-05-08T01:27:43.174ZMay 08 01:27:43.134 INFO creating simnet link 'mgtriobfd_cr2_vn_sim0'
5512026-05-08T01:27:43.174ZMay 08 01:27:43.136 INFO creating vnic link 'mgtriobfd_cr2_vn_vnic0'
5522026-05-08T01:27:43.174ZMay 08 01:27:43.142 DEBG link pair created
5532026-05-08T01:27:43.174ZMay 08 01:27:43.142 INFO creating external links
5542026-05-08T01:27:43.174ZMay 08 01:27:43.142 DEBG destroying external link mgtriobfd_ox_vn_vnic2
5552026-05-08T01:27:43.174ZMay 08 01:27:43.142 INFO creating external link mgtriobfd_ox_vn_vnic2
5562026-05-08T01:27:43.174ZMay 08 01:27:43.144 DEBG external link mgtriobfd_ox_vn_vnic2@igb0 created
5572026-05-08T01:27:43.174ZMay 08 01:27:43.144 DEBG destroying external link mgtriobfd_cr1_vn_vnic1
5582026-05-08T01:27:43.174ZMay 08 01:27:43.144 INFO creating external link mgtriobfd_cr1_vn_vnic1
5592026-05-08T01:27:43.174ZMay 08 01:27:43.145 DEBG external link mgtriobfd_cr1_vn_vnic1@igb0 created
5602026-05-08T01:27:43.174ZMay 08 01:27:43.145 DEBG destroying external link mgtriobfd_cr2_vn_vnic1
5612026-05-08T01:27:43.174ZMay 08 01:27:43.145 INFO creating external link mgtriobfd_cr2_vn_vnic1
5622026-05-08T01:27:43.174ZMay 08 01:27:43.146 DEBG external link mgtriobfd_cr2_vn_vnic1@igb0 created
5632026-05-08T01:27:43.174ZMay 08 01:27:43.146 INFO creating nodes
5642026-05-08T01:27:43.174ZMay 08 01:27:43.146 INFO ox: launching node
5652026-05-08T01:27:43.174ZMay 08 01:27:43.148 INFO cr1: launching node
5662026-05-08T01:27:43.174ZMay 08 01:27:43.150 INFO cr2: launching node
5672026-05-08T01:27:43.199ZMay 08 01:27:43.164 INFO launched instance ox with pid 887 on port 37698
5682026-05-08T01:27:43.199ZMay 08 01:27:43.164 INFO ox: instance ensure
5692026-05-08T01:27:43.200ZMay 08 01:27:43.164 INFO launched instance cr1 with pid 888 on port 45002
5702026-05-08T01:27:43.200ZMay 08 01:27:43.164 INFO cr1: instance ensure
5712026-05-08T01:27:43.200ZMay 08 01:27:43.165 INFO launched instance cr2 with pid 889 on port 56975
5722026-05-08T01:27:43.200ZMay 08 01:27:43.165 INFO cr2: instance ensure
5732026-05-08T01:27:45.325ZMay 08 01:27:45.312 INFO ox: instance run
5742026-05-08T01:27:45.351ZMay 08 01:27:45.313 DEBG [sc] ox: starting
5752026-05-08T01:27:45.351ZMay 08 01:27:45.313 DEBG [sc] ox: connecting to [::1]:37698
5762026-05-08T01:27:45.352ZMay 08 01:27:45.314 DEBG [sc] ox waiting for prompt
5772026-05-08T01:27:45.377ZMay 08 01:27:45.355 INFO cr2: instance run
5782026-05-08T01:27:45.377ZMay 08 01:27:45.356 DEBG [sc] cr2: starting
5792026-05-08T01:27:45.377ZMay 08 01:27:45.356 DEBG [sc] cr2: connecting to [::1]:56975
5802026-05-08T01:27:45.377ZMay 08 01:27:45.356 DEBG [sc] cr2 waiting for prompt
5812026-05-08T01:27:45.433ZMay 08 01:27:45.420 INFO cr1: instance run
5822026-05-08T01:27:45.458ZMay 08 01:27:45.420 DEBG [sc] cr1: starting
5832026-05-08T01:27:45.458ZMay 08 01:27:45.421 DEBG [sc] cr1: connecting to [::1]:45002
5842026-05-08T01:27:45.458ZMay 08 01:27:45.421 DEBG [sc] cr1 waiting for prompt
5852026-05-08T01:28:02.501ZMay 08 01:28:02.487 DEBG [sc] cr1: logging in
5862026-05-08T01:28:02.875ZMay 08 01:28:02.861 INFO cr1: mounting /opt/cargo-bay
5872026-05-08T01:28:02.875ZMay 08 01:28:02.861 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5882026-05-08T01:28:02.899ZMay 08 01:28:02.883 DEBG [sc] cr1: executing command `cd`
5892026-05-08T01:28:02.924ZMay 08 01:28:02.893 INFO cr1: finished mounting /opt/cargo-bay
5902026-05-08T01:28:02.924ZMay 08 01:28:02.893 DEBG [sc] cr1: executing command `hostname cr1`
5912026-05-08T01:28:02.924ZMay 08 01:28:02.904 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
5922026-05-08T01:28:02.949ZMay 08 01:28:02.916 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
5932026-05-08T01:28:02.950ZMay 08 01:28:02.927 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
5942026-05-08T01:28:02.975ZMay 08 01:28:02.938 INFO cr1: logging out
5952026-05-08T01:28:05.018ZMay 08 01:28:05.006 INFO cr1: logged out
5962026-05-08T01:28:06.108ZMay 08 01:28:06.096 DEBG [sc] ox: logging in
5972026-05-08T01:28:06.273ZMay 08 01:28:06.261 INFO ox: mounting /opt/cargo-bay
5982026-05-08T01:28:06.273ZMay 08 01:28:06.261 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5992026-05-08T01:28:07.066ZMay 08 01:28:07.053 DEBG [sc] cr2: logging in
6002026-05-08T01:28:07.348ZMay 08 01:28:07.335 DEBG [sc] ox: executing command `cd`
6012026-05-08T01:28:07.373ZMay 08 01:28:07.346 INFO ox: finished mounting /opt/cargo-bay
6022026-05-08T01:28:07.373ZMay 08 01:28:07.346 DEBG [sc] ox: executing command `hostname ox`
6032026-05-08T01:28:07.373ZMay 08 01:28:07.357 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
6042026-05-08T01:28:07.397ZMay 08 01:28:07.368 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
6052026-05-08T01:28:07.397ZMay 08 01:28:07.379 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
6062026-05-08T01:28:07.422ZMay 08 01:28:07.390 INFO ox: logging out
6072026-05-08T01:28:07.480ZMay 08 01:28:07.468 INFO ox: logged out
6082026-05-08T01:28:07.544ZMay 08 01:28:07.532 INFO cr2: mounting /opt/cargo-bay
6092026-05-08T01:28:07.544ZMay 08 01:28:07.532 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6102026-05-08T01:28:07.569ZMay 08 01:28:07.554 DEBG [sc] cr2: executing command `cd`
6112026-05-08T01:28:07.593ZMay 08 01:28:07.565 INFO cr2: finished mounting /opt/cargo-bay
6122026-05-08T01:28:07.593ZMay 08 01:28:07.565 DEBG [sc] cr2: executing command `hostname cr2`
6132026-05-08T01:28:07.593ZMay 08 01:28:07.576 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
6142026-05-08T01:28:07.618ZMay 08 01:28:07.587 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
6152026-05-08T01:28:07.618ZMay 08 01:28:07.598 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
6162026-05-08T01:28:07.642ZMay 08 01:28:07.610 INFO cr2: logging out
6172026-05-08T01:28:10.434ZMay 08 01:28:10.422 INFO cr2: logged out
6182026-05-08T01:28:10.459ZMay 08 01:28:10.422 DEBG [sc] ox: starting
6192026-05-08T01:28:10.460ZMay 08 01:28:10.422 DEBG [sc] ox: connecting to [::1]:37698
6202026-05-08T01:28:10.460ZMay 08 01:28:10.422 DEBG [sc] ox waiting for prompt
6212026-05-08T01:28:10.460ZMay 08 01:28:10.433 DEBG [sc] ox: logging in
6222026-05-08T01:28:10.536ZMay 08 01:28:10.522 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
6232026-05-08T01:28:16.290ZMay 08 01:28:16.276 DEBG [sc] ox: starting
6242026-05-08T01:28:16.290ZMay 08 01:28:16.276 DEBG [sc] ox: connecting to [::1]:37698
6252026-05-08T01:28:16.318ZMay 08 01:28:16.276 DEBG [sc] ox waiting for prompt
6262026-05-08T01:28:16.318ZMay 08 01:28:16.286 DEBG [sc] ox: logging in
6272026-05-08T01:28:16.376ZMay 08 01:28:16.363 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
6282026-05-08T01:28:16.466ZMay 08 01:28:16.452 DEBG [sc] ox: starting
6292026-05-08T01:28:16.466ZMay 08 01:28:16.452 DEBG [sc] ox: connecting to [::1]:37698
6302026-05-08T01:28:16.495ZMay 08 01:28:16.452 DEBG [sc] ox waiting for prompt
6312026-05-08T01:28:16.495ZMay 08 01:28:16.462 DEBG [sc] ox: logging in
6322026-05-08T01:28:16.564ZMay 08 01:28:16.551 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
6332026-05-08T01:28:16.632ZMay 08 01:28:16.617 INFO waiting for ceos to initialize
6342026-05-08T01:28:16.633ZMay 08 01:28:16.617 INFO cr1: installing frr
6352026-05-08T01:28:16.633ZMay 08 01:28:16.617 INFO ox: setting up npuvm
6362026-05-08T01:28:16.668ZMay 08 01:28:16.617 DEBG [sc] cr2: starting
6372026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] cr2: connecting to [::1]:56975
6382026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] cr1: starting
6392026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] cr1: connecting to [::1]:45002
6402026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] ox: starting
6412026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] ox: connecting to [::1]:37698
6422026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] cr1 waiting for prompt
6432026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] cr2 waiting for prompt
6442026-05-08T01:28:16.668ZMay 08 01:28:16.618 DEBG [sc] ox waiting for prompt
6452026-05-08T01:28:16.668ZMay 08 01:28:16.628 DEBG [sc] ox: logging in
6462026-05-08T01:28:16.668ZMay 08 01:28:16.629 DEBG [sc] cr1: logging in
6472026-05-08T01:28:16.668ZMay 08 01:28:16.629 DEBG [sc] cr2: logging in
6482026-05-08T01:28:16.722ZMay 08 01:28:16.706 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
6492026-05-08T01:28:16.764ZMay 08 01:28:16.750 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6502026-05-08T01:28:17.001ZMay 08 01:28:16.986 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
6512026-05-08T01:28:18.985ZMay 08 01:28:18.969 INFO cr2: executing eos script show version
6522026-05-08T01:28:18.985ZMay 08 01:28:18.969 DEBG [sc] cr2: starting
6532026-05-08T01:28:18.985ZMay 08 01:28:18.969 DEBG [sc] cr2: connecting to [::1]:56975
6542026-05-08T01:28:19.011ZMay 08 01:28:18.969 DEBG [sc] cr2 waiting for prompt
6552026-05-08T01:28:19.011ZMay 08 01:28:18.979 DEBG [sc] cr2: logging in
6562026-05-08T01:28:19.160ZMay 08 01:28:19.146 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6572026-05-08T01:28:22.452ZMay 08 01:28:22.438 DEBG [sc] ox: starting
6582026-05-08T01:28:22.452ZMay 08 01:28:22.438 DEBG [sc] ox: connecting to [::1]:37698
6592026-05-08T01:28:22.481ZMay 08 01:28:22.439 DEBG [sc] ox waiting for prompt
6602026-05-08T01:28:22.481ZMay 08 01:28:22.449 DEBG [sc] ox: logging in
6612026-05-08T01:28:22.550ZMay 08 01:28:22.537 DEBG [sc] ox: executing command `chmod +x npuvm`
6622026-05-08T01:28:22.616ZMay 08 01:28:22.603 DEBG [sc] ox: starting
6632026-05-08T01:28:22.616ZMay 08 01:28:22.603 DEBG [sc] ox: connecting to [::1]:37698
6642026-05-08T01:28:22.643ZMay 08 01:28:22.603 DEBG [sc] ox waiting for prompt
6652026-05-08T01:28:22.643ZMay 08 01:28:22.613 DEBG [sc] ox: logging in
6662026-05-08T01:28:22.705ZMay 08 01:28:22.691 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
6672026-05-08T01:28:26.458ZMay 08 01:28:26.445 INFO cr1: enabling frr daemon bfdd
6682026-05-08T01:28:26.458ZMay 08 01:28:26.445 DEBG [sc] cr1: starting
6692026-05-08T01:28:26.458ZMay 08 01:28:26.445 DEBG [sc] cr1: connecting to [::1]:45002
6702026-05-08T01:28:26.490ZMay 08 01:28:26.446 DEBG [sc] cr1 waiting for prompt
6712026-05-08T01:28:26.491ZMay 08 01:28:26.456 DEBG [sc] cr1: logging in
6722026-05-08T01:28:26.612ZMay 08 01:28:26.599 DEBG [sc] cr1: executing command `sed -i 's/bfdd=no/bfdd=yes/g' /etc/frr/daemons`
6732026-05-08T01:28:27.838ZMay 08 01:28:27.825 DEBG [sc] cr2: starting
6742026-05-08T01:28:27.838ZMay 08 01:28:27.825 DEBG [sc] cr2: connecting to [::1]:56975
6752026-05-08T01:28:27.869ZMay 08 01:28:27.826 DEBG [sc] cr2 waiting for prompt
6762026-05-08T01:28:27.869ZMay 08 01:28:27.836 DEBG [sc] cr2: logging in
6772026-05-08T01:28:27.992ZMay 08 01:28:27.979 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6782026-05-08T01:28:28.691ZMay 08 01:28:28.678 DEBG [sc] cr1: starting
6792026-05-08T01:28:28.691ZMay 08 01:28:28.678 DEBG [sc] cr1: connecting to [::1]:45002
6802026-05-08T01:28:28.723ZMay 08 01:28:28.678 DEBG [sc] cr1 waiting for prompt
6812026-05-08T01:28:28.723ZMay 08 01:28:28.689 DEBG [sc] cr1: logging in
6822026-05-08T01:28:28.845ZMay 08 01:28:28.832 DEBG [sc] cr1: executing command `systemctl restart frr`
6832026-05-08T01:28:30.090ZMay 08 01:28:30.076 INFO cr2: executing eos script show version
6842026-05-08T01:28:30.090ZMay 08 01:28:30.076 DEBG [sc] cr2: starting
6852026-05-08T01:28:30.090ZMay 08 01:28:30.076 DEBG [sc] cr2: connecting to [::1]:56975
6862026-05-08T01:28:30.121ZMay 08 01:28:30.076 DEBG [sc] cr2 waiting for prompt
6872026-05-08T01:28:30.121ZMay 08 01:28:30.087 DEBG [sc] cr2: logging in
6882026-05-08T01:28:30.269ZMay 08 01:28:30.252 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6892026-05-08T01:28:35.943ZMay 08 01:28:32.577 DEBG [sc] cr2: starting
6902026-05-08T01:28:35.943ZMay 08 01:28:32.577 DEBG [sc] cr2: connecting to [::1]:56975
6912026-05-08T01:28:35.998ZMay 08 01:28:32.578 DEBG [sc] cr2 waiting for prompt
6922026-05-08T01:28:35.998ZMay 08 01:28:32.588 DEBG [sc] cr2: logging in
6932026-05-08T01:28:35.998ZMay 08 01:28:32.756 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6942026-05-08T01:28:35.998ZMay 08 01:28:34.902 INFO cr2: executing eos script show version
6952026-05-08T01:28:35.998ZMay 08 01:28:34.902 DEBG [sc] cr2: starting
6962026-05-08T01:28:35.998ZMay 08 01:28:34.902 DEBG [sc] cr2: connecting to [::1]:56975
6972026-05-08T01:28:35.998ZMay 08 01:28:34.903 DEBG [sc] cr2 waiting for prompt
6982026-05-08T01:28:35.998ZMay 08 01:28:34.913 DEBG [sc] cr2: logging in
6992026-05-08T01:28:35.998ZMay 08 01:28:35.068 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
7002026-05-08T01:28:36.419ZMay 08 01:28:36.406 INFO cr1: executing frr script
7012026-05-08T01:28:36.419Z configure
7022026-05-08T01:28:36.419Z interface enp0s8
7032026-05-08T01:28:36.419Z ip address 10.0.0.2/24
7042026-05-08T01:28:36.419Z ipv6 address fd00:1::2/64
7052026-05-08T01:28:36.419Z no shutdown
7062026-05-08T01:28:36.419Z exit
7072026-05-08T01:28:36.419Z bfd
7082026-05-08T01:28:36.419Z peer 10.0.0.1 local-address 10.0.0.2
7092026-05-08T01:28:36.419Z detect-multiplier 3
7102026-05-08T01:28:36.419Z receive-interval 300
7112026-05-08T01:28:36.444Z transmit-interval 300
7122026-05-08T01:28:36.444Z no shutdown
7132026-05-08T01:28:36.444Z exit
7142026-05-08T01:28:36.444Z peer fd00:1::1 local-address fd00:1::2
7152026-05-08T01:28:36.444Z detect-multiplier 3
7162026-05-08T01:28:36.444Z receive-interval 300
7172026-05-08T01:28:36.444Z transmit-interval 300
7182026-05-08T01:28:36.444Z no shutdown
7192026-05-08T01:28:36.444Z exit
7202026-05-08T01:28:36.444Z exit
7212026-05-08T01:28:36.444Z
7222026-05-08T01:28:36.444ZMay 08 01:28:36.406 DEBG [sc] cr1: starting
7232026-05-08T01:28:36.444ZMay 08 01:28:36.406 DEBG [sc] cr1: connecting to [::1]:45002
7242026-05-08T01:28:36.444ZMay 08 01:28:36.407 DEBG [sc] cr1 waiting for prompt
7252026-05-08T01:28:36.444ZMay 08 01:28:36.418 DEBG [sc] cr1: logging in
7262026-05-08T01:28:36.563ZMay 08 01:28:36.550 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-08T01:28:37.505ZMay 08 01:28:37.492 INFO cr2: executing eos script
7282026-05-08T01:28:37.505Z enable
7292026-05-08T01:28:37.505Z configure
7302026-05-08T01:28:37.505Z ip routing
7312026-05-08T01:28:37.505Z ipv6 unicast-routing
7322026-05-08T01:28:37.505Z interface Ethernet1
7332026-05-08T01:28:37.505Z no switchport
7342026-05-08T01:28:37.505Z ip address 10.0.1.2/24
7352026-05-08T01:28:37.505Z ipv6 enable
7362026-05-08T01:28:37.505Z ipv6 address fd00:2::2/64
7372026-05-08T01:28:37.505Z bfd interval 300 min-rx 300 multiplier 3
7382026-05-08T01:28:37.505Z exit
7392026-05-08T01:28:37.505Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7402026-05-08T01:28:37.505Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7412026-05-08T01:28:37.505Z exit
7422026-05-08T01:28:37.505Z
7432026-05-08T01:28:37.505ZMay 08 01:28:37.492 DEBG [sc] cr2: starting
7442026-05-08T01:28:37.505ZMay 08 01:28:37.492 DEBG [sc] cr2: connecting to [::1]:56975
7452026-05-08T01:28:37.530ZMay 08 01:28:37.493 DEBG [sc] cr2 waiting for prompt
7462026-05-08T01:28:37.530ZMay 08 01:28:37.504 DEBG [sc] cr2: logging in
7472026-05-08T01:28:37.650ZMay 08 01:28:37.637 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
7482026-05-08T01:28:37.650Z enable
7492026-05-08T01:28:37.650Z configure
7502026-05-08T01:28:37.650Z ip routing
7512026-05-08T01:28:37.650Z ipv6 unicast-routing
7522026-05-08T01:28:37.650Z interface Ethernet1
7532026-05-08T01:28:37.650Z no switchport
7542026-05-08T01:28:37.650Z ip address 10.0.1.2/24
7552026-05-08T01:28:37.650Z ipv6 enable
7562026-05-08T01:28:37.650Z ipv6 address fd00:2::2/64
7572026-05-08T01:28:37.650Z bfd interval 300 min-rx 300 multiplier 3
7582026-05-08T01:28:37.650Z exit
7592026-05-08T01:28:37.650Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7602026-05-08T01:28:37.650Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7612026-05-08T01:28:37.650Z exit
7622026-05-08T01:28:37.650Z '`
7632026-05-08T01:30:12.719ZMay 08 01:30:12.707 DEBG [sc] ox: starting
7642026-05-08T01:30:12.719ZMay 08 01:30:12.707 DEBG [sc] ox: connecting to [::1]:37698
7652026-05-08T01:30:12.744ZMay 08 01:30:12.707 DEBG [sc] ox waiting for prompt
7662026-05-08T01:30:12.744ZMay 08 01:30:12.718 DEBG [sc] ox: logging in
7672026-05-08T01:30:12.807ZMay 08 01:30:12.794 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
7682026-05-08T01:30:13.411ZMay 08 01:30:13.399 DEBG [sc] ox: starting
7692026-05-08T01:30:13.411ZMay 08 01:30:13.399 DEBG [sc] ox: connecting to [::1]:37698
7702026-05-08T01:30:13.439ZMay 08 01:30:13.399 DEBG [sc] ox waiting for prompt
7712026-05-08T01:30:13.439ZMay 08 01:30:13.410 DEBG [sc] ox: logging in
7722026-05-08T01:30:13.499ZMay 08 01:30:13.487 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7732026-05-08T01:30:13.566ZMay 08 01:30:13.554 DEBG [sc] ox: starting
7742026-05-08T01:30:13.566ZMay 08 01:30:13.554 DEBG [sc] ox: connecting to [::1]:37698
7752026-05-08T01:30:13.591ZMay 08 01:30:13.554 DEBG [sc] ox waiting for prompt
7762026-05-08T01:30:13.591ZMay 08 01:30:13.564 DEBG [sc] ox: logging in
7772026-05-08T01:30:13.667ZMay 08 01:30:13.654 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7782026-05-08T01:30:14.133ZMay 08 01:30:14.119 DEBG [sc] ox: starting
7792026-05-08T01:30:14.133ZMay 08 01:30:14.119 DEBG [sc] ox: connecting to [::1]:37698
7802026-05-08T01:30:14.157ZMay 08 01:30:14.120 DEBG [sc] ox waiting for prompt
7812026-05-08T01:30:14.157ZMay 08 01:30:14.131 DEBG [sc] ox: logging in
7822026-05-08T01:30:14.220ZMay 08 01:30:14.208 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
7832026-05-08T01:30:14.276ZMay 08 01:30:14.264 DEBG [sc] ox: starting
7842026-05-08T01:30:14.276ZMay 08 01:30:14.264 DEBG [sc] ox: connecting to [::1]:37698
7852026-05-08T01:30:14.301ZMay 08 01:30:14.264 DEBG [sc] ox waiting for prompt
7862026-05-08T01:30:14.301ZMay 08 01:30:14.274 DEBG [sc] ox: logging in
7872026-05-08T01:30:14.365ZMay 08 01:30:14.352 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
7882026-05-08T01:30:14.420ZMay 08 01:30:14.407 DEBG [sc] ox: starting
7892026-05-08T01:30:14.420ZMay 08 01:30:14.407 DEBG [sc] ox: connecting to [::1]:37698
7902026-05-08T01:30:14.445ZMay 08 01:30:14.408 DEBG [sc] ox waiting for prompt
7912026-05-08T01:30:14.445ZMay 08 01:30:14.418 DEBG [sc] ox: logging in
7922026-05-08T01:30:14.509ZMay 08 01:30:14.496 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.0.1/24 tfportqsfp0_0/v4`
7932026-05-08T01:30:15.132ZMay 08 01:30:15.120 DEBG [sc] ox: starting
7942026-05-08T01:30:15.132ZMay 08 01:30:15.120 DEBG [sc] ox: connecting to [::1]:37698
7952026-05-08T01:30:15.157ZMay 08 01:30:15.121 DEBG [sc] ox waiting for prompt
7962026-05-08T01:30:15.157ZMay 08 01:30:15.131 DEBG [sc] ox: logging in
7972026-05-08T01:30:15.221ZMay 08 01:30:15.208 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v4 -p -o addr`
7982026-05-08T01:30:15.287ZMay 08 01:30:15.274 DEBG [sc] ox: starting
7992026-05-08T01:30:15.287ZMay 08 01:30:15.274 DEBG [sc] ox: connecting to [::1]:37698
8002026-05-08T01:30:15.312ZMay 08 01:30:15.275 DEBG [sc] ox waiting for prompt
8012026-05-08T01:30:15.312ZMay 08 01:30:15.285 DEBG [sc] ox: logging in
8022026-05-08T01:30:15.376ZMay 08 01:30:15.363 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:1::1/64 tfportqsfp0_0/v6`
8032026-05-08T01:30:15.900ZMay 08 01:30:15.887 DEBG [sc] ox: starting
8042026-05-08T01:30:15.900ZMay 08 01:30:15.887 DEBG [sc] ox: connecting to [::1]:37698
8052026-05-08T01:30:15.925ZMay 08 01:30:15.888 DEBG [sc] ox waiting for prompt
8062026-05-08T01:30:15.925ZMay 08 01:30:15.898 DEBG [sc] ox: logging in
8072026-05-08T01:30:15.988ZMay 08 01:30:15.976 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v6 -p -o addr`
8082026-05-08T01:30:16.044ZMay 08 01:30:16.032 DEBG [sc] ox: starting
8092026-05-08T01:30:16.044ZMay 08 01:30:16.032 DEBG [sc] ox: connecting to [::1]:37698
8102026-05-08T01:30:16.069ZMay 08 01:30:16.032 DEBG [sc] ox waiting for prompt
8112026-05-08T01:30:16.069ZMay 08 01:30:16.043 DEBG [sc] ox: logging in
8122026-05-08T01:30:16.133ZMay 08 01:30:16.121 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
8132026-05-08T01:30:16.189ZMay 08 01:30:16.177 DEBG [sc] ox: starting
8142026-05-08T01:30:16.189ZMay 08 01:30:16.177 DEBG [sc] ox: connecting to [::1]:37698
8152026-05-08T01:30:16.214ZMay 08 01:30:16.177 DEBG [sc] ox waiting for prompt
8162026-05-08T01:30:16.214ZMay 08 01:30:16.187 DEBG [sc] ox: logging in
8172026-05-08T01:30:16.276ZMay 08 01:30:16.264 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
8182026-05-08T01:30:16.332ZMay 08 01:30:16.319 DEBG [sc] ox: starting
8192026-05-08T01:30:16.332ZMay 08 01:30:16.319 DEBG [sc] ox: connecting to [::1]:37698
8202026-05-08T01:30:16.358ZMay 08 01:30:16.320 DEBG [sc] ox waiting for prompt
8212026-05-08T01:30:16.358ZMay 08 01:30:16.331 DEBG [sc] ox: logging in
8222026-05-08T01:30:16.422ZMay 08 01:30:16.409 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.1.1/24 tfportqsfp1_0/v4`
8232026-05-08T01:30:16.980ZMay 08 01:30:16.967 DEBG [sc] ox: starting
8242026-05-08T01:30:16.980ZMay 08 01:30:16.967 DEBG [sc] ox: connecting to [::1]:37698
8252026-05-08T01:30:17.005ZMay 08 01:30:16.968 DEBG [sc] ox waiting for prompt
8262026-05-08T01:30:17.005ZMay 08 01:30:16.978 DEBG [sc] ox: logging in
8272026-05-08T01:30:17.067ZMay 08 01:30:17.055 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v4 -p -o addr`
8282026-05-08T01:30:17.124ZMay 08 01:30:17.111 DEBG [sc] ox: starting
8292026-05-08T01:30:17.124ZMay 08 01:30:17.111 DEBG [sc] ox: connecting to [::1]:37698
8302026-05-08T01:30:17.149ZMay 08 01:30:17.111 DEBG [sc] ox waiting for prompt
8312026-05-08T01:30:17.149ZMay 08 01:30:17.121 DEBG [sc] ox: logging in
8322026-05-08T01:30:17.211ZMay 08 01:30:17.198 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:2::1/64 tfportqsfp1_0/v6`
8332026-05-08T01:30:17.724ZMay 08 01:30:17.712 DEBG [sc] ox: starting
8342026-05-08T01:30:17.724ZMay 08 01:30:17.712 DEBG [sc] ox: connecting to [::1]:37698
8352026-05-08T01:30:17.749ZMay 08 01:30:17.712 DEBG [sc] ox waiting for prompt
8362026-05-08T01:30:17.749ZMay 08 01:30:17.722 DEBG [sc] ox: logging in
8372026-05-08T01:30:17.812ZMay 08 01:30:17.799 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v6 -p -o addr`
8382026-05-08T01:30:17.867ZMay 08 01:30:17.854 DEBG [sc] ox: starting
8392026-05-08T01:30:17.867ZMay 08 01:30:17.854 DEBG [sc] ox: connecting to [::1]:37698
8402026-05-08T01:30:17.897ZMay 08 01:30:17.855 DEBG [sc] ox waiting for prompt
8412026-05-08T01:30:17.897ZMay 08 01:30:17.865 DEBG [sc] ox: logging in
8422026-05-08T01:30:17.958ZMay 08 01:30:17.942 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
8432026-05-08T01:30:18.016ZMay 08 01:30:17.997 DEBG [sc] ox: starting
8442026-05-08T01:30:18.016ZMay 08 01:30:17.997 DEBG [sc] ox: connecting to [::1]:37698
8452026-05-08T01:30:18.049ZMay 08 01:30:17.998 DEBG [sc] ox waiting for prompt
8462026-05-08T01:30:18.049ZMay 08 01:30:18.008 DEBG [sc] ox: logging in
8472026-05-08T01:30:18.110ZMay 08 01:30:18.097 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
8482026-05-08T01:30:18.178ZMay 08 01:30:18.165 INFO installing static v4 route 192.168.100.0/24
8492026-05-08T01:30:18.203ZMay 08 01:30:18.167 INFO installing static v6 route fd01::/64
8502026-05-08T01:30:18.203ZMay 08 01:30:18.168 INFO adding BFD peers for cr1 and cr2 (dual-stack)
8512026-05-08T01:30:18.203ZMay 08 01:30:18.170 INFO phase 1: both peers up
8522026-05-08T01:30:19.187ZMay 08 01:30:19.174 INFO cr1: executing frr script show bfd peers json
8532026-05-08T01:30:19.211ZMay 08 01:30:19.174 DEBG [sc] cr1: starting
8542026-05-08T01:30:19.211ZMay 08 01:30:19.174 DEBG [sc] cr1: connecting to [::1]:45002
8552026-05-08T01:30:19.211ZMay 08 01:30:19.175 DEBG [sc] cr1 waiting for prompt
8562026-05-08T01:30:19.212ZMay 08 01:30:19.186 DEBG [sc] cr1: logging in
8572026-05-08T01:30:19.507ZMay 08 01:30:19.494 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8582026-05-08T01:30:21.638ZMay 08 01:30:21.626 INFO cr1: executing frr script show bfd peers json
8592026-05-08T01:30:21.638ZMay 08 01:30:21.626 DEBG [sc] cr1: starting
8602026-05-08T01:30:21.638ZMay 08 01:30:21.626 DEBG [sc] cr1: connecting to [::1]:45002
8612026-05-08T01:30:21.663ZMay 08 01:30:21.627 DEBG [sc] cr1 waiting for prompt
8622026-05-08T01:30:21.663ZMay 08 01:30:21.637 DEBG [sc] cr1: logging in
8632026-05-08T01:30:21.770ZMay 08 01:30:21.758 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8642026-05-08T01:30:23.915ZMay 08 01:30:23.903 INFO cr2: executing eos script show bfd peers | json
8652026-05-08T01:30:23.940ZMay 08 01:30:23.903 DEBG [sc] cr2: starting
8662026-05-08T01:30:23.940ZMay 08 01:30:23.903 DEBG [sc] cr2: connecting to [::1]:56975
8672026-05-08T01:30:23.940ZMay 08 01:30:23.904 DEBG [sc] cr2 waiting for prompt
8682026-05-08T01:30:23.940ZMay 08 01:30:23.914 DEBG [sc] cr2: logging in
8692026-05-08T01:30:24.251ZMay 08 01:30:24.239 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8702026-05-08T01:30:26.602ZMay 08 01:30:26.589 INFO cr2: executing eos script show bfd peers | json
8712026-05-08T01:30:26.602ZMay 08 01:30:26.589 DEBG [sc] cr2: starting
8722026-05-08T01:30:26.626ZMay 08 01:30:26.589 DEBG [sc] cr2: connecting to [::1]:56975
8732026-05-08T01:30:26.626ZMay 08 01:30:26.590 DEBG [sc] cr2 waiting for prompt
8742026-05-08T01:30:26.626ZMay 08 01:30:26.600 DEBG [sc] cr2: logging in
8752026-05-08T01:30:26.735ZMay 08 01:30:26.722 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8762026-05-08T01:30:29.058ZMay 08 01:30:29.045 INFO phase 2: pause bfdd on cr1
8772026-05-08T01:30:29.058ZMay 08 01:30:29.045 INFO cr1: pausing frr bfdd
8782026-05-08T01:30:29.058ZMay 08 01:30:29.045 DEBG [sc] cr1: starting
8792026-05-08T01:30:29.058ZMay 08 01:30:29.045 DEBG [sc] cr1: connecting to [::1]:45002
8802026-05-08T01:30:29.083ZMay 08 01:30:29.046 DEBG [sc] cr1 waiting for prompt
8812026-05-08T01:30:29.083ZMay 08 01:30:29.057 DEBG [sc] cr1: logging in
8822026-05-08T01:30:29.204ZMay 08 01:30:29.191 DEBG [sc] cr1: executing command `pkill -STOP bfdd`
8832026-05-08T01:30:31.288ZMay 08 01:30:31.276 INFO cr2: executing eos script show bfd peers | json
8842026-05-08T01:30:31.288ZMay 08 01:30:31.276 DEBG [sc] cr2: starting
8852026-05-08T01:30:31.288ZMay 08 01:30:31.276 DEBG [sc] cr2: connecting to [::1]:56975
8862026-05-08T01:30:31.313ZMay 08 01:30:31.276 DEBG [sc] cr2 waiting for prompt
8872026-05-08T01:30:31.313ZMay 08 01:30:31.288 DEBG [sc] cr2: logging in
8882026-05-08T01:30:31.444ZMay 08 01:30:31.431 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8892026-05-08T01:30:33.771ZMay 08 01:30:33.757 INFO cr2: executing eos script show bfd peers | json
8902026-05-08T01:30:33.771ZMay 08 01:30:33.758 DEBG [sc] cr2: starting
8912026-05-08T01:30:33.771ZMay 08 01:30:33.758 DEBG [sc] cr2: connecting to [::1]:56975
8922026-05-08T01:30:33.796ZMay 08 01:30:33.759 DEBG [sc] cr2 waiting for prompt
8932026-05-08T01:30:33.796ZMay 08 01:30:33.769 DEBG [sc] cr2: logging in
8942026-05-08T01:30:33.925ZMay 08 01:30:33.912 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8952026-05-08T01:30:36.267ZMay 08 01:30:36.254 INFO phase 3: pause ceos on cr2
8962026-05-08T01:30:36.267ZMay 08 01:30:36.254 INFO cr2: pausing ceos
8972026-05-08T01:30:36.267ZMay 08 01:30:36.254 DEBG [sc] cr2: starting
8982026-05-08T01:30:36.267ZMay 08 01:30:36.254 DEBG [sc] cr2: connecting to [::1]:56975
8992026-05-08T01:30:36.291ZMay 08 01:30:36.254 DEBG [sc] cr2 waiting for prompt
9002026-05-08T01:30:36.291ZMay 08 01:30:36.262 DEBG [sc] cr2: logging in
9012026-05-08T01:30:36.440ZMay 08 01:30:36.428 DEBG [sc] cr2: executing command `docker pause ceos`
9022026-05-08T01:30:38.540ZMay 08 01:30:38.528 INFO phase 4: resume bfdd on cr1
9032026-05-08T01:30:38.540ZMay 08 01:30:38.528 INFO cr1: resuming frr bfdd
9042026-05-08T01:30:38.540ZMay 08 01:30:38.528 DEBG [sc] cr1: starting
9052026-05-08T01:30:38.540ZMay 08 01:30:38.528 DEBG [sc] cr1: connecting to [::1]:45002
9062026-05-08T01:30:38.566ZMay 08 01:30:38.528 DEBG [sc] cr1 waiting for prompt
9072026-05-08T01:30:38.566ZMay 08 01:30:38.539 DEBG [sc] cr1: logging in
9082026-05-08T01:30:38.684ZMay 08 01:30:38.671 DEBG [sc] cr1: executing command `pkill -CONT bfdd`
9092026-05-08T01:30:40.784ZMay 08 01:30:40.772 INFO cr1: executing frr script show bfd peers json
9102026-05-08T01:30:40.784ZMay 08 01:30:40.772 DEBG [sc] cr1: starting
9112026-05-08T01:30:40.784ZMay 08 01:30:40.772 DEBG [sc] cr1: connecting to [::1]:45002
9122026-05-08T01:30:40.809ZMay 08 01:30:40.772 DEBG [sc] cr1 waiting for prompt
9132026-05-08T01:30:40.809ZMay 08 01:30:40.781 DEBG [sc] cr1: logging in
9142026-05-08T01:30:40.926ZMay 08 01:30:40.913 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9152026-05-08T01:30:43.063ZMay 08 01:30:43.050 INFO cr1: executing frr script show bfd peers json
9162026-05-08T01:30:43.063ZMay 08 01:30:43.050 DEBG [sc] cr1: starting
9172026-05-08T01:30:43.063ZMay 08 01:30:43.050 DEBG [sc] cr1: connecting to [::1]:45002
9182026-05-08T01:30:43.088ZMay 08 01:30:43.051 DEBG [sc] cr1 waiting for prompt
9192026-05-08T01:30:43.088ZMay 08 01:30:43.061 DEBG [sc] cr1: logging in
9202026-05-08T01:30:43.208ZMay 08 01:30:43.194 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9212026-05-08T01:30:45.358ZMay 08 01:30:45.341 INFO phase 5: unpause ceos on cr2
9222026-05-08T01:30:45.358ZMay 08 01:30:45.341 INFO cr2: unpausing ceos
9232026-05-08T01:30:45.358ZMay 08 01:30:45.341 DEBG [sc] cr2: starting
9242026-05-08T01:30:45.358ZMay 08 01:30:45.341 DEBG [sc] cr2: connecting to [::1]:56975
9252026-05-08T01:30:45.383ZMay 08 01:30:45.341 DEBG [sc] cr2 waiting for prompt
9262026-05-08T01:30:45.383ZMay 08 01:30:45.353 DEBG [sc] cr2: logging in
9272026-05-08T01:30:45.499ZMay 08 01:30:45.484 DEBG [sc] cr2: executing command `docker unpause ceos`
9282026-05-08T01:30:47.619ZMay 08 01:30:47.606 INFO cr1: executing frr script show bfd peers json
9292026-05-08T01:30:47.619ZMay 08 01:30:47.606 DEBG [sc] cr1: starting
9302026-05-08T01:30:47.619ZMay 08 01:30:47.606 DEBG [sc] cr1: connecting to [::1]:45002
9312026-05-08T01:30:47.644ZMay 08 01:30:47.607 DEBG [sc] cr1 waiting for prompt
9322026-05-08T01:30:47.644ZMay 08 01:30:47.617 DEBG [sc] cr1: logging in
9332026-05-08T01:30:47.774ZMay 08 01:30:47.761 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9342026-05-08T01:30:49.907ZMay 08 01:30:49.894 INFO cr1: executing frr script show bfd peers json
9352026-05-08T01:30:49.907ZMay 08 01:30:49.894 DEBG [sc] cr1: starting
9362026-05-08T01:30:49.907ZMay 08 01:30:49.894 DEBG [sc] cr1: connecting to [::1]:45002
9372026-05-08T01:30:49.932ZMay 08 01:30:49.895 DEBG [sc] cr1 waiting for prompt
9382026-05-08T01:30:49.932ZMay 08 01:30:49.906 DEBG [sc] cr1: logging in
9392026-05-08T01:30:50.073ZMay 08 01:30:50.061 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9402026-05-08T01:30:52.231ZMay 08 01:30:52.218 INFO cr2: executing eos script show bfd peers | json
9412026-05-08T01:30:52.255ZMay 08 01:30:52.218 DEBG [sc] cr2: starting
9422026-05-08T01:30:52.255ZMay 08 01:30:52.218 DEBG [sc] cr2: connecting to [::1]:56975
9432026-05-08T01:30:52.256ZMay 08 01:30:52.219 DEBG [sc] cr2 waiting for prompt
9442026-05-08T01:30:52.256ZMay 08 01:30:52.230 DEBG [sc] cr2: logging in
9452026-05-08T01:30:52.386ZMay 08 01:30:52.373 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9462026-05-08T01:30:54.729ZMay 08 01:30:54.716 INFO cr2: executing eos script show bfd peers | json
9472026-05-08T01:30:54.729ZMay 08 01:30:54.716 DEBG [sc] cr2: starting
9482026-05-08T01:30:54.729ZMay 08 01:30:54.716 DEBG [sc] cr2: connecting to [::1]:56975
9492026-05-08T01:30:54.754ZMay 08 01:30:54.717 DEBG [sc] cr2 waiting for prompt
9502026-05-08T01:30:54.754ZMay 08 01:30:54.726 DEBG [sc] cr2: logging in
9512026-05-08T01:30:54.884ZMay 08 01:30:54.871 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9522026-05-08T01:30:57.239ZMay 08 01:30:57.225 INFO trio bfd static routing test passed 🎉
9532026-05-08T01:30:57.239ZMay 08 01:30:57.225 INFO destroying runner for deployment mgtriobfd
9542026-05-08T01:30:57.239ZMay 08 01:30:57.225 INFO destroying deployment mgtriobfd
9552026-05-08T01:30:57.239ZMay 08 01:30:57.225 INFO destroying nodes
9562026-05-08T01:30:57.349ZMay 08 01:30:57.336 INFO destroying links
9572026-05-08T01:30:57.349ZMay 08 01:30:57.336 INFO destroying link mgtriobfd_ox_sn_vnic0
9582026-05-08T01:30:57.374ZMay 08 01:30:57.338 INFO destroying link mgtriobfd_ox_sn_sim0
9592026-05-08T01:30:57.374ZMay 08 01:30:57.340 INFO destroying link mgtriobfd_cr1_vn_vnic0
9602026-05-08T01:30:58.355ZMay 08 01:30:58.342 INFO destroying link mgtriobfd_cr1_vn_sim0
9612026-05-08T01:30:58.381ZMay 08 01:30:58.343 INFO destroying link mgtriobfd_ox_sn_vnic1
9622026-05-08T01:30:58.381ZMay 08 01:30:58.345 INFO destroying link mgtriobfd_ox_sn_sim1
9632026-05-08T01:30:58.381ZMay 08 01:30:58.346 INFO destroying link mgtriobfd_cr2_vn_vnic0
9642026-05-08T01:30:58.381ZMay 08 01:30:58.347 INFO destroying link mgtriobfd_cr2_vn_sim0
9652026-05-08T01:30:58.381ZMay 08 01:30:58.348 INFO destroying external links
9662026-05-08T01:30:58.381ZMay 08 01:30:58.348 INFO destroying external link mgtriobfd_ox_vn_vnic2
9672026-05-08T01:30:58.381ZMay 08 01:30:58.349 INFO destroying external link mgtriobfd_cr1_vn_vnic1
9682026-05-08T01:30:58.381ZMay 08 01:30:58.350 INFO destroying external link mgtriobfd_cr2_vn_vnic1
9692026-05-08T01:30:58.381ZMay 08 01:30:58.351 INFO destroying images
9702026-05-08T01:30:58.849ZMay 08 01:30:58.836 INFO destroying workspace at .falcon
9712026-05-08T01:30:58.873Zprocess exited: duration 698471 ms, exit code 0
 
9722026-05-08T01:30:58.925Zfound 0 output files