01KR5CB4EMCF263MD4HEVDCKBH: falcon

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

Buildomat Job: 01KR5CBHBB5GXP8K3SD7FPWT5Z

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-05-09T03:40:40.805Zjob dependencies complete; ready to run (waiting for 14 m 6 s)
22026-05-09T03:43:55.546Zjob assigned to worker 01KR5D5D19XD3HMFA4R65XD541 [factory edgar, gimlet/BRM42220010/943] (queued for 3 m 14 s)
32026-05-09T03:43:56.252Zdownloading input: /input/build/work/debug/ddmadm
42026-05-09T03:44:18.597Zdownloaded input: /input/build/work/debug/ddmadm
52026-05-09T03:44:18.597Zdownloading input: /input/build/work/debug/ddmd
62026-05-09T03:44:45.021Zdownloaded input: /input/build/work/debug/ddmd
72026-05-09T03:44:46.070Zdownloading input: /input/build/work/debug/mgadm
82026-05-09T03:45:11.048Zdownloaded input: /input/build/work/debug/mgadm
92026-05-09T03:45:11.048Zdownloading input: /input/build/work/debug/mgd
102026-05-09T03:45:41.059Zdownloaded input: /input/build/work/debug/mgd
112026-05-09T03:45:41.084Zdownloading input: /input/build-interop/work/testbed.tar.gz
122026-05-09T03:45:49.688Zdownloaded input: /input/build-interop/work/testbed.tar.gz
132026-05-09T03:45:49.713Zdownloading input: /input/build-interop/work/dhcp-server
142026-05-09T03:45:51.955Zdownloaded input: /input/build-interop/work/dhcp-server
152026-05-09T03:45:51.979Zdownloading input: /input/build/work/release/ddmadm
162026-05-09T03:45:54.195Zdownloaded input: /input/build/work/release/ddmadm
172026-05-09T03:45:54.195Zdownloading input: /input/build/work/release/ddmd
182026-05-09T03:45:56.729Zdownloaded input: /input/build/work/release/ddmd
192026-05-09T03:45:56.729Zdownloading input: /input/build/work/release/falcon-lab
202026-05-09T03:45:58.302Zdownloaded input: /input/build/work/release/falcon-lab
212026-05-09T03:45:58.302Zdownloading input: /input/build/work/release/mgadm
222026-05-09T03:46:01.008Zdownloaded input: /input/build/work/release/mgadm
232026-05-09T03:46:01.008Zdownloading input: /input/build/work/release/mgd
242026-05-09T03:46:04.460Zdownloaded input: /input/build/work/release/mgd
 
252026-05-09T03:46:04.460Zstarting task 0: "setup"
262026-05-09T03:46:04.485Z++ uname -s
272026-05-09T03:46:04.485Z+ kern=SunOS
282026-05-09T03:46:04.485Z+ build_user=build
292026-05-09T03:46:04.485Z+ build_uid=12345
302026-05-09T03:46:04.485Z+ work_dir=/work
312026-05-09T03:46:04.485Z+ input_dir=/input
322026-05-09T03:46:04.485Z+ [[ 0 == 12345 ]]
332026-05-09T03:46:04.485Z+ case "$kern" in
342026-05-09T03:46:04.485Z+ groupadd -g 12345 build
352026-05-09T03:46:04.510Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-05-09T03:46:06.499Z+ zfs create -o mountpoint=/work rpool/work
372026-05-09T03:46:06.834Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-05-09T03:46:06.858Z+ home_fs=
392026-05-09T03:46:06.858Z+ [[ '' == autofs ]]
402026-05-09T03:46:06.858Z+ mkdir -p /home/build
412026-05-09T03:46:06.858Z+ chown build:build /home/build /work
422026-05-09T03:46:08.848Z+ chmod 0700 /home/build /work
432026-05-09T03:46:08.872Zprocess exited: duration 4391 ms, exit code 0
 
442026-05-09T03:46:08.920Zstarting task 1: "authentication"
452026-05-09T03:46:09.015Zprocess exited: duration 94 ms, exit code 0
 
462026-05-09T03:46:09.063Zstarting task 2: "build"
472026-05-09T03:46:09.087Z+ set -e
482026-05-09T03:46:09.087Z+ banner zpool
492026-05-09T03:46:09.087Z
502026-05-09T03:46:09.087Z ###### ##### #### #### #
512026-05-09T03:46:09.087Z # # # # # # # #
522026-05-09T03:46:09.087Z # # # # # # # #
532026-05-09T03:46:09.087Z # ##### # # # # #
542026-05-09T03:46:09.087Z # # # # # # #
552026-05-09T03:46:09.087Z ###### # #### #### ######
562026-05-09T03:46:09.087Z
572026-05-09T03:46:09.087Z++ pfexec diskinfo -pH
582026-05-09T03:46:09.111Z++ sort -k8 -n -r
592026-05-09T03:46:09.111Z++ head -1
602026-05-09T03:46:09.111Z++ awk '{print $2}'
612026-05-09T03:46:09.135Z+ DISK=c9t0014EE81000BC3B1d0
622026-05-09T03:46:09.135Z+ export DISK
632026-05-09T03:46:09.135Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC3B1d0
642026-05-09T03:46:09.211Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-05-09T03:46:09.239Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-05-09T03:46:09.413Z+ [[ true =~ true ]]
672026-05-09T03:46:09.413Z+ pfexec zpool trim cpool
682026-05-09T03:46:09.437Z++ zpool status -t cpool
692026-05-09T03:46:09.461Z+ [[ ! pool: cpool
702026-05-09T03:46:09.461Z state: ONLINE
712026-05-09T03:46:09.461Z scan: none requested
722026-05-09T03:46:09.461Zconfig:
732026-05-09T03:46:09.461Z
742026-05-09T03:46:09.461Z NAME STATE READ WRITE CKSUM
752026-05-09T03:46:09.461Z cpool ONLINE 0 0 0
762026-05-09T03:46:09.462Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at May 9, 2026 at 03:46:09 AM UTC)
772026-05-09T03:46:09.462Z
782026-05-09T03:46:09.462Zerrors: No known data errors =~ 100% ]]
792026-05-09T03:46:09.462Z+ sleep 10
802026-05-09T03:46:19.448Z++ zpool status -t cpool
812026-05-09T03:46:19.472Z+ [[ ! pool: cpool
822026-05-09T03:46:19.473Z state: ONLINE
832026-05-09T03:46:19.473Z scan: none requested
842026-05-09T03:46:19.473Zconfig:
852026-05-09T03:46:19.473Z
862026-05-09T03:46:19.473Z NAME STATE READ WRITE CKSUM
872026-05-09T03:46:19.473Z cpool ONLINE 0 0 0
882026-05-09T03:46:19.473Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (69% trimmed, started at May 9, 2026 at 03:46:09 AM UTC)
892026-05-09T03:46:19.473Z
902026-05-09T03:46:19.473Zerrors: No known data errors =~ 100% ]]
912026-05-09T03:46:19.473Z+ sleep 10
922026-05-09T03:46:29.463Z++ zpool status -t cpool
932026-05-09T03:46:29.487Z+ [[ ! pool: cpool
942026-05-09T03:46:29.487Z state: ONLINE
952026-05-09T03:46:29.488Z scan: none requested
962026-05-09T03:46:29.488Zconfig:
972026-05-09T03:46:29.488Z
982026-05-09T03:46:29.488Z NAME STATE READ WRITE CKSUM
992026-05-09T03:46:29.488Z cpool ONLINE 0 0 0
1002026-05-09T03:46:29.488Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at May 9, 2026 at 03:46:23 AM UTC)
1012026-05-09T03:46:29.488Z
1022026-05-09T03:46:29.488Zerrors: No known data errors =~ 100% ]]
1032026-05-09T03:46:29.488Z+ pfexec chown 12345 /ci
1042026-05-09T03:46:29.488Z+ cd /ci
1052026-05-09T03:46:29.488Z+ export FALCON_DATASET=cpool/falcon
1062026-05-09T03:46:29.488Z+ FALCON_DATASET=cpool/falcon
1072026-05-09T03:46:29.488Z+ banner setup
1082026-05-09T03:46:29.488Z
1092026-05-09T03:46:29.488Z #### ###### ##### # # #####
1102026-05-09T03:46:29.488Z # # # # # # #
1112026-05-09T03:46:29.488Z #### ##### # # # # #
1122026-05-09T03:46:29.488Z # # # # # #####
1132026-05-09T03:46:29.488Z # # # # # # #
1142026-05-09T03:46:29.488Z #### ###### # #### #
1152026-05-09T03:46:29.488Z
1162026-05-09T03:46:29.488Z+ cp /input/build-interop/work/dhcp-server .
1172026-05-09T03:46:29.516Z+ cp /input/build/work/release/falcon-lab .
1182026-05-09T03:46:29.546Z+ cp /input/build/work/release/mgd .
1192026-05-09T03:46:29.614Z+ cp /input/build/work/release/ddmd .
1202026-05-09T03:46:29.671Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-05-09T03:46:29.696Z+ mkdir -p cargo-bay
1222026-05-09T03:46:29.696Z+ mv mgd cargo-bay/
1232026-05-09T03:46:29.697Z+ mv ddmd cargo-bay/
1242026-05-09T03:46:29.697Z+ export EXT_INTERFACE=igb0
1252026-05-09T03:46:29.697Z+ EXT_INTERFACE=igb0
1262026-05-09T03:46:29.697Z++ bmat address ls -f extra -Ho first
1272026-05-09T03:46:29.721Z+ first=10.151.6.164
1282026-05-09T03:46:29.721Z++ bmat address ls -f extra -Ho last
1292026-05-09T03:46:29.745Z+ last=10.151.6.227
1302026-05-09T03:46:29.745Z++ bmat address ls -f extra -Ho gateway
1312026-05-09T03:46:29.769Z+ gw=10.151.6.1
1322026-05-09T03:46:29.769Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-05-09T03:46:29.794Z++ sed 's#/.*##g'
1342026-05-09T03:46:29.794Z+ server=10.151.6.100
1352026-05-09T03:46:29.794Z+ RUST_LOG=debug
1362026-05-09T03:46:29.794Z+ pfexec ./falcon-lab run trio-unnumbered
1372026-05-09T03:46:29.794Z+ pfexec ./dhcp-server 10.151.6.164 10.151.6.227 10.151.6.1 10.151.6.100
1382026-05-09T03:46:29.819ZMay 09 03:46:29.785 DEBG using default route interface igb0
1392026-05-09T03:46:29.819ZMay 09 03:46:29.785 DEBG using default route interface igb0
1402026-05-09T03:46:29.819ZMay 09 03:46:29.785 DEBG using default route interface igb0
1412026-05-09T03:46:29.819ZMay 09 03:46:29.785 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1422026-05-09T03:46:29.819ZMay 09 03:46:29.785 INFO starting preflight for deployment mgtriou
1432026-05-09T03:46:29.819ZMay 09 03:46:29.785 INFO propolis-server binary not found
1442026-05-09T03:46:29.819ZMay 09 03:46:29.785 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1452026-05-09T03:46:33.703ZMay 09 03:46:33.692 INFO ovmf fd not found
1462026-05-09T03:46:33.704ZMay 09 03:46:33.692 INFO downloading ovmf
1472026-05-09T03:46:34.090ZMay 09 03:46:34.079 INFO base image for helios-2.9 does not exist, attempting to install
1482026-05-09T03:46:34.091ZMay 09 03:46:34.079 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1492026-05-09T03:47:02.114ZMay 09 03:47:02.100 INFO extracting image to /tmp/helios-2.9_0.raw
1502026-05-09T03:47:36.035ZMay 09 03:47:36.017 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1512026-05-09T03:47:36.083ZMay 09 03:47:36.065 INFO copying image data to zvol
1522026-05-09T03:47:46.624ZMay 09 03:47:46.605 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1532026-05-09T03:47:49.913ZMay 09 03:47:49.893 INFO base image for debian-13.2 does not exist, attempting to install
1542026-05-09T03:47:49.913ZMay 09 03:47:49.893 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1552026-05-09T03:48:10.466ZMay 09 03:48:10.444 INFO extracting image to /tmp/debian-13.2_0.raw
1562026-05-09T03:48:31.671ZMay 09 03:48:31.647 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1572026-05-09T03:48:31.695ZMay 09 03:48:31.672 INFO copying image data to zvol
1582026-05-09T03:48:38.071ZMay 09 03:48:38.047 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1592026-05-09T03:48:41.321ZMay 09 03:48:41.297 INFO base image for eos-4.35 does not exist, attempting to install
1602026-05-09T03:48:41.321ZMay 09 03:48:41.297 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1612026-05-09T03:49:27.049ZMay 09 03:49:27.024 INFO extracting image to /tmp/eos-4.35_0.raw
1622026-05-09T03:50:50.691ZMay 09 03:50:50.676 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1632026-05-09T03:50:50.716ZMay 09 03:50:50.702 INFO copying image data to zvol
1642026-05-09T03:51:37.976ZMay 09 03:51:37.964 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1652026-05-09T03:51:41.439ZMay 09 03:51:41.427 INFO creating links
1662026-05-09T03:51:41.439ZMay 09 03:51:41.427 DEBG destroying link mgtriou_ox_sn_vnic0
1672026-05-09T03:51:41.463ZMay 09 03:51:41.427 DEBG destroying link mgtriou_ox_sn_sim0
1682026-05-09T03:51:41.463ZMay 09 03:51:41.427 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1692026-05-09T03:51:41.464ZMay 09 03:51:41.430 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1702026-05-09T03:51:41.464ZMay 09 03:51:41.437 DEBG link pair created
1712026-05-09T03:51:41.464ZMay 09 03:51:41.437 DEBG destroying link mgtriou_cr1_vn_vnic0
1722026-05-09T03:51:41.464ZMay 09 03:51:41.437 DEBG destroying link mgtriou_cr1_vn_sim0
1732026-05-09T03:51:41.464ZMay 09 03:51:41.437 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1742026-05-09T03:51:41.464ZMay 09 03:51:41.439 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1752026-05-09T03:51:41.464ZMay 09 03:51:41.445 DEBG link pair created
1762026-05-09T03:51:41.464ZMay 09 03:51:41.445 DEBG destroying link mgtriou_ox_sn_vnic1
1772026-05-09T03:51:41.464ZMay 09 03:51:41.446 DEBG destroying link mgtriou_ox_sn_sim1
1782026-05-09T03:51:41.464ZMay 09 03:51:41.446 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1792026-05-09T03:51:41.464ZMay 09 03:51:41.447 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1802026-05-09T03:51:41.488ZMay 09 03:51:41.453 DEBG link pair created
1812026-05-09T03:51:41.488ZMay 09 03:51:41.453 DEBG destroying link mgtriou_cr2_vn_vnic0
1822026-05-09T03:51:41.488ZMay 09 03:51:41.453 DEBG destroying link mgtriou_cr2_vn_sim0
1832026-05-09T03:51:41.489ZMay 09 03:51:41.453 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1842026-05-09T03:51:41.489ZMay 09 03:51:41.454 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1852026-05-09T03:51:41.489ZMay 09 03:51:41.460 DEBG link pair created
1862026-05-09T03:51:41.489ZMay 09 03:51:41.461 INFO creating external links
1872026-05-09T03:51:41.489ZMay 09 03:51:41.461 DEBG destroying external link mgtriou_ox_vn_vnic2
1882026-05-09T03:51:41.489ZMay 09 03:51:41.461 INFO creating external link mgtriou_ox_vn_vnic2
1892026-05-09T03:51:41.489ZMay 09 03:51:41.462 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1902026-05-09T03:51:41.489ZMay 09 03:51:41.462 DEBG destroying external link mgtriou_cr1_vn_vnic1
1912026-05-09T03:51:41.489ZMay 09 03:51:41.462 INFO creating external link mgtriou_cr1_vn_vnic1
1922026-05-09T03:51:41.489ZMay 09 03:51:41.464 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1932026-05-09T03:51:41.490ZMay 09 03:51:41.464 DEBG destroying external link mgtriou_cr2_vn_vnic1
1942026-05-09T03:51:41.490ZMay 09 03:51:41.464 INFO creating external link mgtriou_cr2_vn_vnic1
1952026-05-09T03:51:41.490ZMay 09 03:51:41.465 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1962026-05-09T03:51:41.490ZMay 09 03:51:41.465 INFO creating nodes
1972026-05-09T03:51:41.490ZMay 09 03:51:41.465 INFO ox: launching node
1982026-05-09T03:51:41.490ZMay 09 03:51:41.467 INFO cr1: launching node
1992026-05-09T03:51:41.490ZMay 09 03:51:41.469 INFO cr2: launching node
2002026-05-09T03:51:41.514ZMay 09 03:51:41.484 INFO launched instance ox with pid 856 on port 62372
2012026-05-09T03:51:41.514ZMay 09 03:51:41.484 INFO ox: instance ensure
2022026-05-09T03:51:41.514ZMay 09 03:51:41.484 INFO launched instance cr1 with pid 857 on port 41054
2032026-05-09T03:51:41.514ZMay 09 03:51:41.485 INFO cr1: instance ensure
2042026-05-09T03:51:41.514ZMay 09 03:51:41.485 INFO launched instance cr2 with pid 858 on port 61447
2052026-05-09T03:51:41.514ZMay 09 03:51:41.485 INFO cr2: instance ensure
2062026-05-09T03:51:43.767ZMay 09 03:51:43.755 INFO cr2: instance ensure completed after 0 retries
2072026-05-09T03:51:43.767ZMay 09 03:51:43.755 INFO cr2: instance run
2082026-05-09T03:51:43.792ZMay 09 03:51:43.756 DEBG [sc] cr2: starting
2092026-05-09T03:51:43.792ZMay 09 03:51:43.756 DEBG [sc] cr2: connecting to [::1]:61447
2102026-05-09T03:51:43.792ZMay 09 03:51:43.757 DEBG [sc] cr2 waiting for prompt
2112026-05-09T03:51:43.892ZMay 09 03:51:43.880 INFO ox: instance ensure completed after 0 retries
2122026-05-09T03:51:43.892ZMay 09 03:51:43.880 INFO ox: instance run
2132026-05-09T03:51:43.916ZMay 09 03:51:43.880 DEBG [sc] ox: starting
2142026-05-09T03:51:43.916ZMay 09 03:51:43.880 DEBG [sc] ox: connecting to [::1]:62372
2152026-05-09T03:51:43.916ZMay 09 03:51:43.881 DEBG [sc] ox waiting for prompt
2162026-05-09T03:51:43.917ZMay 09 03:51:43.902 INFO cr1: instance ensure completed after 0 retries
2172026-05-09T03:51:43.917ZMay 09 03:51:43.902 INFO cr1: instance run
2182026-05-09T03:51:43.917ZMay 09 03:51:43.903 DEBG [sc] cr1: starting
2192026-05-09T03:51:43.917ZMay 09 03:51:43.903 DEBG [sc] cr1: connecting to [::1]:41054
2202026-05-09T03:51:43.917ZMay 09 03:51:43.903 DEBG [sc] cr1 waiting for prompt
2212026-05-09T03:52:00.990ZMay 09 03:52:00.978 DEBG [sc] cr1: logging in
2222026-05-09T03:52:01.393ZMay 09 03:52:01.381 INFO cr1: mounting /opt/cargo-bay
2232026-05-09T03:52:01.393ZMay 09 03:52:01.381 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2242026-05-09T03:52:01.417ZMay 09 03:52:01.402 DEBG [sc] cr1: executing command `cd`
2252026-05-09T03:52:01.441ZMay 09 03:52:01.414 INFO cr1: finished mounting /opt/cargo-bay
2262026-05-09T03:52:01.441ZMay 09 03:52:01.414 DEBG [sc] cr1: executing command `hostname cr1`
2272026-05-09T03:52:01.441ZMay 09 03:52:01.425 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2282026-05-09T03:52:01.469ZMay 09 03:52:01.436 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2292026-05-09T03:52:01.469ZMay 09 03:52:01.447 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2302026-05-09T03:52:01.494ZMay 09 03:52:01.457 INFO cr1: logging out
2312026-05-09T03:52:02.066ZMay 09 03:52:02.054 DEBG [sc] ox: logging in
2322026-05-09T03:52:02.256ZMay 09 03:52:02.244 INFO ox: mounting /opt/cargo-bay
2332026-05-09T03:52:02.256ZMay 09 03:52:02.244 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2342026-05-09T03:52:03.387ZMay 09 03:52:03.375 DEBG [sc] ox: executing command `cd`
2352026-05-09T03:52:03.411ZMay 09 03:52:03.387 INFO ox: finished mounting /opt/cargo-bay
2362026-05-09T03:52:03.411ZMay 09 03:52:03.387 DEBG [sc] ox: executing command `hostname ox`
2372026-05-09T03:52:03.411ZMay 09 03:52:03.398 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2382026-05-09T03:52:03.435ZMay 09 03:52:03.409 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2392026-05-09T03:52:03.435ZMay 09 03:52:03.420 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2402026-05-09T03:52:03.459ZMay 09 03:52:03.431 INFO ox: logging out
2412026-05-09T03:52:03.534ZMay 09 03:52:03.522 INFO cr1: logged out
2422026-05-09T03:52:03.562ZMay 09 03:52:03.550 INFO ox: logged out
2432026-05-09T03:52:05.371ZMay 09 03:52:05.359 DEBG [sc] cr2: logging in
2442026-05-09T03:52:05.772ZMay 09 03:52:05.759 INFO cr2: mounting /opt/cargo-bay
2452026-05-09T03:52:05.772ZMay 09 03:52:05.759 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2462026-05-09T03:52:05.796ZMay 09 03:52:05.771 DEBG [sc] cr2: executing command `cd`
2472026-05-09T03:52:05.796ZMay 09 03:52:05.782 INFO cr2: finished mounting /opt/cargo-bay
2482026-05-09T03:52:05.796ZMay 09 03:52:05.782 DEBG [sc] cr2: executing command `hostname cr2`
2492026-05-09T03:52:05.820ZMay 09 03:52:05.793 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2502026-05-09T03:52:05.820ZMay 09 03:52:05.803 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2512026-05-09T03:52:05.844ZMay 09 03:52:05.815 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2522026-05-09T03:52:05.844ZMay 09 03:52:05.826 INFO cr2: logging out
2532026-05-09T03:52:08.776ZMay 09 03:52:08.764 INFO cr2: logged out
2542026-05-09T03:52:08.800ZMay 09 03:52:08.764 DEBG [sc] ox: starting
2552026-05-09T03:52:08.800ZMay 09 03:52:08.764 DEBG [sc] ox: connecting to [::1]:62372
2562026-05-09T03:52:08.800ZMay 09 03:52:08.765 DEBG [sc] ox waiting for prompt
2572026-05-09T03:52:08.800ZMay 09 03:52:08.776 DEBG [sc] ox: logging in
2582026-05-09T03:52:08.876ZMay 09 03:52:08.864 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2592026-05-09T03:52:13.667ZMay 09 03:52:13.655 DEBG [sc] ox: starting
2602026-05-09T03:52:13.667ZMay 09 03:52:13.655 DEBG [sc] ox: connecting to [::1]:62372
2612026-05-09T03:52:13.691ZMay 09 03:52:13.655 DEBG [sc] ox waiting for prompt
2622026-05-09T03:52:13.691ZMay 09 03:52:13.665 DEBG [sc] ox: logging in
2632026-05-09T03:52:13.765ZMay 09 03:52:13.753 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2642026-05-09T03:52:13.854ZMay 09 03:52:13.842 DEBG [sc] ox: starting
2652026-05-09T03:52:13.854ZMay 09 03:52:13.842 DEBG [sc] ox: connecting to [::1]:62372
2662026-05-09T03:52:13.878ZMay 09 03:52:13.843 DEBG [sc] ox waiting for prompt
2672026-05-09T03:52:13.878ZMay 09 03:52:13.853 DEBG [sc] ox: logging in
2682026-05-09T03:52:13.953ZMay 09 03:52:13.941 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2692026-05-09T03:52:14.020ZMay 09 03:52:14.008 INFO cr1: installing frr
2702026-05-09T03:52:14.020ZMay 09 03:52:14.008 INFO waiting for ceos to initialize
2712026-05-09T03:52:14.020ZMay 09 03:52:14.008 INFO ox: setting up npuvm
2722026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr2: starting
2732026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr2: connecting to [::1]:61447
2742026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr1: starting
2752026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr1: connecting to [::1]:41054
2762026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] ox: starting
2772026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] ox: connecting to [::1]:62372
2782026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr2 waiting for prompt
2792026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] ox waiting for prompt
2802026-05-09T03:52:14.044ZMay 09 03:52:14.008 DEBG [sc] cr1 waiting for prompt
2812026-05-09T03:52:14.044ZMay 09 03:52:14.019 DEBG [sc] ox: logging in
2822026-05-09T03:52:14.044ZMay 09 03:52:14.019 DEBG [sc] cr2: logging in
2832026-05-09T03:52:14.044ZMay 09 03:52:14.020 DEBG [sc] cr1: logging in
2842026-05-09T03:52:14.108ZMay 09 03:52:14.095 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2852026-05-09T03:52:14.165ZMay 09 03:52:14.153 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2862026-05-09T03:52:14.443ZMay 09 03:52:14.431 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2872026-05-09T03:52:16.410ZMay 09 03:52:16.398 INFO cr2: executing eos script show version
2882026-05-09T03:52:16.411ZMay 09 03:52:16.398 DEBG [sc] cr2: starting
2892026-05-09T03:52:16.411ZMay 09 03:52:16.398 DEBG [sc] cr2: connecting to [::1]:61447
2902026-05-09T03:52:16.435ZMay 09 03:52:16.399 DEBG [sc] cr2 waiting for prompt
2912026-05-09T03:52:16.435ZMay 09 03:52:16.409 DEBG [sc] cr2: logging in
2922026-05-09T03:52:16.565ZMay 09 03:52:16.553 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2932026-05-09T03:52:19.593ZMay 09 03:52:19.580 DEBG [sc] ox: starting
2942026-05-09T03:52:19.593ZMay 09 03:52:19.580 DEBG [sc] ox: connecting to [::1]:62372
2952026-05-09T03:52:19.617ZMay 09 03:52:19.581 DEBG [sc] ox waiting for prompt
2962026-05-09T03:52:19.617ZMay 09 03:52:19.592 DEBG [sc] ox: logging in
2972026-05-09T03:52:19.681ZMay 09 03:52:19.669 DEBG [sc] ox: executing command `chmod +x npuvm`
2982026-05-09T03:52:19.737ZMay 09 03:52:19.725 DEBG [sc] ox: starting
2992026-05-09T03:52:19.737ZMay 09 03:52:19.725 DEBG [sc] ox: connecting to [::1]:62372
3002026-05-09T03:52:19.761ZMay 09 03:52:19.725 DEBG [sc] ox waiting for prompt
3012026-05-09T03:52:19.761ZMay 09 03:52:19.736 DEBG [sc] ox: logging in
3022026-05-09T03:52:19.825ZMay 09 03:52:19.813 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3032026-05-09T03:52:26.583ZMay 09 03:52:26.571 DEBG [sc] cr2: starting
3042026-05-09T03:52:26.583ZMay 09 03:52:26.571 DEBG [sc] cr2: connecting to [::1]:61447
3052026-05-09T03:52:26.608ZMay 09 03:52:26.572 DEBG [sc] cr2 waiting for prompt
3062026-05-09T03:52:26.608ZMay 09 03:52:26.582 DEBG [sc] cr2: logging in
3072026-05-09T03:52:26.738ZMay 09 03:52:26.726 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3082026-05-09T03:52:28.875ZMay 09 03:52:28.862 INFO cr2: executing eos script show version
3092026-05-09T03:52:28.875ZMay 09 03:52:28.862 DEBG [sc] cr2: starting
3102026-05-09T03:52:28.875ZMay 09 03:52:28.862 DEBG [sc] cr2: connecting to [::1]:61447
3112026-05-09T03:52:28.899ZMay 09 03:52:28.863 DEBG [sc] cr2 waiting for prompt
3122026-05-09T03:52:28.899ZMay 09 03:52:28.873 DEBG [sc] cr2: logging in
3132026-05-09T03:52:29.040ZMay 09 03:52:29.027 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3142026-05-09T03:52:31.404ZMay 09 03:52:31.391 DEBG [sc] cr2: starting
3152026-05-09T03:52:31.404ZMay 09 03:52:31.391 DEBG [sc] cr2: connecting to [::1]:61447
3162026-05-09T03:52:31.428ZMay 09 03:52:31.391 DEBG [sc] cr2 waiting for prompt
3172026-05-09T03:52:31.428ZMay 09 03:52:31.403 DEBG [sc] cr2: logging in
3182026-05-09T03:52:31.559ZMay 09 03:52:31.546 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3192026-05-09T03:52:33.713ZMay 09 03:52:33.700 INFO cr2: executing eos script show version
3202026-05-09T03:52:33.713ZMay 09 03:52:33.700 DEBG [sc] cr2: starting
3212026-05-09T03:52:33.713ZMay 09 03:52:33.700 DEBG [sc] cr2: connecting to [::1]:61447
3222026-05-09T03:52:33.737ZMay 09 03:52:33.700 DEBG [sc] cr2 waiting for prompt
3232026-05-09T03:52:33.737ZMay 09 03:52:33.710 DEBG [sc] cr2: logging in
3242026-05-09T03:52:33.879ZMay 09 03:52:33.865 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3252026-05-09T03:52:36.352ZMay 09 03:52:36.338 INFO cr2: executing eos script
3262026-05-09T03:52:36.352Z enable
3272026-05-09T03:52:36.352Z configure
3282026-05-09T03:52:36.352Z ipv6 unicast-routing
3292026-05-09T03:52:36.352Z ip routing ipv6 interfaces
3302026-05-09T03:52:36.352Z ip routing
3312026-05-09T03:52:36.353Z ip route 1.2.3.0/24 null0
3322026-05-09T03:52:36.353Z ipv6 route fd99::/64 null0
3332026-05-09T03:52:36.353Z interface et1
3342026-05-09T03:52:36.353Z no switchport
3352026-05-09T03:52:36.353Z ipv6 enable
3362026-05-09T03:52:36.353Z
3372026-05-09T03:52:36.353Z router bgp 45
3382026-05-09T03:52:36.353Z router-id 1.2.3.1
3392026-05-09T03:52:36.353Z no bgp default ipv4-unicast
3402026-05-09T03:52:36.353Z timers bgp 2 6
3412026-05-09T03:52:36.353Z neighbor ebgp peer group
3422026-05-09T03:52:36.353Z neighbor ebgp remote-as 33
3432026-05-09T03:52:36.353Z neighbor interface Et1 peer-group ebgp
3442026-05-09T03:52:36.353Z address-family ipv4
3452026-05-09T03:52:36.353Z neighbor ebgp activate
3462026-05-09T03:52:36.353Z neighbor ebgp next-hop address-family ipv6 originate
3472026-05-09T03:52:36.353Z network 1.2.3.0/24
3482026-05-09T03:52:36.353Z exit
3492026-05-09T03:52:36.353Z address-family ipv6
3502026-05-09T03:52:36.353Z neighbor ebgp activate
3512026-05-09T03:52:36.354Z neighbor ebgp next-hop address-family ipv6 originate
3522026-05-09T03:52:36.354Z network fd99::/64
3532026-05-09T03:52:36.354Z exit
3542026-05-09T03:52:36.354Z exit
3552026-05-09T03:52:36.354Z
3562026-05-09T03:52:36.354ZMay 09 03:52:36.338 DEBG [sc] cr2: starting
3572026-05-09T03:52:36.354ZMay 09 03:52:36.338 DEBG [sc] cr2: connecting to [::1]:61447
3582026-05-09T03:52:36.378ZMay 09 03:52:36.339 DEBG [sc] cr2 waiting for prompt
3592026-05-09T03:52:36.378ZMay 09 03:52:36.349 DEBG [sc] cr2: logging in
3602026-05-09T03:52:36.505ZMay 09 03:52:36.492 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3612026-05-09T03:52:36.506Z enable
3622026-05-09T03:52:36.506Z configure
3632026-05-09T03:52:36.506Z ipv6 unicast-routing
3642026-05-09T03:52:36.506Z ip routing ipv6 interfaces
3652026-05-09T03:52:36.506Z ip routing
3662026-05-09T03:52:36.506Z ip route 1.2.3.0/24 null0
3672026-05-09T03:52:36.506Z ipv6 route fd99::/64 null0
3682026-05-09T03:52:36.506Z interface et1
3692026-05-09T03:52:36.506Z no switchport
3702026-05-09T03:52:36.506Z ipv6 enable
3712026-05-09T03:52:36.506Z
3722026-05-09T03:52:36.506Z router bgp 45
3732026-05-09T03:52:36.506Z router-id 1.2.3.1
3742026-05-09T03:52:36.506Z no bgp default ipv4-unicast
3752026-05-09T03:52:36.506Z timers bgp 2 6
3762026-05-09T03:52:36.506Z neighbor ebgp peer group
3772026-05-09T03:52:36.506Z neighbor ebgp remote-as 33
3782026-05-09T03:52:36.506Z neighbor interface Et1 peer-group ebgp
3792026-05-09T03:52:36.506Z address-family ipv4
3802026-05-09T03:52:36.506Z neighbor ebgp activate
3812026-05-09T03:52:36.506Z neighbor ebgp next-hop address-family ipv6 originate
3822026-05-09T03:52:36.506Z network 1.2.3.0/24
3832026-05-09T03:52:36.506Z exit
3842026-05-09T03:52:36.506Z address-family ipv6
3852026-05-09T03:52:36.506Z neighbor ebgp activate
3862026-05-09T03:52:36.506Z neighbor ebgp next-hop address-family ipv6 originate
3872026-05-09T03:52:36.506Z network fd99::/64
3882026-05-09T03:52:36.506Z exit
3892026-05-09T03:52:36.506Z exit
3902026-05-09T03:52:36.506Z '`
3912026-05-09T03:52:52.153ZMay 09 03:52:52.139 INFO cr1: enabling frr daemon bgpd
3922026-05-09T03:52:52.177ZMay 09 03:52:52.139 DEBG [sc] cr1: starting
3932026-05-09T03:52:52.177ZMay 09 03:52:52.140 DEBG [sc] cr1: connecting to [::1]:41054
3942026-05-09T03:52:52.177ZMay 09 03:52:52.140 DEBG [sc] cr1 waiting for prompt
3952026-05-09T03:52:52.177ZMay 09 03:52:52.150 DEBG [sc] cr1: logging in
3962026-05-09T03:52:52.307ZMay 09 03:52:52.294 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
3972026-05-09T03:52:54.403ZMay 09 03:52:54.390 DEBG [sc] cr1: starting
3982026-05-09T03:52:54.404ZMay 09 03:52:54.390 DEBG [sc] cr1: connecting to [::1]:41054
3992026-05-09T03:52:54.427ZMay 09 03:52:54.391 DEBG [sc] cr1 waiting for prompt
4002026-05-09T03:52:54.428ZMay 09 03:52:54.401 DEBG [sc] cr1: logging in
4012026-05-09T03:52:54.557ZMay 09 03:52:54.544 DEBG [sc] cr1: executing command `systemctl restart frr`
4022026-05-09T03:53:02.185ZMay 09 03:53:02.171 INFO cr1: executing frr script
4032026-05-09T03:53:02.185Z configure
4042026-05-09T03:53:02.185Z ip forwarding
4052026-05-09T03:53:02.185Z ipv6 forwarding
4062026-05-09T03:53:02.185Z ip route 1.2.3.0/24 null0
4072026-05-09T03:53:02.185Z ipv6 route fd99::/64 null0
4082026-05-09T03:53:02.185Z router bgp 44
4092026-05-09T03:53:02.185Z no bgp ebgp-requires-policy
4102026-05-09T03:53:02.185Z timers bgp 2 6
4112026-05-09T03:53:02.185Z neighbor enp0s8 interface remote-as external
4122026-05-09T03:53:02.185Z neighbor enp0s8 timers connect 1
4132026-05-09T03:53:02.186Z address-family ipv4 unicast
4142026-05-09T03:53:02.186Z network 1.2.3.0/24
4152026-05-09T03:53:02.186Z neighbor enp0s8 activate
4162026-05-09T03:53:02.186Z exit-address-family
4172026-05-09T03:53:02.186Z address-family ipv6 unicast
4182026-05-09T03:53:02.186Z network fd99::/64
4192026-05-09T03:53:02.186Z neighbor enp0s8 activate
4202026-05-09T03:53:02.186Z exit-address-family
4212026-05-09T03:53:02.186Z exit
4222026-05-09T03:53:02.186Z
4232026-05-09T03:53:02.186ZMay 09 03:53:02.171 DEBG [sc] cr1: starting
4242026-05-09T03:53:02.186ZMay 09 03:53:02.171 DEBG [sc] cr1: connecting to [::1]:41054
4252026-05-09T03:53:02.210ZMay 09 03:53:02.172 DEBG [sc] cr1 waiting for prompt
4262026-05-09T03:53:02.210ZMay 09 03:53:02.183 DEBG [sc] cr1: logging in
4272026-05-09T03:53:02.317ZMay 09 03:53:02.304 DEBG [sc] cr1: executing command `vtysh -c '' -c ' configure' -c ' ip forwarding' -c ' ipv6 forwarding' -c ' ip route 1.2.3.0/24 null0' -c ' ipv6 route fd99::/64 null0' -c ' router bgp 44' -c ' no bgp ebgp-requires-policy' -c ' timers bgp 2 6' -c ' neighbor enp0s8 interface remote-as external' -c ' neighbor enp0s8 timers connect 1 ' -c ' address-family ipv4 unicast' -c ' network 1.2.3.0/24' -c ' neighbor enp0s8 activate' -c ' exit-address-family' -c ' address-family ipv6 unicast' -c ' network fd99::/64' -c ' neighbor enp0s8 activate' -c ' exit-address-family' -c ' exit' -c ' '`
4282026-05-09T03:54:09.994ZMay 09 03:54:09.981 DEBG [sc] ox: starting
4292026-05-09T03:54:09.995ZMay 09 03:54:09.981 DEBG [sc] ox: connecting to [::1]:62372
4302026-05-09T03:54:10.019ZMay 09 03:54:09.982 DEBG [sc] ox waiting for prompt
4312026-05-09T03:54:10.019ZMay 09 03:54:09.992 DEBG [sc] ox: logging in
4322026-05-09T03:54:10.083ZMay 09 03:54:10.069 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4332026-05-09T03:54:10.385ZMay 09 03:54:10.372 DEBG [sc] ox: starting
4342026-05-09T03:54:10.386ZMay 09 03:54:10.372 DEBG [sc] ox: connecting to [::1]:62372
4352026-05-09T03:54:10.410ZMay 09 03:54:10.372 DEBG [sc] ox waiting for prompt
4362026-05-09T03:54:10.410ZMay 09 03:54:10.384 DEBG [sc] ox: logging in
4372026-05-09T03:54:10.474ZMay 09 03:54:10.460 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4382026-05-09T03:54:11.497ZMay 09 03:54:11.484 DEBG [sc] ox: starting
4392026-05-09T03:54:11.497ZMay 09 03:54:11.484 DEBG [sc] ox: connecting to [::1]:62372
4402026-05-09T03:54:11.522ZMay 09 03:54:11.484 DEBG [sc] ox waiting for prompt
4412026-05-09T03:54:11.522ZMay 09 03:54:11.484 DEBG [sc] ox: logging in
4422026-05-09T03:54:11.574ZMay 09 03:54:11.561 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4432026-05-09T03:54:11.641ZMay 09 03:54:11.628 DEBG [sc] ox: starting
4442026-05-09T03:54:11.641ZMay 09 03:54:11.628 DEBG [sc] ox: connecting to [::1]:62372
4452026-05-09T03:54:11.666ZMay 09 03:54:11.628 DEBG [sc] ox waiting for prompt
4462026-05-09T03:54:11.666ZMay 09 03:54:11.638 DEBG [sc] ox: logging in
4472026-05-09T03:54:11.729ZMay 09 03:54:11.716 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4482026-05-09T03:54:11.795ZMay 09 03:54:11.782 DEBG [sc] ox: starting
4492026-05-09T03:54:11.795ZMay 09 03:54:11.782 DEBG [sc] ox: connecting to [::1]:62372
4502026-05-09T03:54:11.820ZMay 09 03:54:11.782 DEBG [sc] ox waiting for prompt
4512026-05-09T03:54:11.820ZMay 09 03:54:11.793 DEBG [sc] ox: logging in
4522026-05-09T03:54:11.883ZMay 09 03:54:11.870 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4532026-05-09T03:54:11.949ZMay 09 03:54:11.936 DEBG [sc] ox: starting
4542026-05-09T03:54:11.950ZMay 09 03:54:11.936 DEBG [sc] ox: connecting to [::1]:62372
4552026-05-09T03:54:11.973ZMay 09 03:54:11.937 DEBG [sc] ox waiting for prompt
4562026-05-09T03:54:11.973ZMay 09 03:54:11.948 DEBG [sc] ox: logging in
4572026-05-09T03:54:12.040ZMay 09 03:54:12.026 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4582026-05-09T03:54:12.107ZMay 09 03:54:12.093 DEBG [sc] ox: starting
4592026-05-09T03:54:12.107ZMay 09 03:54:12.093 DEBG [sc] ox: connecting to [::1]:62372
4602026-05-09T03:54:12.131ZMay 09 03:54:12.094 DEBG [sc] ox waiting for prompt
4612026-05-09T03:54:12.131ZMay 09 03:54:12.103 DEBG [sc] ox: logging in
4622026-05-09T03:54:12.194ZMay 09 03:54:12.180 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4632026-05-09T03:54:12.260ZMay 09 03:54:12.247 DEBG [sc] ox: starting
4642026-05-09T03:54:12.260ZMay 09 03:54:12.247 DEBG [sc] ox: connecting to [::1]:62372
4652026-05-09T03:54:12.284ZMay 09 03:54:12.247 DEBG [sc] ox waiting for prompt
4662026-05-09T03:54:12.284ZMay 09 03:54:12.258 DEBG [sc] ox: logging in
4672026-05-09T03:54:12.348ZMay 09 03:54:12.334 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4682026-05-09T03:54:12.404ZMay 09 03:54:12.390 DEBG [sc] ox: starting
4692026-05-09T03:54:12.404ZMay 09 03:54:12.390 DEBG [sc] ox: connecting to [::1]:62372
4702026-05-09T03:54:12.428ZMay 09 03:54:12.391 DEBG [sc] ox waiting for prompt
4712026-05-09T03:54:12.428ZMay 09 03:54:12.400 DEBG [sc] ox: logging in
4722026-05-09T03:54:12.492ZMay 09 03:54:12.479 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4732026-05-09T03:54:12.547ZMay 09 03:54:12.534 DEBG [sc] ox: starting
4742026-05-09T03:54:12.547ZMay 09 03:54:12.534 DEBG [sc] ox: connecting to [::1]:62372
4752026-05-09T03:54:12.571ZMay 09 03:54:12.534 DEBG [sc] ox waiting for prompt
4762026-05-09T03:54:12.571ZMay 09 03:54:12.545 DEBG [sc] ox: logging in
4772026-05-09T03:54:12.635ZMay 09 03:54:12.621 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4782026-05-09T03:54:12.695ZMay 09 03:54:12.682 INFO adding BGP router to mgd
4792026-05-09T03:54:15.869ZMay 09 03:54:15.855 INFO cr1: executing frr script show ip bgp json
4802026-05-09T03:54:15.869ZMay 09 03:54:15.855 DEBG [sc] cr1: starting
4812026-05-09T03:54:15.893ZMay 09 03:54:15.855 DEBG [sc] cr1: connecting to [::1]:41054
4822026-05-09T03:54:15.894ZMay 09 03:54:15.856 DEBG [sc] cr1 waiting for prompt
4832026-05-09T03:54:15.894ZMay 09 03:54:15.866 DEBG [sc] cr1: logging in
4842026-05-09T03:54:16.227ZMay 09 03:54:16.214 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4852026-05-09T03:54:18.363ZMay 09 03:54:18.349 INFO cr1: executing frr script show bgp json
4862026-05-09T03:54:18.363ZMay 09 03:54:18.349 DEBG [sc] cr1: starting
4872026-05-09T03:54:18.363ZMay 09 03:54:18.349 DEBG [sc] cr1: connecting to [::1]:41054
4882026-05-09T03:54:18.387ZMay 09 03:54:18.350 DEBG [sc] cr1 waiting for prompt
4892026-05-09T03:54:18.387ZMay 09 03:54:18.360 DEBG [sc] cr1: logging in
4902026-05-09T03:54:18.496ZMay 09 03:54:18.483 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
4912026-05-09T03:54:20.616ZMay 09 03:54:20.602 INFO cr2: executing eos script show ip bgp | json
4922026-05-09T03:54:20.616ZMay 09 03:54:20.603 DEBG [sc] cr2: starting
4932026-05-09T03:54:20.616ZMay 09 03:54:20.603 DEBG [sc] cr2: connecting to [::1]:61447
4942026-05-09T03:54:20.640ZMay 09 03:54:20.603 DEBG [sc] cr2 waiting for prompt
4952026-05-09T03:54:20.640ZMay 09 03:54:20.615 DEBG [sc] cr2: logging in
4962026-05-09T03:54:20.958ZMay 09 03:54:20.945 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
4972026-05-09T03:54:23.335ZMay 09 03:54:23.321 INFO cr2: executing eos script show ipv6 bgp | json
4982026-05-09T03:54:23.335ZMay 09 03:54:23.321 DEBG [sc] cr2: starting
4992026-05-09T03:54:23.335ZMay 09 03:54:23.321 DEBG [sc] cr2: connecting to [::1]:61447
5002026-05-09T03:54:23.359ZMay 09 03:54:23.322 DEBG [sc] cr2 waiting for prompt
5012026-05-09T03:54:23.359ZMay 09 03:54:23.333 DEBG [sc] cr2: logging in
5022026-05-09T03:54:23.489ZMay 09 03:54:23.475 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5032026-05-09T03:54:25.852ZMay 09 03:54:25.838 INFO trio bgp unnumbered test passed 🎉
5042026-05-09T03:54:25.854ZMay 09 03:54:25.838 INFO destroying runner for deployment mgtriou
5052026-05-09T03:54:25.854ZMay 09 03:54:25.838 INFO destroying deployment mgtriou
5062026-05-09T03:54:25.854ZMay 09 03:54:25.838 INFO destroying nodes
5072026-05-09T03:54:25.960ZMay 09 03:54:25.946 INFO destroying links
5082026-05-09T03:54:25.960ZMay 09 03:54:25.946 INFO destroying link mgtriou_ox_sn_vnic0
5092026-05-09T03:54:25.984ZMay 09 03:54:25.949 INFO destroying link mgtriou_ox_sn_sim0
5102026-05-09T03:54:25.984ZMay 09 03:54:25.950 INFO destroying link mgtriou_cr1_vn_vnic0
5112026-05-09T03:54:26.967ZMay 09 03:54:26.953 INFO destroying link mgtriou_cr1_vn_sim0
5122026-05-09T03:54:26.991ZMay 09 03:54:26.954 INFO destroying link mgtriou_ox_sn_vnic1
5132026-05-09T03:54:26.991ZMay 09 03:54:26.955 INFO destroying link mgtriou_ox_sn_sim1
5142026-05-09T03:54:26.991ZMay 09 03:54:26.957 INFO destroying link mgtriou_cr2_vn_vnic0
5152026-05-09T03:54:26.991ZMay 09 03:54:26.958 INFO destroying link mgtriou_cr2_vn_sim0
5162026-05-09T03:54:26.991ZMay 09 03:54:26.959 INFO destroying external links
5172026-05-09T03:54:26.991ZMay 09 03:54:26.959 INFO destroying external link mgtriou_ox_vn_vnic2
5182026-05-09T03:54:26.991ZMay 09 03:54:26.960 INFO destroying external link mgtriou_cr1_vn_vnic1
5192026-05-09T03:54:26.992ZMay 09 03:54:26.961 INFO destroying external link mgtriou_cr2_vn_vnic1
5202026-05-09T03:54:26.992ZMay 09 03:54:26.963 INFO destroying images
5212026-05-09T03:54:27.452ZMay 09 03:54:27.438 INFO destroying workspace at .falcon
5222026-05-09T03:54:27.476Z+ RUST_LOG=debug
5232026-05-09T03:54:27.476Z+ pfexec ./falcon-lab run trio-bfd-static-routing
5242026-05-09T03:54:27.500ZMay 09 03:54:27.480 DEBG using default route interface igb0
5252026-05-09T03:54:27.500ZMay 09 03:54:27.480 DEBG using default route interface igb0
5262026-05-09T03:54:27.500ZMay 09 03:54:27.480 DEBG using default route interface igb0
5272026-05-09T03:54:27.500ZMay 09 03:54:27.480 INFO launching runner: deployment(mgtriobfd) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
5282026-05-09T03:54:27.500ZMay 09 03:54:27.480 INFO starting preflight for deployment mgtriobfd
5292026-05-09T03:54:28.145ZMay 09 03:54:28.132 INFO creating links
5302026-05-09T03:54:28.145ZMay 09 03:54:28.132 DEBG destroying link mgtriobfd_ox_sn_vnic0
5312026-05-09T03:54:28.145ZMay 09 03:54:28.132 DEBG destroying link mgtriobfd_ox_sn_sim0
5322026-05-09T03:54:28.169ZMay 09 03:54:28.132 INFO creating simnet link 'mgtriobfd_ox_sn_sim0'
5332026-05-09T03:54:28.169ZMay 09 03:54:28.134 INFO creating vnic link 'mgtriobfd_ox_sn_vnic0'
5342026-05-09T03:54:28.169ZMay 09 03:54:28.142 DEBG link pair created
5352026-05-09T03:54:28.169ZMay 09 03:54:28.142 DEBG destroying link mgtriobfd_cr1_vn_vnic0
5362026-05-09T03:54:28.169ZMay 09 03:54:28.142 DEBG destroying link mgtriobfd_cr1_vn_sim0
5372026-05-09T03:54:28.169ZMay 09 03:54:28.142 INFO creating simnet link 'mgtriobfd_cr1_vn_sim0'
5382026-05-09T03:54:28.169ZMay 09 03:54:28.143 INFO creating vnic link 'mgtriobfd_cr1_vn_vnic0'
5392026-05-09T03:54:28.169ZMay 09 03:54:28.150 DEBG link pair created
5402026-05-09T03:54:28.169ZMay 09 03:54:28.150 DEBG destroying link mgtriobfd_ox_sn_vnic1
5412026-05-09T03:54:28.169ZMay 09 03:54:28.150 DEBG destroying link mgtriobfd_ox_sn_sim1
5422026-05-09T03:54:28.169ZMay 09 03:54:28.150 INFO creating simnet link 'mgtriobfd_ox_sn_sim1'
5432026-05-09T03:54:28.169ZMay 09 03:54:28.151 INFO creating vnic link 'mgtriobfd_ox_sn_vnic1'
5442026-05-09T03:54:28.193ZMay 09 03:54:28.158 DEBG link pair created
5452026-05-09T03:54:28.193ZMay 09 03:54:28.158 DEBG destroying link mgtriobfd_cr2_vn_vnic0
5462026-05-09T03:54:28.193ZMay 09 03:54:28.158 DEBG destroying link mgtriobfd_cr2_vn_sim0
5472026-05-09T03:54:28.194ZMay 09 03:54:28.158 INFO creating simnet link 'mgtriobfd_cr2_vn_sim0'
5482026-05-09T03:54:28.194ZMay 09 03:54:28.160 INFO creating vnic link 'mgtriobfd_cr2_vn_vnic0'
5492026-05-09T03:54:28.194ZMay 09 03:54:28.166 DEBG link pair created
5502026-05-09T03:54:28.194ZMay 09 03:54:28.166 INFO creating external links
5512026-05-09T03:54:28.194ZMay 09 03:54:28.166 DEBG destroying external link mgtriobfd_ox_vn_vnic2
5522026-05-09T03:54:28.194ZMay 09 03:54:28.166 INFO creating external link mgtriobfd_ox_vn_vnic2
5532026-05-09T03:54:28.194ZMay 09 03:54:28.168 DEBG external link mgtriobfd_ox_vn_vnic2@igb0 created
5542026-05-09T03:54:28.194ZMay 09 03:54:28.168 DEBG destroying external link mgtriobfd_cr1_vn_vnic1
5552026-05-09T03:54:28.194ZMay 09 03:54:28.168 INFO creating external link mgtriobfd_cr1_vn_vnic1
5562026-05-09T03:54:28.194ZMay 09 03:54:28.169 DEBG external link mgtriobfd_cr1_vn_vnic1@igb0 created
5572026-05-09T03:54:28.194ZMay 09 03:54:28.169 DEBG destroying external link mgtriobfd_cr2_vn_vnic1
5582026-05-09T03:54:28.194ZMay 09 03:54:28.169 INFO creating external link mgtriobfd_cr2_vn_vnic1
5592026-05-09T03:54:28.194ZMay 09 03:54:28.170 DEBG external link mgtriobfd_cr2_vn_vnic1@igb0 created
5602026-05-09T03:54:28.194ZMay 09 03:54:28.170 INFO creating nodes
5612026-05-09T03:54:28.195ZMay 09 03:54:28.170 INFO ox: launching node
5622026-05-09T03:54:28.195ZMay 09 03:54:28.172 INFO cr1: launching node
5632026-05-09T03:54:28.195ZMay 09 03:54:28.174 INFO cr2: launching node
5642026-05-09T03:54:28.219ZMay 09 03:54:28.188 INFO launched instance ox with pid 895 on port 58746
5652026-05-09T03:54:28.219ZMay 09 03:54:28.188 INFO ox: instance ensure
5662026-05-09T03:54:28.219ZMay 09 03:54:28.188 INFO launched instance cr1 with pid 896 on port 39020
5672026-05-09T03:54:28.219ZMay 09 03:54:28.189 INFO cr1: instance ensure
5682026-05-09T03:54:28.219ZMay 09 03:54:28.189 INFO launched instance cr2 with pid 897 on port 43868
5692026-05-09T03:54:28.219ZMay 09 03:54:28.189 INFO cr2: instance ensure
5702026-05-09T03:54:30.241ZMay 09 03:54:30.227 INFO cr2: instance ensure completed after 0 retries
5712026-05-09T03:54:30.241ZMay 09 03:54:30.227 INFO cr2: instance run
5722026-05-09T03:54:30.265ZMay 09 03:54:30.228 DEBG [sc] cr2: starting
5732026-05-09T03:54:30.266ZMay 09 03:54:30.228 DEBG [sc] cr2: connecting to [::1]:43868
5742026-05-09T03:54:30.266ZMay 09 03:54:30.229 DEBG [sc] cr2 waiting for prompt
5752026-05-09T03:54:30.433ZMay 09 03:54:30.420 INFO cr1: instance ensure completed after 0 retries
5762026-05-09T03:54:30.434ZMay 09 03:54:30.420 INFO cr1: instance run
5772026-05-09T03:54:30.458ZMay 09 03:54:30.421 DEBG [sc] cr1: starting
5782026-05-09T03:54:30.458ZMay 09 03:54:30.421 DEBG [sc] cr1: connecting to [::1]:39020
5792026-05-09T03:54:30.458ZMay 09 03:54:30.421 DEBG [sc] cr1 waiting for prompt
5802026-05-09T03:54:30.458ZMay 09 03:54:30.440 INFO ox: instance ensure completed after 0 retries
5812026-05-09T03:54:30.458ZMay 09 03:54:30.440 INFO ox: instance run
5822026-05-09T03:54:30.458ZMay 09 03:54:30.441 DEBG [sc] ox: starting
5832026-05-09T03:54:30.458ZMay 09 03:54:30.441 DEBG [sc] ox: connecting to [::1]:58746
5842026-05-09T03:54:30.458ZMay 09 03:54:30.441 DEBG [sc] ox waiting for prompt
5852026-05-09T03:54:47.577ZMay 09 03:54:47.563 DEBG [sc] cr1: logging in
5862026-05-09T03:54:47.996ZMay 09 03:54:47.983 INFO cr1: mounting /opt/cargo-bay
5872026-05-09T03:54:47.996ZMay 09 03:54:47.983 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5882026-05-09T03:54:48.021ZMay 09 03:54:48.005 DEBG [sc] cr1: executing command `cd`
5892026-05-09T03:54:48.045ZMay 09 03:54:48.016 INFO cr1: finished mounting /opt/cargo-bay
5902026-05-09T03:54:48.045ZMay 09 03:54:48.016 DEBG [sc] cr1: executing command `hostname cr1`
5912026-05-09T03:54:48.045ZMay 09 03:54:48.027 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
5922026-05-09T03:54:48.069ZMay 09 03:54:48.038 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
5932026-05-09T03:54:48.069ZMay 09 03:54:48.050 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
5942026-05-09T03:54:48.093ZMay 09 03:54:48.061 INFO cr1: logging out
5952026-05-09T03:54:50.158ZMay 09 03:54:50.144 INFO cr1: logged out
5962026-05-09T03:54:51.114ZMay 09 03:54:51.100 DEBG [sc] ox: logging in
5972026-05-09T03:54:51.266ZMay 09 03:54:51.252 INFO ox: mounting /opt/cargo-bay
5982026-05-09T03:54:51.266ZMay 09 03:54:51.252 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5992026-05-09T03:54:51.927ZMay 09 03:54:51.913 DEBG [sc] cr2: logging in
6002026-05-09T03:54:52.236ZMay 09 03:54:52.223 DEBG [sc] ox: executing command `cd`
6012026-05-09T03:54:52.261ZMay 09 03:54:52.234 INFO ox: finished mounting /opt/cargo-bay
6022026-05-09T03:54:52.261ZMay 09 03:54:52.234 DEBG [sc] ox: executing command `hostname ox`
6032026-05-09T03:54:52.261ZMay 09 03:54:52.244 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
6042026-05-09T03:54:52.285ZMay 09 03:54:52.256 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
6052026-05-09T03:54:52.285ZMay 09 03:54:52.267 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
6062026-05-09T03:54:52.309ZMay 09 03:54:52.278 INFO ox: logging out
6072026-05-09T03:54:52.379ZMay 09 03:54:52.365 INFO ox: logged out
6082026-05-09T03:54:52.409ZMay 09 03:54:52.395 INFO cr2: mounting /opt/cargo-bay
6092026-05-09T03:54:52.409ZMay 09 03:54:52.395 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
6102026-05-09T03:54:52.433ZMay 09 03:54:52.417 DEBG [sc] cr2: executing command `cd`
6112026-05-09T03:54:52.457ZMay 09 03:54:52.428 INFO cr2: finished mounting /opt/cargo-bay
6122026-05-09T03:54:52.457ZMay 09 03:54:52.428 DEBG [sc] cr2: executing command `hostname cr2`
6132026-05-09T03:54:52.457ZMay 09 03:54:52.439 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
6142026-05-09T03:54:52.481ZMay 09 03:54:52.450 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
6152026-05-09T03:54:52.481ZMay 09 03:54:52.461 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
6162026-05-09T03:54:52.505ZMay 09 03:54:52.472 INFO cr2: logging out
6172026-05-09T03:54:55.400ZMay 09 03:54:55.387 INFO cr2: logged out
6182026-05-09T03:54:55.424ZMay 09 03:54:55.387 DEBG [sc] ox: starting
6192026-05-09T03:54:55.424ZMay 09 03:54:55.387 DEBG [sc] ox: connecting to [::1]:58746
6202026-05-09T03:54:55.424ZMay 09 03:54:55.388 DEBG [sc] ox waiting for prompt
6212026-05-09T03:54:55.425ZMay 09 03:54:55.399 DEBG [sc] ox: logging in
6222026-05-09T03:54:55.500ZMay 09 03:54:55.487 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
6232026-05-09T03:55:02.100ZMay 09 03:55:02.086 DEBG [sc] ox: starting
6242026-05-09T03:55:02.100ZMay 09 03:55:02.086 DEBG [sc] ox: connecting to [::1]:58746
6252026-05-09T03:55:02.124ZMay 09 03:55:02.087 DEBG [sc] ox waiting for prompt
6262026-05-09T03:55:02.125ZMay 09 03:55:02.097 DEBG [sc] ox: logging in
6272026-05-09T03:55:02.188ZMay 09 03:55:02.174 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
6282026-05-09T03:55:02.275ZMay 09 03:55:02.262 DEBG [sc] ox: starting
6292026-05-09T03:55:02.275ZMay 09 03:55:02.262 DEBG [sc] ox: connecting to [::1]:58746
6302026-05-09T03:55:02.300ZMay 09 03:55:02.263 DEBG [sc] ox waiting for prompt
6312026-05-09T03:55:02.300ZMay 09 03:55:02.273 DEBG [sc] ox: logging in
6322026-05-09T03:55:02.375ZMay 09 03:55:02.361 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
6332026-05-09T03:55:02.441ZMay 09 03:55:02.427 INFO waiting for ceos to initialize
6342026-05-09T03:55:02.441ZMay 09 03:55:02.427 INFO cr1: installing frr
6352026-05-09T03:55:02.441ZMay 09 03:55:02.427 INFO ox: setting up npuvm
6362026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr2: starting
6372026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr1: starting
6382026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr2: connecting to [::1]:43868
6392026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr1: connecting to [::1]:39020
6402026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] ox: starting
6412026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] ox: connecting to [::1]:58746
6422026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr1 waiting for prompt
6432026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] cr2 waiting for prompt
6442026-05-09T03:55:02.465ZMay 09 03:55:02.428 DEBG [sc] ox waiting for prompt
6452026-05-09T03:55:02.465ZMay 09 03:55:02.439 DEBG [sc] ox: logging in
6462026-05-09T03:55:02.465ZMay 09 03:55:02.439 DEBG [sc] cr1: logging in
6472026-05-09T03:55:02.465ZMay 09 03:55:02.439 DEBG [sc] cr2: logging in
6482026-05-09T03:55:02.528ZMay 09 03:55:02.515 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
6492026-05-09T03:55:02.597ZMay 09 03:55:02.584 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6502026-05-09T03:55:02.791ZMay 09 03:55:02.778 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
6512026-05-09T03:55:04.846ZMay 09 03:55:04.833 INFO cr2: executing eos script show version
6522026-05-09T03:55:04.847ZMay 09 03:55:04.833 DEBG [sc] cr2: starting
6532026-05-09T03:55:04.847ZMay 09 03:55:04.833 DEBG [sc] cr2: connecting to [::1]:43868
6542026-05-09T03:55:04.871ZMay 09 03:55:04.833 DEBG [sc] cr2 waiting for prompt
6552026-05-09T03:55:04.871ZMay 09 03:55:04.844 DEBG [sc] cr2: logging in
6562026-05-09T03:55:05.012ZMay 09 03:55:04.998 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6572026-05-09T03:55:08.832ZMay 09 03:55:08.818 DEBG [sc] ox: starting
6582026-05-09T03:55:08.832ZMay 09 03:55:08.818 DEBG [sc] ox: connecting to [::1]:58746
6592026-05-09T03:55:08.856ZMay 09 03:55:08.819 DEBG [sc] ox waiting for prompt
6602026-05-09T03:55:08.856ZMay 09 03:55:08.829 DEBG [sc] ox: logging in
6612026-05-09T03:55:08.930ZMay 09 03:55:08.917 DEBG [sc] ox: executing command `chmod +x npuvm`
6622026-05-09T03:55:08.997ZMay 09 03:55:08.984 DEBG [sc] ox: starting
6632026-05-09T03:55:08.997ZMay 09 03:55:08.984 DEBG [sc] ox: connecting to [::1]:58746
6642026-05-09T03:55:09.021ZMay 09 03:55:08.984 DEBG [sc] ox waiting for prompt
6652026-05-09T03:55:09.021ZMay 09 03:55:08.995 DEBG [sc] ox: logging in
6662026-05-09T03:55:09.086ZMay 09 03:55:09.072 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
6672026-05-09T03:55:12.450ZMay 09 03:55:12.436 DEBG [sc] cr2: starting
6682026-05-09T03:55:12.450ZMay 09 03:55:12.436 DEBG [sc] cr2: connecting to [::1]:43868
6692026-05-09T03:55:12.474ZMay 09 03:55:12.437 DEBG [sc] cr2 waiting for prompt
6702026-05-09T03:55:12.474ZMay 09 03:55:12.447 DEBG [sc] cr2: logging in
6712026-05-09T03:55:12.593ZMay 09 03:55:12.579 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6722026-05-09T03:55:14.691ZMay 09 03:55:14.678 INFO cr2: executing eos script show version
6732026-05-09T03:55:14.691ZMay 09 03:55:14.678 DEBG [sc] cr2: starting
6742026-05-09T03:55:14.692ZMay 09 03:55:14.678 DEBG [sc] cr2: connecting to [::1]:43868
6752026-05-09T03:55:14.716ZMay 09 03:55:14.678 DEBG [sc] cr2 waiting for prompt
6762026-05-09T03:55:14.716ZMay 09 03:55:14.689 DEBG [sc] cr2: logging in
6772026-05-09T03:55:14.846ZMay 09 03:55:14.832 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6782026-05-09T03:55:17.312ZMay 09 03:55:17.298 DEBG [sc] cr2: starting
6792026-05-09T03:55:17.312ZMay 09 03:55:17.298 DEBG [sc] cr2: connecting to [::1]:43868
6802026-05-09T03:55:17.336ZMay 09 03:55:17.299 DEBG [sc] cr2 waiting for prompt
6812026-05-09T03:55:17.336ZMay 09 03:55:17.309 DEBG [sc] cr2: logging in
6822026-05-09T03:55:17.455ZMay 09 03:55:17.442 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6832026-05-09T03:55:19.586ZMay 09 03:55:19.572 INFO cr2: executing eos script show version
6842026-05-09T03:55:19.586ZMay 09 03:55:19.572 DEBG [sc] cr2: starting
6852026-05-09T03:55:19.586ZMay 09 03:55:19.572 DEBG [sc] cr2: connecting to [::1]:43868
6862026-05-09T03:55:19.610ZMay 09 03:55:19.573 DEBG [sc] cr2 waiting for prompt
6872026-05-09T03:55:19.610ZMay 09 03:55:19.583 DEBG [sc] cr2: logging in
6882026-05-09T03:55:19.766ZMay 09 03:55:19.749 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
6892026-05-09T03:55:22.290ZMay 09 03:55:22.276 DEBG [sc] cr2: starting
6902026-05-09T03:55:22.290ZMay 09 03:55:22.276 DEBG [sc] cr2: connecting to [::1]:43868
6912026-05-09T03:55:22.314ZMay 09 03:55:22.276 DEBG [sc] cr2 waiting for prompt
6922026-05-09T03:55:22.314ZMay 09 03:55:22.287 DEBG [sc] cr2: logging in
6932026-05-09T03:55:22.455ZMay 09 03:55:22.442 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
6942026-05-09T03:55:24.560ZMay 09 03:55:24.546 INFO cr2: executing eos script show version
6952026-05-09T03:55:24.560ZMay 09 03:55:24.546 DEBG [sc] cr2: starting
6962026-05-09T03:55:24.560ZMay 09 03:55:24.546 DEBG [sc] cr2: connecting to [::1]:43868
6972026-05-09T03:55:24.584ZMay 09 03:55:24.546 DEBG [sc] cr2 waiting for prompt
6982026-05-09T03:55:24.584ZMay 09 03:55:24.558 DEBG [sc] cr2: logging in
6992026-05-09T03:55:24.703ZMay 09 03:55:24.689 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
7002026-05-09T03:55:27.026ZMay 09 03:55:27.012 INFO cr2: executing eos script
7012026-05-09T03:55:27.026Z enable
7022026-05-09T03:55:27.026Z configure
7032026-05-09T03:55:27.026Z ip routing
7042026-05-09T03:55:27.026Z ipv6 unicast-routing
7052026-05-09T03:55:27.026Z interface Ethernet1
7062026-05-09T03:55:27.026Z no switchport
7072026-05-09T03:55:27.026Z ip address 10.0.1.2/24
7082026-05-09T03:55:27.026Z ipv6 enable
7092026-05-09T03:55:27.026Z ipv6 address fd00:2::2/64
7102026-05-09T03:55:27.026Z bfd interval 300 min-rx 300 multiplier 3
7112026-05-09T03:55:27.027Z exit
7122026-05-09T03:55:27.027Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7132026-05-09T03:55:27.027Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7142026-05-09T03:55:27.027Z exit
7152026-05-09T03:55:27.028Z
7162026-05-09T03:55:27.028ZMay 09 03:55:27.012 DEBG [sc] cr2: starting
7172026-05-09T03:55:27.028ZMay 09 03:55:27.012 DEBG [sc] cr2: connecting to [::1]:43868
7182026-05-09T03:55:27.053ZMay 09 03:55:27.013 DEBG [sc] cr2 waiting for prompt
7192026-05-09T03:55:27.053ZMay 09 03:55:27.023 DEBG [sc] cr2: logging in
7202026-05-09T03:55:27.181ZMay 09 03:55:27.167 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
7212026-05-09T03:55:27.181Z enable
7222026-05-09T03:55:27.181Z configure
7232026-05-09T03:55:27.181Z ip routing
7242026-05-09T03:55:27.181Z ipv6 unicast-routing
7252026-05-09T03:55:27.181Z interface Ethernet1
7262026-05-09T03:55:27.181Z no switchport
7272026-05-09T03:55:27.181Z ip address 10.0.1.2/24
7282026-05-09T03:55:27.181Z ipv6 enable
7292026-05-09T03:55:27.181Z ipv6 address fd00:2::2/64
7302026-05-09T03:55:27.181Z bfd interval 300 min-rx 300 multiplier 3
7312026-05-09T03:55:27.181Z exit
7322026-05-09T03:55:27.181Z ip route 100.64.0.0/24 10.0.1.1 track bfd
7332026-05-09T03:55:27.181Z ipv6 route 3fff::/64 fd00:2::1 track bfd
7342026-05-09T03:55:27.181Z exit
7352026-05-09T03:55:27.181Z '`
7362026-05-09T03:55:39.968ZMay 09 03:55:39.954 INFO cr1: enabling frr daemon bfdd
7372026-05-09T03:55:39.968ZMay 09 03:55:39.954 DEBG [sc] cr1: starting
7382026-05-09T03:55:39.968ZMay 09 03:55:39.954 DEBG [sc] cr1: connecting to [::1]:39020
7392026-05-09T03:55:39.993ZMay 09 03:55:39.954 DEBG [sc] cr1 waiting for prompt
7402026-05-09T03:55:39.993ZMay 09 03:55:39.965 DEBG [sc] cr1: logging in
7412026-05-09T03:55:40.123ZMay 09 03:55:40.109 DEBG [sc] cr1: executing command `sed -i 's/bfdd=no/bfdd=yes/g' /etc/frr/daemons`
7422026-05-09T03:55:42.194ZMay 09 03:55:42.180 DEBG [sc] cr1: starting
7432026-05-09T03:55:42.194ZMay 09 03:55:42.180 DEBG [sc] cr1: connecting to [::1]:39020
7442026-05-09T03:55:42.219ZMay 09 03:55:42.180 DEBG [sc] cr1 waiting for prompt
7452026-05-09T03:55:42.219ZMay 09 03:55:42.190 DEBG [sc] cr1: logging in
7462026-05-09T03:55:42.347ZMay 09 03:55:42.333 DEBG [sc] cr1: executing command `systemctl restart frr`
7472026-05-09T03:55:49.935ZMay 09 03:55:49.921 INFO cr1: executing frr script
7482026-05-09T03:55:49.935Z configure
7492026-05-09T03:55:49.935Z interface enp0s8
7502026-05-09T03:55:49.935Z ip address 10.0.0.2/24
7512026-05-09T03:55:49.935Z ipv6 address fd00:1::2/64
7522026-05-09T03:55:49.935Z no shutdown
7532026-05-09T03:55:49.935Z exit
7542026-05-09T03:55:49.935Z bfd
7552026-05-09T03:55:49.935Z peer 10.0.0.1 local-address 10.0.0.2
7562026-05-09T03:55:49.935Z detect-multiplier 3
7572026-05-09T03:55:49.935Z receive-interval 300
7582026-05-09T03:55:49.935Z transmit-interval 300
7592026-05-09T03:55:49.935Z no shutdown
7602026-05-09T03:55:49.935Z exit
7612026-05-09T03:55:49.935Z peer fd00:1::1 local-address fd00:1::2
7622026-05-09T03:55:49.935Z detect-multiplier 3
7632026-05-09T03:55:49.935Z receive-interval 300
7642026-05-09T03:55:49.935Z transmit-interval 300
7652026-05-09T03:55:49.935Z no shutdown
7662026-05-09T03:55:49.935Z exit
7672026-05-09T03:55:49.936Z exit
7682026-05-09T03:55:49.936Z
7692026-05-09T03:55:49.936ZMay 09 03:55:49.921 DEBG [sc] cr1: starting
7702026-05-09T03:55:49.936ZMay 09 03:55:49.921 DEBG [sc] cr1: connecting to [::1]:39020
7712026-05-09T03:55:49.960ZMay 09 03:55:49.922 DEBG [sc] cr1 waiting for prompt
7722026-05-09T03:55:49.960ZMay 09 03:55:49.933 DEBG [sc] cr1: logging in
7732026-05-09T03:55:50.070ZMay 09 03:55:50.056 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 ' '`
7742026-05-09T03:56:56.721ZMay 09 03:56:56.707 DEBG [sc] ox: starting
7752026-05-09T03:56:56.721ZMay 09 03:56:56.707 DEBG [sc] ox: connecting to [::1]:58746
7762026-05-09T03:56:56.745ZMay 09 03:56:56.708 DEBG [sc] ox waiting for prompt
7772026-05-09T03:56:56.745ZMay 09 03:56:56.718 DEBG [sc] ox: logging in
7782026-05-09T03:56:56.809ZMay 09 03:56:56.795 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
7792026-05-09T03:56:57.124ZMay 09 03:56:57.111 DEBG [sc] ox: starting
7802026-05-09T03:56:57.124ZMay 09 03:56:57.111 DEBG [sc] ox: connecting to [::1]:58746
7812026-05-09T03:56:57.148ZMay 09 03:56:57.111 DEBG [sc] ox waiting for prompt
7822026-05-09T03:56:57.148ZMay 09 03:56:57.123 DEBG [sc] ox: logging in
7832026-05-09T03:56:57.213ZMay 09 03:56:57.200 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7842026-05-09T03:56:58.237ZMay 09 03:56:58.223 DEBG [sc] ox: starting
7852026-05-09T03:56:58.237ZMay 09 03:56:58.223 DEBG [sc] ox: connecting to [::1]:58746
7862026-05-09T03:56:58.261ZMay 09 03:56:58.224 DEBG [sc] ox waiting for prompt
7872026-05-09T03:56:58.261ZMay 09 03:56:58.224 DEBG [sc] ox: logging in
7882026-05-09T03:56:58.325ZMay 09 03:56:58.312 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
7892026-05-09T03:56:58.392ZMay 09 03:56:58.378 DEBG [sc] ox: starting
7902026-05-09T03:56:58.392ZMay 09 03:56:58.378 DEBG [sc] ox: connecting to [::1]:58746
7912026-05-09T03:56:58.416ZMay 09 03:56:58.379 DEBG [sc] ox waiting for prompt
7922026-05-09T03:56:58.416ZMay 09 03:56:58.390 DEBG [sc] ox: logging in
7932026-05-09T03:56:58.491ZMay 09 03:56:58.478 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
7942026-05-09T03:56:58.948ZMay 09 03:56:58.934 DEBG [sc] ox: starting
7952026-05-09T03:56:58.948ZMay 09 03:56:58.934 DEBG [sc] ox: connecting to [::1]:58746
7962026-05-09T03:56:58.972ZMay 09 03:56:58.935 DEBG [sc] ox waiting for prompt
7972026-05-09T03:56:58.972ZMay 09 03:56:58.945 DEBG [sc] ox: logging in
7982026-05-09T03:56:59.036ZMay 09 03:56:59.023 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
7992026-05-09T03:56:59.092ZMay 09 03:56:59.078 DEBG [sc] ox: starting
8002026-05-09T03:56:59.092ZMay 09 03:56:59.078 DEBG [sc] ox: connecting to [::1]:58746
8012026-05-09T03:56:59.115ZMay 09 03:56:59.079 DEBG [sc] ox waiting for prompt
8022026-05-09T03:56:59.115ZMay 09 03:56:59.089 DEBG [sc] ox: logging in
8032026-05-09T03:56:59.180ZMay 09 03:56:59.166 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
8042026-05-09T03:56:59.236ZMay 09 03:56:59.222 DEBG [sc] ox: starting
8052026-05-09T03:56:59.236ZMay 09 03:56:59.222 DEBG [sc] ox: connecting to [::1]:58746
8062026-05-09T03:56:59.260ZMay 09 03:56:59.223 DEBG [sc] ox waiting for prompt
8072026-05-09T03:56:59.260ZMay 09 03:56:59.233 DEBG [sc] ox: logging in
8082026-05-09T03:56:59.324ZMay 09 03:56:59.310 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.0.1/24 tfportqsfp0_0/v4`
8092026-05-09T03:56:59.881ZMay 09 03:56:59.868 DEBG [sc] ox: starting
8102026-05-09T03:56:59.882ZMay 09 03:56:59.868 DEBG [sc] ox: connecting to [::1]:58746
8112026-05-09T03:56:59.906ZMay 09 03:56:59.869 DEBG [sc] ox waiting for prompt
8122026-05-09T03:56:59.906ZMay 09 03:56:59.879 DEBG [sc] ox: logging in
8132026-05-09T03:56:59.969ZMay 09 03:56:59.956 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v4 -p -o addr`
8142026-05-09T03:57:00.025ZMay 09 03:57:00.011 DEBG [sc] ox: starting
8152026-05-09T03:57:00.025ZMay 09 03:57:00.011 DEBG [sc] ox: connecting to [::1]:58746
8162026-05-09T03:57:00.049ZMay 09 03:57:00.011 DEBG [sc] ox waiting for prompt
8172026-05-09T03:57:00.049ZMay 09 03:57:00.022 DEBG [sc] ox: logging in
8182026-05-09T03:57:00.113ZMay 09 03:57:00.099 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:1::1/64 tfportqsfp0_0/v6`
8192026-05-09T03:57:00.626ZMay 09 03:57:00.612 DEBG [sc] ox: starting
8202026-05-09T03:57:00.626ZMay 09 03:57:00.612 DEBG [sc] ox: connecting to [::1]:58746
8212026-05-09T03:57:00.650ZMay 09 03:57:00.613 DEBG [sc] ox waiting for prompt
8222026-05-09T03:57:00.650ZMay 09 03:57:00.622 DEBG [sc] ox: logging in
8232026-05-09T03:57:00.714ZMay 09 03:57:00.700 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/v6 -p -o addr`
8242026-05-09T03:57:00.768ZMay 09 03:57:00.755 DEBG [sc] ox: starting
8252026-05-09T03:57:00.768ZMay 09 03:57:00.755 DEBG [sc] ox: connecting to [::1]:58746
8262026-05-09T03:57:00.792ZMay 09 03:57:00.756 DEBG [sc] ox waiting for prompt
8272026-05-09T03:57:00.792ZMay 09 03:57:00.765 DEBG [sc] ox: logging in
8282026-05-09T03:57:00.857ZMay 09 03:57:00.843 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
8292026-05-09T03:57:00.912ZMay 09 03:57:00.899 DEBG [sc] ox: starting
8302026-05-09T03:57:00.912ZMay 09 03:57:00.899 DEBG [sc] ox: connecting to [::1]:58746
8312026-05-09T03:57:00.936ZMay 09 03:57:00.900 DEBG [sc] ox waiting for prompt
8322026-05-09T03:57:00.936ZMay 09 03:57:00.910 DEBG [sc] ox: logging in
8332026-05-09T03:57:01.001ZMay 09 03:57:00.987 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
8342026-05-09T03:57:01.055ZMay 09 03:57:01.042 DEBG [sc] ox: starting
8352026-05-09T03:57:01.055ZMay 09 03:57:01.042 DEBG [sc] ox: connecting to [::1]:58746
8362026-05-09T03:57:01.079ZMay 09 03:57:01.043 DEBG [sc] ox waiting for prompt
8372026-05-09T03:57:01.079ZMay 09 03:57:01.053 DEBG [sc] ox: logging in
8382026-05-09T03:57:01.143ZMay 09 03:57:01.130 DEBG [sc] ox: executing command `ipadm create-addr -T static -a 10.0.1.1/24 tfportqsfp1_0/v4`
8392026-05-09T03:57:01.615ZMay 09 03:57:01.601 DEBG [sc] ox: starting
8402026-05-09T03:57:01.615ZMay 09 03:57:01.601 DEBG [sc] ox: connecting to [::1]:58746
8412026-05-09T03:57:01.639ZMay 09 03:57:01.602 DEBG [sc] ox waiting for prompt
8422026-05-09T03:57:01.639ZMay 09 03:57:01.612 DEBG [sc] ox: logging in
8432026-05-09T03:57:01.702ZMay 09 03:57:01.688 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v4 -p -o addr`
8442026-05-09T03:57:01.758ZMay 09 03:57:01.744 DEBG [sc] ox: starting
8452026-05-09T03:57:01.758ZMay 09 03:57:01.744 DEBG [sc] ox: connecting to [::1]:58746
8462026-05-09T03:57:01.782ZMay 09 03:57:01.745 DEBG [sc] ox waiting for prompt
8472026-05-09T03:57:01.782ZMay 09 03:57:01.756 DEBG [sc] ox: logging in
8482026-05-09T03:57:01.848ZMay 09 03:57:01.834 DEBG [sc] ox: executing command `ipadm create-addr -T static -a fd00:2::1/64 tfportqsfp1_0/v6`
8492026-05-09T03:57:02.361ZMay 09 03:57:02.347 DEBG [sc] ox: starting
8502026-05-09T03:57:02.361ZMay 09 03:57:02.347 DEBG [sc] ox: connecting to [::1]:58746
8512026-05-09T03:57:02.385ZMay 09 03:57:02.348 DEBG [sc] ox waiting for prompt
8522026-05-09T03:57:02.385ZMay 09 03:57:02.358 DEBG [sc] ox: logging in
8532026-05-09T03:57:02.449ZMay 09 03:57:02.436 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/v6 -p -o addr`
8542026-05-09T03:57:02.505ZMay 09 03:57:02.492 DEBG [sc] ox: starting
8552026-05-09T03:57:02.505ZMay 09 03:57:02.492 DEBG [sc] ox: connecting to [::1]:58746
8562026-05-09T03:57:02.529ZMay 09 03:57:02.492 DEBG [sc] ox waiting for prompt
8572026-05-09T03:57:02.529ZMay 09 03:57:02.502 DEBG [sc] ox: logging in
8582026-05-09T03:57:02.592ZMay 09 03:57:02.579 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
8592026-05-09T03:57:02.648ZMay 09 03:57:02.634 DEBG [sc] ox: starting
8602026-05-09T03:57:02.648ZMay 09 03:57:02.634 DEBG [sc] ox: connecting to [::1]:58746
8612026-05-09T03:57:02.672ZMay 09 03:57:02.635 DEBG [sc] ox waiting for prompt
8622026-05-09T03:57:02.672ZMay 09 03:57:02.645 DEBG [sc] ox: logging in
8632026-05-09T03:57:02.748ZMay 09 03:57:02.735 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
8642026-05-09T03:57:02.821ZMay 09 03:57:02.807 INFO installing static v4 route 192.168.100.0/24
8652026-05-09T03:57:02.845ZMay 09 03:57:02.809 INFO installing static v6 route fd01::/64
8662026-05-09T03:57:02.845ZMay 09 03:57:02.809 INFO adding BFD peers for cr1 and cr2 (dual-stack)
8672026-05-09T03:57:02.845ZMay 09 03:57:02.812 INFO phase 1: both peers up
8682026-05-09T03:57:04.832ZMay 09 03:57:04.819 INFO cr1: executing frr script show bfd peers json
8692026-05-09T03:57:04.832ZMay 09 03:57:04.819 DEBG [sc] cr1: starting
8702026-05-09T03:57:04.832ZMay 09 03:57:04.819 DEBG [sc] cr1: connecting to [::1]:39020
8712026-05-09T03:57:04.856ZMay 09 03:57:04.819 DEBG [sc] cr1 waiting for prompt
8722026-05-09T03:57:04.857ZMay 09 03:57:04.831 DEBG [sc] cr1: logging in
8732026-05-09T03:57:05.186ZMay 09 03:57:05.172 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8742026-05-09T03:57:07.330ZMay 09 03:57:07.316 INFO cr1: executing frr script show bfd peers json
8752026-05-09T03:57:07.330ZMay 09 03:57:07.317 DEBG [sc] cr1: starting
8762026-05-09T03:57:07.330ZMay 09 03:57:07.317 DEBG [sc] cr1: connecting to [::1]:39020
8772026-05-09T03:57:07.355ZMay 09 03:57:07.317 DEBG [sc] cr1 waiting for prompt
8782026-05-09T03:57:07.355ZMay 09 03:57:07.328 DEBG [sc] cr1: logging in
8792026-05-09T03:57:07.474ZMay 09 03:57:07.460 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
8802026-05-09T03:57:09.630ZMay 09 03:57:09.616 INFO cr2: executing eos script show bfd peers | json
8812026-05-09T03:57:09.630ZMay 09 03:57:09.616 DEBG [sc] cr2: starting
8822026-05-09T03:57:09.630ZMay 09 03:57:09.616 DEBG [sc] cr2: connecting to [::1]:43868
8832026-05-09T03:57:09.654ZMay 09 03:57:09.617 DEBG [sc] cr2 waiting for prompt
8842026-05-09T03:57:09.654ZMay 09 03:57:09.628 DEBG [sc] cr2: logging in
8852026-05-09T03:57:09.977ZMay 09 03:57:09.963 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8862026-05-09T03:57:12.377ZMay 09 03:57:12.363 INFO cr2: executing eos script show bfd peers | json
8872026-05-09T03:57:12.377ZMay 09 03:57:12.363 DEBG [sc] cr2: starting
8882026-05-09T03:57:12.377ZMay 09 03:57:12.363 DEBG [sc] cr2: connecting to [::1]:43868
8892026-05-09T03:57:12.402ZMay 09 03:57:12.364 DEBG [sc] cr2 waiting for prompt
8902026-05-09T03:57:12.402ZMay 09 03:57:12.373 DEBG [sc] cr2: logging in
8912026-05-09T03:57:12.519ZMay 09 03:57:12.506 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
8922026-05-09T03:57:14.902ZMay 09 03:57:14.888 INFO phase 2: pause bfdd on cr1
8932026-05-09T03:57:14.902ZMay 09 03:57:14.888 INFO cr1: pausing frr bfdd
8942026-05-09T03:57:14.902ZMay 09 03:57:14.888 DEBG [sc] cr1: starting
8952026-05-09T03:57:14.926ZMay 09 03:57:14.888 DEBG [sc] cr1: connecting to [::1]:39020
8962026-05-09T03:57:14.926ZMay 09 03:57:14.889 DEBG [sc] cr1 waiting for prompt
8972026-05-09T03:57:14.926ZMay 09 03:57:14.899 DEBG [sc] cr1: logging in
8982026-05-09T03:57:15.056ZMay 09 03:57:15.042 DEBG [sc] cr1: executing command `pkill -STOP bfdd`
8992026-05-09T03:57:17.152ZMay 09 03:57:17.139 INFO cr2: executing eos script show bfd peers | json
9002026-05-09T03:57:17.177ZMay 09 03:57:17.139 DEBG [sc] cr2: starting
9012026-05-09T03:57:17.177ZMay 09 03:57:17.139 DEBG [sc] cr2: connecting to [::1]:43868
9022026-05-09T03:57:17.177ZMay 09 03:57:17.139 DEBG [sc] cr2 waiting for prompt
9032026-05-09T03:57:17.177ZMay 09 03:57:17.151 DEBG [sc] cr2: logging in
9042026-05-09T03:57:17.297ZMay 09 03:57:17.283 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9052026-05-09T03:57:19.620ZMay 09 03:57:19.607 INFO cr2: executing eos script show bfd peers | json
9062026-05-09T03:57:19.622ZMay 09 03:57:19.607 DEBG [sc] cr2: starting
9072026-05-09T03:57:19.622ZMay 09 03:57:19.607 DEBG [sc] cr2: connecting to [::1]:43868
9082026-05-09T03:57:19.646ZMay 09 03:57:19.607 DEBG [sc] cr2 waiting for prompt
9092026-05-09T03:57:19.646ZMay 09 03:57:19.618 DEBG [sc] cr2: logging in
9102026-05-09T03:57:19.753ZMay 09 03:57:19.739 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9112026-05-09T03:57:22.129ZMay 09 03:57:22.116 INFO phase 3: pause ceos on cr2
9122026-05-09T03:57:22.129ZMay 09 03:57:22.116 INFO cr2: pausing ceos
9132026-05-09T03:57:22.129ZMay 09 03:57:22.116 DEBG [sc] cr2: starting
9142026-05-09T03:57:22.129ZMay 09 03:57:22.116 DEBG [sc] cr2: connecting to [::1]:43868
9152026-05-09T03:57:22.153ZMay 09 03:57:22.116 DEBG [sc] cr2 waiting for prompt
9162026-05-09T03:57:22.153ZMay 09 03:57:22.126 DEBG [sc] cr2: logging in
9172026-05-09T03:57:22.260ZMay 09 03:57:22.246 DEBG [sc] cr2: executing command `docker pause ceos`
9182026-05-09T03:57:24.372ZMay 09 03:57:24.358 INFO phase 4: resume bfdd on cr1
9192026-05-09T03:57:24.372ZMay 09 03:57:24.358 INFO cr1: resuming frr bfdd
9202026-05-09T03:57:24.372ZMay 09 03:57:24.358 DEBG [sc] cr1: starting
9212026-05-09T03:57:24.372ZMay 09 03:57:24.358 DEBG [sc] cr1: connecting to [::1]:39020
9222026-05-09T03:57:24.396ZMay 09 03:57:24.359 DEBG [sc] cr1 waiting for prompt
9232026-05-09T03:57:24.396ZMay 09 03:57:24.370 DEBG [sc] cr1: logging in
9242026-05-09T03:57:24.528ZMay 09 03:57:24.514 DEBG [sc] cr1: executing command `pkill -CONT bfdd`
9252026-05-09T03:57:26.609ZMay 09 03:57:26.595 INFO cr1: executing frr script show bfd peers json
9262026-05-09T03:57:26.609ZMay 09 03:57:26.595 DEBG [sc] cr1: starting
9272026-05-09T03:57:26.609ZMay 09 03:57:26.595 DEBG [sc] cr1: connecting to [::1]:39020
9282026-05-09T03:57:26.633ZMay 09 03:57:26.596 DEBG [sc] cr1 waiting for prompt
9292026-05-09T03:57:26.633ZMay 09 03:57:26.604 DEBG [sc] cr1: logging in
9302026-05-09T03:57:26.751ZMay 09 03:57:26.737 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9312026-05-09T03:57:28.889ZMay 09 03:57:28.875 INFO cr1: executing frr script show bfd peers json
9322026-05-09T03:57:28.889ZMay 09 03:57:28.875 DEBG [sc] cr1: starting
9332026-05-09T03:57:28.889ZMay 09 03:57:28.875 DEBG [sc] cr1: connecting to [::1]:39020
9342026-05-09T03:57:28.913ZMay 09 03:57:28.876 DEBG [sc] cr1 waiting for prompt
9352026-05-09T03:57:28.913ZMay 09 03:57:28.886 DEBG [sc] cr1: logging in
9362026-05-09T03:57:29.023ZMay 09 03:57:29.009 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9372026-05-09T03:57:31.162ZMay 09 03:57:31.149 INFO phase 5: unpause ceos on cr2
9382026-05-09T03:57:31.162ZMay 09 03:57:31.149 INFO cr2: unpausing ceos
9392026-05-09T03:57:31.162ZMay 09 03:57:31.149 DEBG [sc] cr2: starting
9402026-05-09T03:57:31.162ZMay 09 03:57:31.149 DEBG [sc] cr2: connecting to [::1]:43868
9412026-05-09T03:57:31.187ZMay 09 03:57:31.149 DEBG [sc] cr2 waiting for prompt
9422026-05-09T03:57:31.187ZMay 09 03:57:31.160 DEBG [sc] cr2: logging in
9432026-05-09T03:57:31.306ZMay 09 03:57:31.293 DEBG [sc] cr2: executing command `docker unpause ceos`
9442026-05-09T03:57:33.443ZMay 09 03:57:33.429 INFO cr1: executing frr script show bfd peers json
9452026-05-09T03:57:33.443ZMay 09 03:57:33.429 DEBG [sc] cr1: starting
9462026-05-09T03:57:33.443ZMay 09 03:57:33.429 DEBG [sc] cr1: connecting to [::1]:39020
9472026-05-09T03:57:33.467ZMay 09 03:57:33.430 DEBG [sc] cr1 waiting for prompt
9482026-05-09T03:57:33.467ZMay 09 03:57:33.441 DEBG [sc] cr1: logging in
9492026-05-09T03:57:33.587ZMay 09 03:57:33.573 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9502026-05-09T03:57:35.735ZMay 09 03:57:35.720 INFO cr1: executing frr script show bfd peers json
9512026-05-09T03:57:35.735ZMay 09 03:57:35.720 DEBG [sc] cr1: starting
9522026-05-09T03:57:35.735ZMay 09 03:57:35.720 DEBG [sc] cr1: connecting to [::1]:39020
9532026-05-09T03:57:35.759ZMay 09 03:57:35.721 DEBG [sc] cr1 waiting for prompt
9542026-05-09T03:57:35.760ZMay 09 03:57:35.732 DEBG [sc] cr1: logging in
9552026-05-09T03:57:35.888ZMay 09 03:57:35.874 DEBG [sc] cr1: executing command `vtysh -c 'show bfd peers json'`
9562026-05-09T03:57:38.026ZMay 09 03:57:38.013 INFO cr2: executing eos script show bfd peers | json
9572026-05-09T03:57:38.026ZMay 09 03:57:38.013 DEBG [sc] cr2: starting
9582026-05-09T03:57:38.026ZMay 09 03:57:38.013 DEBG [sc] cr2: connecting to [::1]:43868
9592026-05-09T03:57:38.050ZMay 09 03:57:38.013 DEBG [sc] cr2 waiting for prompt
9602026-05-09T03:57:38.050ZMay 09 03:57:38.025 DEBG [sc] cr2: logging in
9612026-05-09T03:57:38.180ZMay 09 03:57:38.167 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9622026-05-09T03:57:40.569ZMay 09 03:57:40.555 INFO cr2: executing eos script show bfd peers | json
9632026-05-09T03:57:40.569ZMay 09 03:57:40.555 DEBG [sc] cr2: starting
9642026-05-09T03:57:40.593ZMay 09 03:57:40.555 DEBG [sc] cr2: connecting to [::1]:43868
9652026-05-09T03:57:40.593ZMay 09 03:57:40.556 DEBG [sc] cr2 waiting for prompt
9662026-05-09T03:57:40.593ZMay 09 03:57:40.565 DEBG [sc] cr2: logging in
9672026-05-09T03:57:40.712ZMay 09 03:57:40.698 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show bfd peers | json'`
9682026-05-09T03:57:43.037ZMay 09 03:57:43.023 INFO trio bfd static routing test passed 🎉
9692026-05-09T03:57:43.061ZMay 09 03:57:43.023 INFO destroying runner for deployment mgtriobfd
9702026-05-09T03:57:43.061ZMay 09 03:57:43.023 INFO destroying deployment mgtriobfd
9712026-05-09T03:57:43.061ZMay 09 03:57:43.023 INFO destroying nodes
9722026-05-09T03:57:43.142ZMay 09 03:57:43.128 INFO destroying links
9732026-05-09T03:57:43.142ZMay 09 03:57:43.128 INFO destroying link mgtriobfd_ox_sn_vnic0
9742026-05-09T03:57:43.165ZMay 09 03:57:43.130 INFO destroying link mgtriobfd_ox_sn_sim0
9752026-05-09T03:57:43.166ZMay 09 03:57:43.131 INFO destroying link mgtriobfd_cr1_vn_vnic0
9762026-05-09T03:57:44.147ZMay 09 03:57:44.134 INFO destroying link mgtriobfd_cr1_vn_sim0
9772026-05-09T03:57:44.172ZMay 09 03:57:44.134 INFO destroying link mgtriobfd_ox_sn_vnic1
9782026-05-09T03:57:44.172ZMay 09 03:57:44.135 INFO destroying link mgtriobfd_ox_sn_sim1
9792026-05-09T03:57:44.172ZMay 09 03:57:44.136 INFO destroying link mgtriobfd_cr2_vn_vnic0
9802026-05-09T03:57:44.172ZMay 09 03:57:44.137 INFO destroying link mgtriobfd_cr2_vn_sim0
9812026-05-09T03:57:44.172ZMay 09 03:57:44.138 INFO destroying external links
9822026-05-09T03:57:44.172ZMay 09 03:57:44.138 INFO destroying external link mgtriobfd_ox_vn_vnic2
9832026-05-09T03:57:44.172ZMay 09 03:57:44.139 INFO destroying external link mgtriobfd_cr1_vn_vnic1
9842026-05-09T03:57:44.172ZMay 09 03:57:44.140 INFO destroying external link mgtriobfd_cr2_vn_vnic1
9852026-05-09T03:57:44.172ZMay 09 03:57:44.141 INFO destroying images
9862026-05-09T03:57:44.630ZMay 09 03:57:44.617 INFO destroying workspace at .falcon
9872026-05-09T03:57:44.654Zprocess exited: duration 695557 ms, exit code 0
 
9882026-05-09T03:57:44.705Zfound 0 output files