01KP9EN31FZC34JFFRNP6NZ3R4: falcon

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

Buildomat Job: 01KP9ENH3WESGSYMXNWBAAZ5RH

Tags:

Output:

SEQ GLOBAL TIME DETAILS
12026-04-15T21:06:50.113Zjob dependencies complete; ready to run (waiting for 14 m 17 s)
22026-04-15T21:10:03.956Zjob assigned to worker 01KP9FFQ77V321YV5V59RVGXZ7 [factory edgar, gimlet/BRM42220010/769] (queued for 3 m 13 s)
32026-04-15T21:10:04.507Zdownloading input: /input/build-interop/work/testbed.tar.gz
42026-04-15T21:10:13.079Zdownloaded input: /input/build-interop/work/testbed.tar.gz
52026-04-15T21:10:13.079Zdownloading input: /input/build-interop/work/dhcp-server
62026-04-15T21:10:15.513Zdownloaded input: /input/build-interop/work/dhcp-server
72026-04-15T21:10:15.537Zdownloading input: /input/build/work/debug/ddmadm
82026-04-15T21:10:37.964Zdownloaded input: /input/build/work/debug/ddmadm
92026-04-15T21:10:37.964Zdownloading input: /input/build/work/debug/ddmd
102026-04-15T21:11:05.454Zdownloaded input: /input/build/work/debug/ddmd
112026-04-15T21:11:05.478Zdownloading input: /input/build/work/debug/mgadm
122026-04-15T21:11:31.660Zdownloaded input: /input/build/work/debug/mgadm
132026-04-15T21:11:31.660Zdownloading input: /input/build/work/debug/mgd
142026-04-15T21:12:02.868Zdownloaded input: /input/build/work/debug/mgd
152026-04-15T21:12:02.892Zdownloading input: /input/build/work/release/ddmadm
162026-04-15T21:12:04.957Zdownloaded input: /input/build/work/release/ddmadm
172026-04-15T21:12:04.957Zdownloading input: /input/build/work/release/ddmd
182026-04-15T21:12:07.373Zdownloaded input: /input/build/work/release/ddmd
192026-04-15T21:12:07.373Zdownloading input: /input/build/work/release/falcon-lab
202026-04-15T21:12:08.969Zdownloaded input: /input/build/work/release/falcon-lab
212026-04-15T21:12:08.969Zdownloading input: /input/build/work/release/mgadm
222026-04-15T21:12:11.599Zdownloaded input: /input/build/work/release/mgadm
232026-04-15T21:12:11.624Zdownloading input: /input/build/work/release/mgd
242026-04-15T21:12:14.952Zdownloaded input: /input/build/work/release/mgd
 
252026-04-15T21:12:14.952Zstarting task 0: "setup"
262026-04-15T21:12:14.976Z++ uname -s
272026-04-15T21:12:14.976Z+ kern=SunOS
282026-04-15T21:12:14.976Z+ build_user=build
292026-04-15T21:12:14.976Z+ build_uid=12345
302026-04-15T21:12:14.976Z+ work_dir=/work
312026-04-15T21:12:14.976Z+ input_dir=/input
322026-04-15T21:12:14.976Z+ [[ 0 == 12345 ]]
332026-04-15T21:12:14.976Z+ case "$kern" in
342026-04-15T21:12:14.976Z+ groupadd -g 12345 build
352026-04-15T21:12:14.976Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
362026-04-15T21:12:16.985Z+ zfs create -o mountpoint=/work rpool/work
372026-04-15T21:12:17.651Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
382026-04-15T21:12:17.689Z+ home_fs=
392026-04-15T21:12:17.689Z+ [[ '' == autofs ]]
402026-04-15T21:12:17.689Z+ mkdir -p /home/build
412026-04-15T21:12:17.689Z+ chown build:build /home/build /work
422026-04-15T21:12:18.664Z+ chmod 0700 /home/build /work
432026-04-15T21:12:18.693Zprocess exited: duration 3716 ms, exit code 0
 
442026-04-15T21:12:18.747Zstarting task 1: "authentication"
452026-04-15T21:12:18.842Zprocess exited: duration 94 ms, exit code 0
 
462026-04-15T21:12:18.898Zstarting task 2: "build"
472026-04-15T21:12:18.924Z+ set -e
482026-04-15T21:12:18.924Z+ banner zpool
492026-04-15T21:12:18.924Z
502026-04-15T21:12:18.924Z ###### ##### #### #### #
512026-04-15T21:12:18.924Z # # # # # # # #
522026-04-15T21:12:18.924Z # # # # # # # #
532026-04-15T21:12:18.924Z # ##### # # # # #
542026-04-15T21:12:18.924Z # # # # # # #
552026-04-15T21:12:18.924Z ###### # #### #### ######
562026-04-15T21:12:18.924Z
572026-04-15T21:12:18.924Z++ pfexec diskinfo -pH
582026-04-15T21:12:18.924Z++ sort -k8 -n -r
592026-04-15T21:12:18.948Z++ head -1
602026-04-15T21:12:18.948Z++ awk '{print $2}'
612026-04-15T21:12:18.972Z+ DISK=c9t0014EE81000BC3B1d0
622026-04-15T21:12:18.972Z+ export DISK
632026-04-15T21:12:18.972Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC3B1d0
642026-04-15T21:12:19.037Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
652026-04-15T21:12:19.064Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
662026-04-15T21:12:19.248Z+ [[ true =~ true ]]
672026-04-15T21:12:19.248Z+ pfexec zpool trim cpool
682026-04-15T21:12:19.277Z++ zpool status -t cpool
692026-04-15T21:12:19.277Z+ [[ ! pool: cpool
702026-04-15T21:12:19.277Z state: ONLINE
712026-04-15T21:12:19.277Z scan: none requested
722026-04-15T21:12:19.277Zconfig:
732026-04-15T21:12:19.277Z
742026-04-15T21:12:19.277Z NAME STATE READ WRITE CKSUM
752026-04-15T21:12:19.277Z cpool ONLINE 0 0 0
762026-04-15T21:12:19.277Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at April 15, 2026 at 09:12:19 PM UTC)
772026-04-15T21:12:19.277Z
782026-04-15T21:12:19.277Zerrors: No known data errors =~ 100% ]]
792026-04-15T21:12:19.277Z+ sleep 10
802026-04-15T21:12:29.280Z++ zpool status -t cpool
812026-04-15T21:12:29.304Z+ [[ ! pool: cpool
822026-04-15T21:12:29.304Z state: ONLINE
832026-04-15T21:12:29.304Z scan: none requested
842026-04-15T21:12:29.304Zconfig:
852026-04-15T21:12:29.304Z
862026-04-15T21:12:29.304Z NAME STATE READ WRITE CKSUM
872026-04-15T21:12:29.304Z cpool ONLINE 0 0 0
882026-04-15T21:12:29.304Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (70% trimmed, started at April 15, 2026 at 09:12:19 PM UTC)
892026-04-15T21:12:29.304Z
902026-04-15T21:12:29.304Zerrors: No known data errors =~ 100% ]]
912026-04-15T21:12:29.304Z+ sleep 10
922026-04-15T21:12:39.294Z++ zpool status -t cpool
932026-04-15T21:12:39.318Z+ [[ ! pool: cpool
942026-04-15T21:12:39.318Z state: ONLINE
952026-04-15T21:12:39.318Z scan: none requested
962026-04-15T21:12:39.318Zconfig:
972026-04-15T21:12:39.319Z
982026-04-15T21:12:39.319Z NAME STATE READ WRITE CKSUM
992026-04-15T21:12:39.319Z cpool ONLINE 0 0 0
1002026-04-15T21:12:39.319Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at April 15, 2026 at 09:12:33 PM UTC)
1012026-04-15T21:12:39.319Z
1022026-04-15T21:12:39.319Zerrors: No known data errors =~ 100% ]]
1032026-04-15T21:12:39.319Z+ pfexec chown 12345 /ci
1042026-04-15T21:12:39.319Z+ cd /ci
1052026-04-15T21:12:39.319Z+ export FALCON_DATASET=cpool/falcon
1062026-04-15T21:12:39.319Z+ FALCON_DATASET=cpool/falcon
1072026-04-15T21:12:39.319Z+ banner setup
1082026-04-15T21:12:39.319Z
1092026-04-15T21:12:39.319Z #### ###### ##### # # #####
1102026-04-15T21:12:39.319Z # # # # # # #
1112026-04-15T21:12:39.319Z #### ##### # # # # #
1122026-04-15T21:12:39.319Z # # # # # #####
1132026-04-15T21:12:39.319Z # # # # # # #
1142026-04-15T21:12:39.319Z #### ###### # #### #
1152026-04-15T21:12:39.319Z
1162026-04-15T21:12:39.319Z+ cp /input/build-interop/work/dhcp-server .
1172026-04-15T21:12:39.627Z+ cp /input/build/work/release/falcon-lab .
1182026-04-15T21:12:39.661Z+ cp /input/build/work/release/mgd .
1192026-04-15T21:12:39.726Z+ cp /input/build/work/release/ddmd .
1202026-04-15T21:12:39.779Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1212026-04-15T21:12:39.804Z+ mkdir -p cargo-bay
1222026-04-15T21:12:39.804Z+ mv mgd cargo-bay/
1232026-04-15T21:12:39.804Z+ mv ddmd cargo-bay/
1242026-04-15T21:12:39.804Z+ export EXT_INTERFACE=igb0
1252026-04-15T21:12:39.804Z+ EXT_INTERFACE=igb0
1262026-04-15T21:12:39.804Z++ bmat address ls -f extra -Ho first
1272026-04-15T21:12:39.828Z+ first=10.151.6.164
1282026-04-15T21:12:39.828Z++ bmat address ls -f extra -Ho last
1292026-04-15T21:12:39.852Z+ last=10.151.6.227
1302026-04-15T21:12:39.852Z++ bmat address ls -f extra -Ho gateway
1312026-04-15T21:12:39.877Z+ gw=10.151.6.1
1322026-04-15T21:12:39.877Z++ ipadm show-addr igb0/dhcp -po ADDR
1332026-04-15T21:12:39.900Z++ sed 's#/.*##g'
1342026-04-15T21:12:39.900Z+ server=10.151.6.100
1352026-04-15T21:12:39.900Z+ pfexec ./dhcp-server 10.151.6.164 10.151.6.227 10.151.6.1 10.151.6.100
1362026-04-15T21:12:39.900Z++ pfexec dladm create-vnic -l igb0 dummy0
1372026-04-15T21:12:39.900Z+ error=
1382026-04-15T21:12:39.900Z+ RUST_LOG=debug
1392026-04-15T21:12:39.900Z+ pfexec ./falcon-lab run trio-unnumbered
1402026-04-15T21:12:39.924ZApr 15 21:12:39.904 DEBG using default route interface igb0
1412026-04-15T21:12:39.924ZApr 15 21:12:39.905 DEBG using default route interface igb0
1422026-04-15T21:12:39.924ZApr 15 21:12:39.905 DEBG using default route interface igb0
1432026-04-15T21:12:39.924ZApr 15 21:12:39.905 INFO launching runner: deployment(mgtriou) persistent(false) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1442026-04-15T21:12:39.924ZApr 15 21:12:39.905 INFO starting preflight for deployment mgtriou
1452026-04-15T21:12:39.924ZApr 15 21:12:39.905 INFO propolis-server binary not found
1462026-04-15T21:12:39.924ZApr 15 21:12:39.905 INFO downloading propolis server rev 36f20be9bb4c3b362029237f5feb6377c982395f, writing to .falcon/bin/propolis-server
1472026-04-15T21:12:43.682ZApr 15 21:12:43.672 INFO ovmf fd not found
1482026-04-15T21:12:43.682ZApr 15 21:12:43.672 INFO downloading ovmf
1492026-04-15T21:12:44.083ZApr 15 21:12:44.073 INFO base image for helios-2.9 does not exist, attempting to install
1502026-04-15T21:12:44.083ZApr 15 21:12:44.073 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-2.9_0.raw.xz
1512026-04-15T21:13:12.897ZApr 15 21:13:12.885 INFO extracting image to /tmp/helios-2.9_0.raw
1522026-04-15T21:13:46.674ZApr 15 21:13:46.661 INFO creating zvol cpool/falcon/img/helios-2.9 of size 4508880896
1532026-04-15T21:13:46.725ZApr 15 21:13:46.713 INFO copying image data to zvol
1542026-04-15T21:13:57.210ZApr 15 21:13:57.198 INFO creating zfs snapshot cpool/falcon/img/helios-2.9@base
1552026-04-15T21:14:00.635ZApr 15 21:14:00.623 INFO base image for debian-13.2 does not exist, attempting to install
1562026-04-15T21:14:00.635ZApr 15 21:14:00.623 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
1572026-04-15T21:14:21.238ZApr 15 21:14:21.224 INFO extracting image to /tmp/debian-13.2_0.raw
1582026-04-15T21:14:42.174ZApr 15 21:14:42.160 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
1592026-04-15T21:14:42.200ZApr 15 21:14:42.187 INFO copying image data to zvol
1602026-04-15T21:14:48.558ZApr 15 21:14:48.545 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
1612026-04-15T21:14:51.808ZApr 15 21:14:51.795 INFO base image for eos-4.35 does not exist, attempting to install
1622026-04-15T21:14:51.808ZApr 15 21:14:51.795 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
1632026-04-15T21:15:35.740ZApr 15 21:15:35.727 INFO extracting image to /tmp/eos-4.35_0.raw
1642026-04-15T21:17:00.004ZApr 15 21:16:59.991 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
1652026-04-15T21:17:00.029ZApr 15 21:17:00.017 INFO copying image data to zvol
1662026-04-15T21:17:48.513ZApr 15 21:17:48.500 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
1672026-04-15T21:17:51.992ZApr 15 21:17:51.980 INFO creating links
1682026-04-15T21:17:51.992ZApr 15 21:17:51.980 DEBG destroying link mgtriou_ox_sn_vnic0
1692026-04-15T21:17:52.017ZApr 15 21:17:51.980 DEBG destroying link mgtriou_ox_sn_sim0
1702026-04-15T21:17:52.017ZApr 15 21:17:51.980 INFO creating simnet link 'mgtriou_ox_sn_sim0'
1712026-04-15T21:17:52.017ZApr 15 21:17:51.982 INFO creating vnic link 'mgtriou_ox_sn_vnic0'
1722026-04-15T21:17:52.017ZApr 15 21:17:51.989 DEBG link pair created
1732026-04-15T21:17:52.017ZApr 15 21:17:51.989 DEBG destroying link mgtriou_cr1_vn_vnic0
1742026-04-15T21:17:52.017ZApr 15 21:17:51.989 DEBG destroying link mgtriou_cr1_vn_sim0
1752026-04-15T21:17:52.017ZApr 15 21:17:51.989 INFO creating simnet link 'mgtriou_cr1_vn_sim0'
1762026-04-15T21:17:52.018ZApr 15 21:17:51.990 INFO creating vnic link 'mgtriou_cr1_vn_vnic0'
1772026-04-15T21:17:52.018ZApr 15 21:17:51.997 DEBG link pair created
1782026-04-15T21:17:52.018ZApr 15 21:17:51.997 DEBG destroying link mgtriou_ox_sn_vnic1
1792026-04-15T21:17:52.018ZApr 15 21:17:51.997 DEBG destroying link mgtriou_ox_sn_sim1
1802026-04-15T21:17:52.018ZApr 15 21:17:51.997 INFO creating simnet link 'mgtriou_ox_sn_sim1'
1812026-04-15T21:17:52.018ZApr 15 21:17:51.999 INFO creating vnic link 'mgtriou_ox_sn_vnic1'
1822026-04-15T21:17:52.043ZApr 15 21:17:52.006 DEBG link pair created
1832026-04-15T21:17:52.043ZApr 15 21:17:52.006 DEBG destroying link mgtriou_cr2_vn_vnic0
1842026-04-15T21:17:52.043ZApr 15 21:17:52.006 DEBG destroying link mgtriou_cr2_vn_sim0
1852026-04-15T21:17:52.043ZApr 15 21:17:52.006 INFO creating simnet link 'mgtriou_cr2_vn_sim0'
1862026-04-15T21:17:52.043ZApr 15 21:17:52.007 INFO creating vnic link 'mgtriou_cr2_vn_vnic0'
1872026-04-15T21:17:52.043ZApr 15 21:17:52.014 DEBG link pair created
1882026-04-15T21:17:52.043ZApr 15 21:17:52.014 INFO creating external links
1892026-04-15T21:17:52.043ZApr 15 21:17:52.014 DEBG destroying external link mgtriou_ox_vn_vnic2
1902026-04-15T21:17:52.043ZApr 15 21:17:52.014 INFO creating external link mgtriou_ox_vn_vnic2
1912026-04-15T21:17:52.043ZApr 15 21:17:52.016 DEBG external link mgtriou_ox_vn_vnic2@igb0 created
1922026-04-15T21:17:52.043ZApr 15 21:17:52.016 DEBG destroying external link mgtriou_cr1_vn_vnic1
1932026-04-15T21:17:52.044ZApr 15 21:17:52.016 INFO creating external link mgtriou_cr1_vn_vnic1
1942026-04-15T21:17:52.044ZApr 15 21:17:52.017 DEBG external link mgtriou_cr1_vn_vnic1@igb0 created
1952026-04-15T21:17:52.045ZApr 15 21:17:52.017 DEBG destroying external link mgtriou_cr2_vn_vnic1
1962026-04-15T21:17:52.045ZApr 15 21:17:52.017 INFO creating external link mgtriou_cr2_vn_vnic1
1972026-04-15T21:17:52.045ZApr 15 21:17:52.018 DEBG external link mgtriou_cr2_vn_vnic1@igb0 created
1982026-04-15T21:17:52.045ZApr 15 21:17:52.018 INFO creating nodes
1992026-04-15T21:17:52.045ZApr 15 21:17:52.018 INFO ox: launching node
2002026-04-15T21:17:52.045ZApr 15 21:17:52.020 INFO cr1: launching node
2012026-04-15T21:17:52.045ZApr 15 21:17:52.022 INFO cr2: launching node
2022026-04-15T21:17:52.070ZApr 15 21:17:52.036 INFO launched instance ox with pid 849 on port 50922
2032026-04-15T21:17:52.070ZApr 15 21:17:52.036 INFO ox: instance ensure
2042026-04-15T21:17:52.070ZApr 15 21:17:52.036 INFO launched instance cr1 with pid 850 on port 39310
2052026-04-15T21:17:52.070ZApr 15 21:17:52.036 INFO cr1: instance ensure
2062026-04-15T21:17:52.070ZApr 15 21:17:52.048 INFO launched instance cr2 with pid 851 on port 46798
2072026-04-15T21:17:52.070ZApr 15 21:17:52.048 INFO cr2: instance ensure
2082026-04-15T21:17:54.382ZApr 15 21:17:54.369 INFO cr1: instance run
2092026-04-15T21:17:54.406ZApr 15 21:17:54.370 DEBG [sc] cr1: starting
2102026-04-15T21:17:54.406ZApr 15 21:17:54.370 DEBG [sc] cr1: connecting to [::1]:39310
2112026-04-15T21:17:54.408ZApr 15 21:17:54.371 DEBG [sc] cr1 waiting for prompt
2122026-04-15T21:17:54.509ZApr 15 21:17:54.491 INFO cr2: instance run
2132026-04-15T21:17:54.509ZApr 15 21:17:54.492 DEBG [sc] cr2: starting
2142026-04-15T21:17:54.509ZApr 15 21:17:54.492 DEBG [sc] cr2: connecting to [::1]:46798
2152026-04-15T21:17:54.509ZApr 15 21:17:54.493 DEBG [sc] cr2 waiting for prompt
2162026-04-15T21:17:54.566ZApr 15 21:17:54.554 INFO ox: instance run
2172026-04-15T21:17:54.590ZApr 15 21:17:54.554 DEBG [sc] ox: starting
2182026-04-15T21:17:54.590ZApr 15 21:17:54.554 DEBG [sc] ox: connecting to [::1]:50922
2192026-04-15T21:17:54.591ZApr 15 21:17:54.555 DEBG [sc] ox waiting for prompt
2202026-04-15T21:18:11.473ZApr 15 21:18:11.461 DEBG [sc] cr1: logging in
2212026-04-15T21:18:11.880ZApr 15 21:18:11.868 INFO cr1: mounting /opt/cargo-bay
2222026-04-15T21:18:11.881ZApr 15 21:18:11.868 DEBG [sc] cr1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2232026-04-15T21:18:11.905ZApr 15 21:18:11.889 DEBG [sc] cr1: executing command `cd`
2242026-04-15T21:18:11.929ZApr 15 21:18:11.900 INFO cr1: finished mounting /opt/cargo-bay
2252026-04-15T21:18:11.929ZApr 15 21:18:11.900 DEBG [sc] cr1: executing command `hostname cr1`
2262026-04-15T21:18:11.929ZApr 15 21:18:11.911 DEBG [sc] cr1: executing command `echo 'cr1' > /etc/nodename`
2272026-04-15T21:18:11.954ZApr 15 21:18:11.922 DEBG [sc] cr1: executing command `echo '::1 cr1.local cr1' >> /etc/hosts`
2282026-04-15T21:18:11.954ZApr 15 21:18:11.934 DEBG [sc] cr1: executing command `echo '127.0.0.1 cr1.local cr1' >> /etc/hosts`
2292026-04-15T21:18:11.978ZApr 15 21:18:11.945 INFO cr1: logging out
2302026-04-15T21:18:14.024ZApr 15 21:18:14.012 INFO cr1: logged out
2312026-04-15T21:18:15.115ZApr 15 21:18:15.103 DEBG [sc] ox: logging in
2322026-04-15T21:18:15.304ZApr 15 21:18:15.292 INFO ox: mounting /opt/cargo-bay
2332026-04-15T21:18:15.304ZApr 15 21:18:15.292 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2342026-04-15T21:18:16.072ZApr 15 21:18:16.060 DEBG [sc] cr2: logging in
2352026-04-15T21:18:16.253ZApr 15 21:18:16.241 DEBG [sc] ox: executing command `cd`
2362026-04-15T21:18:16.277ZApr 15 21:18:16.252 INFO ox: finished mounting /opt/cargo-bay
2372026-04-15T21:18:16.277ZApr 15 21:18:16.252 DEBG [sc] ox: executing command `hostname ox`
2382026-04-15T21:18:16.277ZApr 15 21:18:16.263 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
2392026-04-15T21:18:16.302ZApr 15 21:18:16.275 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
2402026-04-15T21:18:16.302ZApr 15 21:18:16.286 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
2412026-04-15T21:18:16.326ZApr 15 21:18:16.297 INFO ox: logging out
2422026-04-15T21:18:16.396ZApr 15 21:18:16.384 INFO ox: logged out
2432026-04-15T21:18:16.568ZApr 15 21:18:16.556 INFO cr2: mounting /opt/cargo-bay
2442026-04-15T21:18:16.569ZApr 15 21:18:16.556 DEBG [sc] cr2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2452026-04-15T21:18:16.593ZApr 15 21:18:16.577 DEBG [sc] cr2: executing command `cd`
2462026-04-15T21:18:16.616ZApr 15 21:18:16.589 INFO cr2: finished mounting /opt/cargo-bay
2472026-04-15T21:18:16.616ZApr 15 21:18:16.589 DEBG [sc] cr2: executing command `hostname cr2`
2482026-04-15T21:18:16.617ZApr 15 21:18:16.600 DEBG [sc] cr2: executing command `echo 'cr2' > /etc/nodename`
2492026-04-15T21:18:16.641ZApr 15 21:18:16.611 DEBG [sc] cr2: executing command `echo '::1 cr2.local cr2' >> /etc/hosts`
2502026-04-15T21:18:16.641ZApr 15 21:18:16.622 DEBG [sc] cr2: executing command `echo '127.0.0.1 cr2.local cr2' >> /etc/hosts`
2512026-04-15T21:18:16.665ZApr 15 21:18:16.633 INFO cr2: logging out
2522026-04-15T21:18:19.570ZApr 15 21:18:19.558 INFO cr2: logged out
2532026-04-15T21:18:19.594ZApr 15 21:18:19.558 DEBG [sc] ox: starting
2542026-04-15T21:18:19.594ZApr 15 21:18:19.558 DEBG [sc] ox: connecting to [::1]:50922
2552026-04-15T21:18:19.595ZApr 15 21:18:19.559 DEBG [sc] ox waiting for prompt
2562026-04-15T21:18:19.595ZApr 15 21:18:19.570 DEBG [sc] ox: logging in
2572026-04-15T21:18:19.670ZApr 15 21:18:19.658 DEBG [sc] ox: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2582026-04-15T21:18:24.657ZApr 15 21:18:24.645 DEBG [sc] ox: starting
2592026-04-15T21:18:24.657ZApr 15 21:18:24.645 DEBG [sc] ox: connecting to [::1]:50922
2602026-04-15T21:18:24.681ZApr 15 21:18:24.646 DEBG [sc] ox waiting for prompt
2612026-04-15T21:18:24.681ZApr 15 21:18:24.656 DEBG [sc] ox: logging in
2622026-04-15T21:18:24.756ZApr 15 21:18:24.744 DEBG [sc] ox: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2632026-04-15T21:18:24.834ZApr 15 21:18:24.822 DEBG [sc] ox: starting
2642026-04-15T21:18:24.834ZApr 15 21:18:24.822 DEBG [sc] ox: connecting to [::1]:50922
2652026-04-15T21:18:24.858ZApr 15 21:18:24.822 DEBG [sc] ox waiting for prompt
2662026-04-15T21:18:24.858ZApr 15 21:18:24.832 DEBG [sc] ox: logging in
2672026-04-15T21:18:24.922ZApr 15 21:18:24.909 DEBG [sc] ox: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2682026-04-15T21:18:24.987ZApr 15 21:18:24.975 INFO cr1: installing frr
2692026-04-15T21:18:24.987ZApr 15 21:18:24.975 INFO waiting for ceos to initialize
2702026-04-15T21:18:24.987ZApr 15 21:18:24.975 INFO ox: setting up npuvm
2712026-04-15T21:18:25.011ZApr 15 21:18:24.975 DEBG [sc] ox: starting
2722026-04-15T21:18:25.011ZApr 15 21:18:24.975 DEBG [sc] ox: connecting to [::1]:50922
2732026-04-15T21:18:25.012ZApr 15 21:18:24.975 DEBG [sc] cr1: starting
2742026-04-15T21:18:25.012ZApr 15 21:18:24.975 DEBG [sc] cr1: connecting to [::1]:39310
2752026-04-15T21:18:25.012ZApr 15 21:18:24.975 DEBG [sc] cr2: starting
2762026-04-15T21:18:25.012ZApr 15 21:18:24.975 DEBG [sc] cr2: connecting to [::1]:46798
2772026-04-15T21:18:25.012ZApr 15 21:18:24.976 DEBG [sc] ox waiting for prompt
2782026-04-15T21:18:25.012ZApr 15 21:18:24.976 DEBG [sc] cr1 waiting for prompt
2792026-04-15T21:18:25.012ZApr 15 21:18:24.976 DEBG [sc] cr2 waiting for prompt
2802026-04-15T21:18:25.012ZApr 15 21:18:24.986 DEBG [sc] ox: logging in
2812026-04-15T21:18:25.012ZApr 15 21:18:24.987 DEBG [sc] cr1: logging in
2822026-04-15T21:18:25.012ZApr 15 21:18:24.987 DEBG [sc] cr2: logging in
2832026-04-15T21:18:25.086ZApr 15 21:18:25.074 DEBG [sc] ox: executing command `curl --retry 5 -OL https://buildomat.eng.oxide.computer/public/file/oxidecomputer//softnpu/image/fd2c726815cdb03c2687e1bf2912a9184905557b/npuvm`
2842026-04-15T21:18:25.142ZApr 15 21:18:25.131 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
2852026-04-15T21:18:25.412ZApr 15 21:18:25.400 DEBG [sc] cr1: executing command `apt-get -y update && apt-get -y install frr`
2862026-04-15T21:18:27.365ZApr 15 21:18:27.353 INFO cr2: executing eos script show version
2872026-04-15T21:18:27.365ZApr 15 21:18:27.353 DEBG [sc] cr2: starting
2882026-04-15T21:18:27.366ZApr 15 21:18:27.353 DEBG [sc] cr2: connecting to [::1]:46798
2892026-04-15T21:18:27.391ZApr 15 21:18:27.353 DEBG [sc] cr2 waiting for prompt
2902026-04-15T21:18:27.391ZApr 15 21:18:27.363 DEBG [sc] cr2: logging in
2912026-04-15T21:18:27.519ZApr 15 21:18:27.507 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
2922026-04-15T21:18:30.645ZApr 15 21:18:30.632 DEBG [sc] ox: starting
2932026-04-15T21:18:30.645ZApr 15 21:18:30.632 DEBG [sc] ox: connecting to [::1]:50922
2942026-04-15T21:18:30.669ZApr 15 21:18:30.633 DEBG [sc] ox waiting for prompt
2952026-04-15T21:18:30.669ZApr 15 21:18:30.644 DEBG [sc] ox: logging in
2962026-04-15T21:18:30.734ZApr 15 21:18:30.722 DEBG [sc] ox: executing command `chmod +x npuvm`
2972026-04-15T21:18:30.800ZApr 15 21:18:30.788 DEBG [sc] ox: starting
2982026-04-15T21:18:30.800ZApr 15 21:18:30.788 DEBG [sc] ox: connecting to [::1]:50922
2992026-04-15T21:18:30.824ZApr 15 21:18:30.788 DEBG [sc] ox waiting for prompt
3002026-04-15T21:18:30.824ZApr 15 21:18:30.799 DEBG [sc] ox: logging in
3012026-04-15T21:18:30.899ZApr 15 21:18:30.887 DEBG [sc] ox: executing command `./npuvm install --front-ports 2 --rear-ports 0 --pkt-source vioif0 `
3022026-04-15T21:18:36.839ZApr 15 21:18:36.827 DEBG [sc] cr2: starting
3032026-04-15T21:18:36.839ZApr 15 21:18:36.827 DEBG [sc] cr2: connecting to [::1]:46798
3042026-04-15T21:18:36.864ZApr 15 21:18:36.828 DEBG [sc] cr2 waiting for prompt
3052026-04-15T21:18:36.864ZApr 15 21:18:36.839 DEBG [sc] cr2: logging in
3062026-04-15T21:18:36.997ZApr 15 21:18:36.982 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3072026-04-15T21:18:39.083ZApr 15 21:18:39.070 INFO cr2: executing eos script show version
3082026-04-15T21:18:39.083ZApr 15 21:18:39.071 DEBG [sc] cr2: starting
3092026-04-15T21:18:39.083ZApr 15 21:18:39.071 DEBG [sc] cr2: connecting to [::1]:46798
3102026-04-15T21:18:39.107ZApr 15 21:18:39.071 DEBG [sc] cr2 waiting for prompt
3112026-04-15T21:18:39.107ZApr 15 21:18:39.082 DEBG [sc] cr2: logging in
3122026-04-15T21:18:39.237ZApr 15 21:18:39.225 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3132026-04-15T21:18:41.504ZApr 15 21:18:41.492 DEBG [sc] cr2: starting
3142026-04-15T21:18:41.504ZApr 15 21:18:41.492 DEBG [sc] cr2: connecting to [::1]:46798
3152026-04-15T21:18:41.528ZApr 15 21:18:41.492 DEBG [sc] cr2 waiting for prompt
3162026-04-15T21:18:41.528ZApr 15 21:18:41.503 DEBG [sc] cr2: logging in
3172026-04-15T21:18:41.683ZApr 15 21:18:41.671 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3182026-04-15T21:18:43.846ZApr 15 21:18:43.834 INFO cr2: executing eos script show version
3192026-04-15T21:18:43.846ZApr 15 21:18:43.834 DEBG [sc] cr2: starting
3202026-04-15T21:18:43.846ZApr 15 21:18:43.834 DEBG [sc] cr2: connecting to [::1]:46798
3212026-04-15T21:18:43.870ZApr 15 21:18:43.834 DEBG [sc] cr2 waiting for prompt
3222026-04-15T21:18:43.870ZApr 15 21:18:43.845 DEBG [sc] cr2: logging in
3232026-04-15T21:18:44.012ZApr 15 21:18:43.999 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3242026-04-15T21:18:46.409ZApr 15 21:18:46.397 DEBG [sc] cr2: starting
3252026-04-15T21:18:46.409ZApr 15 21:18:46.397 DEBG [sc] cr2: connecting to [::1]:46798
3262026-04-15T21:18:46.434ZApr 15 21:18:46.398 DEBG [sc] cr2 waiting for prompt
3272026-04-15T21:18:46.434ZApr 15 21:18:46.408 DEBG [sc] cr2: logging in
3282026-04-15T21:18:46.563ZApr 15 21:18:46.551 DEBG [sc] cr2: executing command `docker inspect ceos --format '{{.State.Status}}'`
3292026-04-15T21:18:48.674ZApr 15 21:18:48.661 INFO cr2: executing eos script show version
3302026-04-15T21:18:48.674ZApr 15 21:18:48.662 DEBG [sc] cr2: starting
3312026-04-15T21:18:48.674ZApr 15 21:18:48.662 DEBG [sc] cr2: connecting to [::1]:46798
3322026-04-15T21:18:48.699ZApr 15 21:18:48.662 DEBG [sc] cr2 waiting for prompt
3332026-04-15T21:18:48.699ZApr 15 21:18:48.672 DEBG [sc] cr2: logging in
3342026-04-15T21:18:48.850ZApr 15 21:18:48.838 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show version'`
3352026-04-15T21:18:51.163ZApr 15 21:18:51.150 INFO cr2: executing eos script
3362026-04-15T21:18:51.163Z enable
3372026-04-15T21:18:51.163Z configure
3382026-04-15T21:18:51.163Z ipv6 unicast-routing
3392026-04-15T21:18:51.163Z ip routing ipv6 interfaces
3402026-04-15T21:18:51.163Z ip routing
3412026-04-15T21:18:51.163Z ip route 1.2.3.0/24 null0
3422026-04-15T21:18:51.163Z ipv6 route fd99::/64 null0
3432026-04-15T21:18:51.163Z interface et1
3442026-04-15T21:18:51.163Z no switchport
3452026-04-15T21:18:51.163Z ipv6 enable
3462026-04-15T21:18:51.163Z
3472026-04-15T21:18:51.163Z router bgp 45
3482026-04-15T21:18:51.163Z router-id 1.2.3.1
3492026-04-15T21:18:51.163Z no bgp default ipv4-unicast
3502026-04-15T21:18:51.163Z timers bgp 2 6
3512026-04-15T21:18:51.163Z neighbor ebgp peer group
3522026-04-15T21:18:51.163Z neighbor ebgp remote-as 33
3532026-04-15T21:18:51.163Z neighbor interface Et1 peer-group ebgp
3542026-04-15T21:18:51.163Z address-family ipv4
3552026-04-15T21:18:51.163Z neighbor ebgp activate
3562026-04-15T21:18:51.163Z neighbor ebgp next-hop address-family ipv6 originate
3572026-04-15T21:18:51.163Z network 1.2.3.0/24
3582026-04-15T21:18:51.163Z exit
3592026-04-15T21:18:51.163Z address-family ipv6
3602026-04-15T21:18:51.163Z neighbor ebgp activate
3612026-04-15T21:18:51.163Z neighbor ebgp next-hop address-family ipv6 originate
3622026-04-15T21:18:51.163Z network fd99::/64
3632026-04-15T21:18:51.163Z exit
3642026-04-15T21:18:51.163Z exit
3652026-04-15T21:18:51.163Z
3662026-04-15T21:18:51.164ZApr 15 21:18:51.150 DEBG [sc] cr2: starting
3672026-04-15T21:18:51.164ZApr 15 21:18:51.150 DEBG [sc] cr2: connecting to [::1]:46798
3682026-04-15T21:18:51.188ZApr 15 21:18:51.151 DEBG [sc] cr2 waiting for prompt
3692026-04-15T21:18:51.188ZApr 15 21:18:51.161 DEBG [sc] cr2: logging in
3702026-04-15T21:18:51.327ZApr 15 21:18:51.315 DEBG [sc] cr2: executing command `docker exec ceos Cli -c '
3712026-04-15T21:18:51.327Z enable
3722026-04-15T21:18:51.327Z configure
3732026-04-15T21:18:51.327Z ipv6 unicast-routing
3742026-04-15T21:18:51.327Z ip routing ipv6 interfaces
3752026-04-15T21:18:51.328Z ip routing
3762026-04-15T21:18:51.328Z ip route 1.2.3.0/24 null0
3772026-04-15T21:18:51.328Z ipv6 route fd99::/64 null0
3782026-04-15T21:18:51.328Z interface et1
3792026-04-15T21:18:51.328Z no switchport
3802026-04-15T21:18:51.328Z ipv6 enable
3812026-04-15T21:18:51.328Z
3822026-04-15T21:18:51.328Z router bgp 45
3832026-04-15T21:18:51.328Z router-id 1.2.3.1
3842026-04-15T21:18:51.329Z no bgp default ipv4-unicast
3852026-04-15T21:18:51.329Z timers bgp 2 6
3862026-04-15T21:18:51.329Z neighbor ebgp peer group
3872026-04-15T21:18:51.329Z neighbor ebgp remote-as 33
3882026-04-15T21:18:51.329Z neighbor interface Et1 peer-group ebgp
3892026-04-15T21:18:51.329Z address-family ipv4
3902026-04-15T21:18:51.329Z neighbor ebgp activate
3912026-04-15T21:18:51.329Z neighbor ebgp next-hop address-family ipv6 originate
3922026-04-15T21:18:51.329Z network 1.2.3.0/24
3932026-04-15T21:18:51.329Z exit
3942026-04-15T21:18:51.329Z address-family ipv6
3952026-04-15T21:18:51.329Z neighbor ebgp activate
3962026-04-15T21:18:51.329Z neighbor ebgp next-hop address-family ipv6 originate
3972026-04-15T21:18:51.329Z network fd99::/64
3982026-04-15T21:18:51.329Z exit
3992026-04-15T21:18:51.329Z exit
4002026-04-15T21:18:51.329Z '`
4012026-04-15T21:19:02.740ZApr 15 21:19:02.728 INFO cr1: enabling frr daemon bgpd
4022026-04-15T21:19:02.740ZApr 15 21:19:02.728 DEBG [sc] cr1: starting
4032026-04-15T21:19:02.740ZApr 15 21:19:02.728 DEBG [sc] cr1: connecting to [::1]:39310
4042026-04-15T21:19:02.765ZApr 15 21:19:02.729 DEBG [sc] cr1 waiting for prompt
4052026-04-15T21:19:02.765ZApr 15 21:19:02.739 DEBG [sc] cr1: logging in
4062026-04-15T21:19:02.894ZApr 15 21:19:02.882 DEBG [sc] cr1: executing command `sed -i 's/bgpd=no/bgpd=yes/g' /etc/frr/daemons`
4072026-04-15T21:19:04.962ZApr 15 21:19:04.949 DEBG [sc] cr1: starting
4082026-04-15T21:19:04.962ZApr 15 21:19:04.949 DEBG [sc] cr1: connecting to [::1]:39310
4092026-04-15T21:19:04.986ZApr 15 21:19:04.950 DEBG [sc] cr1 waiting for prompt
4102026-04-15T21:19:04.986ZApr 15 21:19:04.960 DEBG [sc] cr1: logging in
4112026-04-15T21:19:05.094ZApr 15 21:19:05.082 DEBG [sc] cr1: executing command `systemctl restart frr`
4122026-04-15T21:19:12.723ZApr 15 21:19:12.711 INFO cr1: executing frr script
4132026-04-15T21:19:12.723Z configure
4142026-04-15T21:19:12.723Z ip forwarding
4152026-04-15T21:19:12.723Z ipv6 forwarding
4162026-04-15T21:19:12.723Z ip route 1.2.3.0/24 null0
4172026-04-15T21:19:12.723Z ipv6 route fd99::/64 null0
4182026-04-15T21:19:12.723Z route-map PERMIT-ALL permit 10
4192026-04-15T21:19:12.723Z router bgp 44
4202026-04-15T21:19:12.723Z timers bgp 2 6
4212026-04-15T21:19:12.723Z neighbor enp0s8 interface remote-as external
4222026-04-15T21:19:12.723Z neighbor enp0s8 timers connect 1
4232026-04-15T21:19:12.723Z address-family ipv4 unicast
4242026-04-15T21:19:12.723Z network 1.2.3.0/24
4252026-04-15T21:19:12.723Z neighbor enp0s8 activate
4262026-04-15T21:19:12.723Z neighbor enp0s8 route-map PERMIT-ALL out
4272026-04-15T21:19:12.723Z neighbor enp0s8 route-map PERMIT-ALL in
4282026-04-15T21:19:12.723Z exit-address-family
4292026-04-15T21:19:12.723Z address-family ipv6 unicast
4302026-04-15T21:19:12.724Z network fd99::/64
4312026-04-15T21:19:12.724Z neighbor enp0s8 activate
4322026-04-15T21:19:12.724Z neighbor enp0s8 route-map PERMIT-ALL out
4332026-04-15T21:19:12.724Z neighbor enp0s8 route-map PERMIT-ALL in
4342026-04-15T21:19:12.724Z exit-address-family
4352026-04-15T21:19:12.724Z exit
4362026-04-15T21:19:12.724Z
4372026-04-15T21:19:12.724ZApr 15 21:19:12.711 DEBG [sc] cr1: starting
4382026-04-15T21:19:12.724ZApr 15 21:19:12.711 DEBG [sc] cr1: connecting to [::1]:39310
4392026-04-15T21:19:12.779ZApr 15 21:19:12.712 DEBG [sc] cr1 waiting for prompt
4402026-04-15T21:19:12.779ZApr 15 21:19:12.723 DEBG [sc] cr1: logging in
4412026-04-15T21:19:12.868ZApr 15 21:19:12.856 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 ' route-map PERMIT-ALL permit 10' -c ' router bgp 44' -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 ' neighbor enp0s8 route-map PERMIT-ALL out' -c ' neighbor enp0s8 route-map PERMIT-ALL in' -c ' exit-address-family' -c ' address-family ipv6 unicast' -c ' network fd99::/64' -c ' neighbor enp0s8 activate' -c ' neighbor enp0s8 route-map PERMIT-ALL out' -c ' neighbor enp0s8 route-map PERMIT-ALL in' -c ' exit-address-family' -c ' exit' -c ' '`
4422026-04-15T21:20:13.796ZApr 15 21:20:13.783 DEBG [sc] ox: starting
4432026-04-15T21:20:13.796ZApr 15 21:20:13.783 DEBG [sc] ox: connecting to [::1]:50922
4442026-04-15T21:20:13.820ZApr 15 21:20:13.784 DEBG [sc] ox waiting for prompt
4452026-04-15T21:20:13.820ZApr 15 21:20:13.794 DEBG [sc] ox: logging in
4462026-04-15T21:20:13.884ZApr 15 21:20:13.871 DEBG [sc] ox: executing command `/root/scadm propolis load-program /root/libsidecar_lite.so`
4472026-04-15T21:20:14.142ZApr 15 21:20:14.130 DEBG [sc] ox: starting
4482026-04-15T21:20:14.142ZApr 15 21:20:14.130 DEBG [sc] ox: connecting to [::1]:50922
4492026-04-15T21:20:14.166ZApr 15 21:20:14.130 DEBG [sc] ox waiting for prompt
4502026-04-15T21:20:14.166ZApr 15 21:20:14.142 DEBG [sc] ox: logging in
4512026-04-15T21:20:14.242ZApr 15 21:20:14.230 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4522026-04-15T21:20:15.266ZApr 15 21:20:15.254 DEBG [sc] ox: starting
4532026-04-15T21:20:15.266ZApr 15 21:20:15.254 DEBG [sc] ox: connecting to [::1]:50922
4542026-04-15T21:20:15.290ZApr 15 21:20:15.255 DEBG [sc] ox waiting for prompt
4552026-04-15T21:20:15.290ZApr 15 21:20:15.255 DEBG [sc] ox: logging in
4562026-04-15T21:20:15.343ZApr 15 21:20:15.331 DEBG [sc] ox: executing command `dladm show-link tfportqsfp0_0 -p -o link`
4572026-04-15T21:20:15.399ZApr 15 21:20:15.387 DEBG [sc] ox: starting
4582026-04-15T21:20:15.399ZApr 15 21:20:15.387 DEBG [sc] ox: connecting to [::1]:50922
4592026-04-15T21:20:15.423ZApr 15 21:20:15.388 DEBG [sc] ox waiting for prompt
4602026-04-15T21:20:15.424ZApr 15 21:20:15.398 DEBG [sc] ox: logging in
4612026-04-15T21:20:15.487ZApr 15 21:20:15.475 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp0_0/ll`
4622026-04-15T21:20:15.542ZApr 15 21:20:15.530 DEBG [sc] ox: starting
4632026-04-15T21:20:15.542ZApr 15 21:20:15.530 DEBG [sc] ox: connecting to [::1]:50922
4642026-04-15T21:20:15.566ZApr 15 21:20:15.531 DEBG [sc] ox waiting for prompt
4652026-04-15T21:20:15.566ZApr 15 21:20:15.540 DEBG [sc] ox: logging in
4662026-04-15T21:20:15.630ZApr 15 21:20:15.618 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp0_0/ll -p -o addr`
4672026-04-15T21:20:15.685ZApr 15 21:20:15.673 DEBG [sc] ox: starting
4682026-04-15T21:20:15.685ZApr 15 21:20:15.673 DEBG [sc] ox: connecting to [::1]:50922
4692026-04-15T21:20:15.709ZApr 15 21:20:15.673 DEBG [sc] ox waiting for prompt
4702026-04-15T21:20:15.709ZApr 15 21:20:15.683 DEBG [sc] ox: logging in
4712026-04-15T21:20:15.773ZApr 15 21:20:15.761 DEBG [sc] ox: executing command `dladm show-link tfportqsfp1_0 -p -o link`
4722026-04-15T21:20:15.829ZApr 15 21:20:15.817 DEBG [sc] ox: starting
4732026-04-15T21:20:15.830ZApr 15 21:20:15.817 DEBG [sc] ox: connecting to [::1]:50922
4742026-04-15T21:20:15.854ZApr 15 21:20:15.818 DEBG [sc] ox waiting for prompt
4752026-04-15T21:20:15.854ZApr 15 21:20:15.829 DEBG [sc] ox: logging in
4762026-04-15T21:20:15.918ZApr 15 21:20:15.906 DEBG [sc] ox: executing command `ipadm create-addr -T addrconf tfportqsfp1_0/ll`
4772026-04-15T21:20:15.974ZApr 15 21:20:15.962 DEBG [sc] ox: starting
4782026-04-15T21:20:15.974ZApr 15 21:20:15.962 DEBG [sc] ox: connecting to [::1]:50922
4792026-04-15T21:20:15.998ZApr 15 21:20:15.962 DEBG [sc] ox waiting for prompt
4802026-04-15T21:20:15.998ZApr 15 21:20:15.973 DEBG [sc] ox: logging in
4812026-04-15T21:20:16.063ZApr 15 21:20:16.050 DEBG [sc] ox: executing command `ipadm show-addr tfportqsfp1_0/ll -p -o addr`
4822026-04-15T21:20:16.118ZApr 15 21:20:16.106 DEBG [sc] ox: starting
4832026-04-15T21:20:16.119ZApr 15 21:20:16.106 DEBG [sc] ox: connecting to [::1]:50922
4842026-04-15T21:20:16.143ZApr 15 21:20:16.107 DEBG [sc] ox waiting for prompt
4852026-04-15T21:20:16.143ZApr 15 21:20:16.117 DEBG [sc] ox: logging in
4862026-04-15T21:20:16.206ZApr 15 21:20:16.194 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
4872026-04-15T21:20:16.273ZApr 15 21:20:16.260 DEBG [sc] ox: starting
4882026-04-15T21:20:16.273ZApr 15 21:20:16.260 DEBG [sc] ox: connecting to [::1]:50922
4892026-04-15T21:20:16.297ZApr 15 21:20:16.261 DEBG [sc] ox waiting for prompt
4902026-04-15T21:20:16.297ZApr 15 21:20:16.271 DEBG [sc] ox: logging in
4912026-04-15T21:20:16.361ZApr 15 21:20:16.349 DEBG [sc] ox: executing command `chmod +x /opt/cargo-bay/ddmd && /opt/cargo-bay/ddmd &> /tmp/ddm.log &`
4922026-04-15T21:20:16.417ZApr 15 21:20:16.405 INFO adding BGP router to mgd
4932026-04-15T21:20:18.435ZApr 15 21:20:18.423 INFO cr1: executing frr script show ip bgp json
4942026-04-15T21:20:18.435ZApr 15 21:20:18.423 DEBG [sc] cr1: starting
4952026-04-15T21:20:18.435ZApr 15 21:20:18.423 DEBG [sc] cr1: connecting to [::1]:39310
4962026-04-15T21:20:18.460ZApr 15 21:20:18.424 DEBG [sc] cr1 waiting for prompt
4972026-04-15T21:20:18.460ZApr 15 21:20:18.435 DEBG [sc] cr1: logging in
4982026-04-15T21:20:18.767ZApr 15 21:20:18.754 DEBG [sc] cr1: executing command `vtysh -c 'show ip bgp json'`
4992026-04-15T21:20:20.901ZApr 15 21:20:20.888 INFO cr1: executing frr script show bgp json
5002026-04-15T21:20:20.901ZApr 15 21:20:20.888 DEBG [sc] cr1: starting
5012026-04-15T21:20:20.901ZApr 15 21:20:20.888 DEBG [sc] cr1: connecting to [::1]:39310
5022026-04-15T21:20:20.925ZApr 15 21:20:20.889 DEBG [sc] cr1 waiting for prompt
5032026-04-15T21:20:20.925ZApr 15 21:20:20.899 DEBG [sc] cr1: logging in
5042026-04-15T21:20:21.065ZApr 15 21:20:21.053 DEBG [sc] cr1: executing command `vtysh -c 'show bgp json'`
5052026-04-15T21:20:23.200ZApr 15 21:20:23.188 INFO cr2: executing eos script show ip bgp | json
5062026-04-15T21:20:23.224ZApr 15 21:20:23.188 DEBG [sc] cr2: starting
5072026-04-15T21:20:23.224ZApr 15 21:20:23.188 DEBG [sc] cr2: connecting to [::1]:46798
5082026-04-15T21:20:23.224ZApr 15 21:20:23.189 DEBG [sc] cr2 waiting for prompt
5092026-04-15T21:20:23.224ZApr 15 21:20:23.200 DEBG [sc] cr2: logging in
5102026-04-15T21:20:23.541ZApr 15 21:20:23.528 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ip bgp | json'`
5112026-04-15T21:20:25.914ZApr 15 21:20:25.902 INFO cr2: executing eos script show ipv6 bgp | json
5122026-04-15T21:20:25.914ZApr 15 21:20:25.902 DEBG [sc] cr2: starting
5132026-04-15T21:20:25.914ZApr 15 21:20:25.902 DEBG [sc] cr2: connecting to [::1]:46798
5142026-04-15T21:20:25.938ZApr 15 21:20:25.903 DEBG [sc] cr2 waiting for prompt
5152026-04-15T21:20:25.938ZApr 15 21:20:25.913 DEBG [sc] cr2: logging in
5162026-04-15T21:20:26.080ZApr 15 21:20:26.067 DEBG [sc] cr2: executing command `docker exec ceos Cli -c 'show ipv6 bgp | json'`
5172026-04-15T21:20:28.476ZApr 15 21:20:28.463 INFO trio bgp unnumbered test passed 🎉
5182026-04-15T21:20:28.476ZApr 15 21:20:28.463 INFO destroying runner for deployment mgtriou
5192026-04-15T21:20:28.476ZApr 15 21:20:28.463 INFO destroying deployment mgtriou
5202026-04-15T21:20:28.476ZApr 15 21:20:28.463 INFO destroying nodes
5212026-04-15T21:20:28.575ZApr 15 21:20:28.563 INFO destroying links
5222026-04-15T21:20:28.575ZApr 15 21:20:28.563 INFO destroying link mgtriou_ox_sn_vnic0
5232026-04-15T21:20:28.600ZApr 15 21:20:28.566 INFO destroying link mgtriou_ox_sn_sim0
5242026-04-15T21:20:28.600ZApr 15 21:20:28.567 INFO destroying link mgtriou_cr1_vn_vnic0
5252026-04-15T21:20:29.583ZApr 15 21:20:29.570 INFO destroying link mgtriou_cr1_vn_sim0
5262026-04-15T21:20:29.606ZApr 15 21:20:29.571 INFO destroying link mgtriou_ox_sn_vnic1
5272026-04-15T21:20:29.606ZApr 15 21:20:29.572 INFO destroying link mgtriou_ox_sn_sim1
5282026-04-15T21:20:29.606ZApr 15 21:20:29.574 INFO destroying link mgtriou_cr2_vn_vnic0
5292026-04-15T21:20:29.606ZApr 15 21:20:29.575 INFO destroying link mgtriou_cr2_vn_sim0
5302026-04-15T21:20:29.606ZApr 15 21:20:29.576 INFO destroying external links
5312026-04-15T21:20:29.606ZApr 15 21:20:29.576 INFO destroying external link mgtriou_ox_vn_vnic2
5322026-04-15T21:20:29.606ZApr 15 21:20:29.577 INFO destroying external link mgtriou_cr1_vn_vnic1
5332026-04-15T21:20:29.606ZApr 15 21:20:29.579 INFO destroying external link mgtriou_cr2_vn_vnic1
5342026-04-15T21:20:29.606ZApr 15 21:20:29.580 INFO destroying images
5352026-04-15T21:20:30.061ZApr 15 21:20:30.048 INFO destroying workspace at .falcon
5362026-04-15T21:20:30.085Zprocess exited: duration 491160 ms, exit code 0
 
5372026-04-15T21:20:30.135Zfound 0 output files