01M700N3D3HB4Q96RHCSNMPJPT: falcon

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

Buildomat Job: 01M700Q96GHG8HRZQFNYF2C8NW

Tags:

Artefacts:

Output:

SEQ GLOBAL TIME DETAILS
12026-11-09T11:35:41.626Zjob dependencies complete; ready to run (waiting for 13 m 10 s)
22026-11-09T11:39:06.231Zjob assigned to worker 01M701FDF1TVAB8V5SSSF8B56S [factory edgar, gimlet/BRM42220010/1993] (queued for 3 m 24 s)
32026-11-09T11:39:07.087Zdownloading input: /input/build-dhcp-server/work/dhcp-server
42026-11-09T11:39:07.414Zdownloaded input: /input/build-dhcp-server/work/dhcp-server
52026-11-09T11:39:07.439Zdownloading input: /input/build/work/debug/ddmadm
62026-11-09T11:39:35.779Zdownloaded input: /input/build/work/debug/ddmadm
72026-11-09T11:39:35.779Zdownloading input: /input/build/work/debug/ddmd
82026-11-09T11:40:07.389Zdownloaded input: /input/build/work/debug/ddmd
92026-11-09T11:40:07.389Zdownloading input: /input/build/work/debug/mgadm
102026-11-09T11:40:44.182Zdownloaded input: /input/build/work/debug/mgadm
112026-11-09T11:40:44.182Zdownloading input: /input/build/work/debug/mgd
122026-11-09T11:41:23.882Zdownloaded input: /input/build/work/debug/mgd
132026-11-09T11:41:23.921Zdownloading input: /input/build/work/release/ddmadm
142026-11-09T11:41:26.389Zdownloaded input: /input/build/work/release/ddmadm
152026-11-09T11:41:26.389Zdownloading input: /input/build/work/release/ddmd
162026-11-09T11:41:29.325Zdownloaded input: /input/build/work/release/ddmd
172026-11-09T11:41:29.326Zdownloading input: /input/build/work/release/falcon-lab
182026-11-09T11:41:33.969Zdownloaded input: /input/build/work/release/falcon-lab
192026-11-09T11:41:33.969Zdownloading input: /input/build/work/release/mgadm
202026-11-09T11:41:40.161Zdownloaded input: /input/build/work/release/mgadm
212026-11-09T11:41:40.161Zdownloading input: /input/build/work/release/mgd
222026-11-09T11:41:44.930Zdownloaded input: /input/build/work/release/mgd
 
232026-11-09T11:41:44.930Zstarting task 0: "setup"
242026-11-09T11:41:44.956Z++ uname -s
252026-11-09T11:41:44.956Z+ kern=SunOS
262026-11-09T11:41:44.957Z+ build_user=build
272026-11-09T11:41:44.957Z+ build_uid=12345
282026-11-09T11:41:44.957Z+ work_dir=/work
292026-11-09T11:41:44.957Z+ input_dir=/input
302026-11-09T11:41:44.957Z+ [[ 0 == 12345 ]]
312026-11-09T11:41:44.957Z+ case "$kern" in
322026-11-09T11:41:44.957Z+ groupadd -g 12345 build
332026-11-09T11:41:44.957Z+ useradd -u 12345 -g build -d /home/build -s /bin/bash -c build -P 'Primary Administrator' build
342026-11-09T11:41:46.965Z+ zfs create -o mountpoint=/work rpool/work
352026-11-09T11:41:47.164Z++ awk '$2 == "/home" { print $3 }' /etc/mnttab
362026-11-09T11:41:47.189Z+ home_fs=
372026-11-09T11:41:47.189Z+ [[ '' == autofs ]]
382026-11-09T11:41:47.189Z+ mkdir -p /home/build
392026-11-09T11:41:47.189Z+ chown build:build /home/build /work
402026-11-09T11:41:48.177Z+ chmod 0700 /home/build /work
412026-11-09T11:41:48.202Zprocess exited: duration 3250 ms, exit code 0
 
422026-11-09T11:41:48.253Zstarting task 1: "authentication"
432026-11-09T11:41:48.348Zprocess exited: duration 95 ms, exit code 0
 
442026-11-09T11:41:48.399Zstarting task 2: "build"
452026-11-09T11:41:48.426Z+ set -e
462026-11-09T11:41:48.427Z+ set -o pipefail
472026-11-09T11:41:48.427Z+ banner zpool
482026-11-09T11:41:48.427Z
492026-11-09T11:41:48.427Z ###### ##### #### #### #
502026-11-09T11:41:48.427Z # # # # # # # #
512026-11-09T11:41:48.427Z # # # # # # # #
522026-11-09T11:41:48.427Z # ##### # # # # #
532026-11-09T11:41:48.427Z # # # # # # #
542026-11-09T11:41:48.427Z ###### # #### #### ######
552026-11-09T11:41:48.427Z
562026-11-09T11:41:48.427Z++ pfexec diskinfo -pH
572026-11-09T11:41:48.427Z++ sort -k8 -n -r
582026-11-09T11:41:48.427Z++ head -1
592026-11-09T11:41:48.453Z++ awk '{print $2}'
602026-11-09T11:41:48.483Z+ DISK=c9t0014EE81000BC3B1d0
612026-11-09T11:41:48.483Z+ export DISK
622026-11-09T11:41:48.508Z+ pfexec zpool create -o ashift=12 -f cpool c9t0014EE81000BC3B1d0
632026-11-09T11:41:48.802Z+ pfexec zfs create -o mountpoint=/ci cpool/ci
642026-11-09T11:41:48.827Z++ curl -s http://catacomb.eng.oxide.computer:12346/trim-me
652026-11-09T11:41:48.885Z+ trim_response=true
662026-11-09T11:41:48.912Z+ [[ true =~ true ]]
672026-11-09T11:41:48.912Z+ pfexec zpool trim cpool
682026-11-09T11:41:48.912Z+ true
692026-11-09T11:41:48.912Z++ zpool status -t cpool
702026-11-09T11:41:48.913Z+ trim_status=' pool: cpool
712026-11-09T11:41:48.913Z state: ONLINE
722026-11-09T11:41:48.913Z scan: none requested
732026-11-09T11:41:48.913Zconfig:
742026-11-09T11:41:48.913Z
752026-11-09T11:41:48.913Z NAME STATE READ WRITE CKSUM
762026-11-09T11:41:48.913Z cpool ONLINE 0 0 0
772026-11-09T11:41:48.913Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at November 9, 2026 at 11:41:48 AM UTC)
782026-11-09T11:41:48.913Z
792026-11-09T11:41:48.913Zerrors: No known data errors'
802026-11-09T11:41:48.913Z+ [[ pool: cpool
812026-11-09T11:41:48.913Z state: ONLINE
822026-11-09T11:41:48.913Z scan: none requested
832026-11-09T11:41:48.913Zconfig:
842026-11-09T11:41:48.913Z
852026-11-09T11:41:48.913Z NAME STATE READ WRITE CKSUM
862026-11-09T11:41:48.913Z cpool ONLINE 0 0 0
872026-11-09T11:41:48.914Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (1% trimmed, started at November 9, 2026 at 11:41:48 AM UTC)
882026-11-09T11:41:48.914Z
892026-11-09T11:41:48.914Zerrors: No known data errors =~ 100% ]]
902026-11-09T11:41:48.914Z+ sleep 10
912026-11-09T11:41:58.947Z+ true
922026-11-09T11:41:58.981Z++ zpool status -t cpool
932026-11-09T11:41:58.981Z+ trim_status=' pool: cpool
942026-11-09T11:41:58.981Z state: ONLINE
952026-11-09T11:41:58.981Z scan: none requested
962026-11-09T11:41:58.981Zconfig:
972026-11-09T11:41:58.981Z
982026-11-09T11:41:58.981Z NAME STATE READ WRITE CKSUM
992026-11-09T11:41:58.981Z cpool ONLINE 0 0 0
1002026-11-09T11:41:58.981Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (56% trimmed, started at November 9, 2026 at 11:41:48 AM UTC)
1012026-11-09T11:41:58.981Z
1022026-11-09T11:41:58.982Zerrors: No known data errors'
1032026-11-09T11:41:58.982Z+ [[ pool: cpool
1042026-11-09T11:41:58.982Z state: ONLINE
1052026-11-09T11:41:58.982Z scan: none requested
1062026-11-09T11:41:58.982Zconfig:
1072026-11-09T11:41:58.982Z
1082026-11-09T11:41:58.982Z NAME STATE READ WRITE CKSUM
1092026-11-09T11:41:58.982Z cpool ONLINE 0 0 0
1102026-11-09T11:41:58.982Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (56% trimmed, started at November 9, 2026 at 11:41:48 AM UTC)
1112026-11-09T11:41:58.982Z
1122026-11-09T11:41:58.982Zerrors: No known data errors =~ 100% ]]
1132026-11-09T11:41:58.982Z+ sleep 10
1142026-11-09T11:42:08.928Z+ true
1152026-11-09T11:42:08.953Z++ zpool status -t cpool
1162026-11-09T11:42:08.953Z+ trim_status=' pool: cpool
1172026-11-09T11:42:08.953Z state: ONLINE
1182026-11-09T11:42:08.953Z scan: none requested
1192026-11-09T11:42:08.953Zconfig:
1202026-11-09T11:42:08.953Z
1212026-11-09T11:42:08.953Z NAME STATE READ WRITE CKSUM
1222026-11-09T11:42:08.953Z cpool ONLINE 0 0 0
1232026-11-09T11:42:08.953Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at November 9, 2026 at 11:42:07 AM UTC)
1242026-11-09T11:42:08.953Z
1252026-11-09T11:42:08.953Zerrors: No known data errors'
1262026-11-09T11:42:08.954Z+ [[ pool: cpool
1272026-11-09T11:42:08.954Z state: ONLINE
1282026-11-09T11:42:08.954Z scan: none requested
1292026-11-09T11:42:08.954Zconfig:
1302026-11-09T11:42:08.954Z
1312026-11-09T11:42:08.954Z NAME STATE READ WRITE CKSUM
1322026-11-09T11:42:08.954Z cpool ONLINE 0 0 0
1332026-11-09T11:42:08.954Z c9t0014EE81000BC3B1d0 ONLINE 0 0 0 (100% trimmed, completed at November 9, 2026 at 11:42:07 AM UTC)
1342026-11-09T11:42:08.954Z
1352026-11-09T11:42:08.954Zerrors: No known data errors =~ 100% ]]
1362026-11-09T11:42:08.954Z+ break
1372026-11-09T11:42:08.954Z+ pfexec chown 12345 /ci
1382026-11-09T11:42:08.954Z+ cd /ci
1392026-11-09T11:42:08.954Z+ export FALCON_DATASET=cpool/falcon
1402026-11-09T11:42:08.954Z+ FALCON_DATASET=cpool/falcon
1412026-11-09T11:42:08.954Z+ banner setup
1422026-11-09T11:42:08.954Z
1432026-11-09T11:42:08.954Z #### ###### ##### # # #####
1442026-11-09T11:42:08.954Z # # # # # # #
1452026-11-09T11:42:08.954Z #### ##### # # # # #
1462026-11-09T11:42:08.954Z # # # # # #####
1472026-11-09T11:42:08.954Z # # # # # # #
1482026-11-09T11:42:08.955Z #### ###### # #### #
1492026-11-09T11:42:08.955Z
1502026-11-09T11:42:08.955Z+ cp /input/build-dhcp-server/work/dhcp-server .
1512026-11-09T11:42:08.980Z+ cp /input/build/work/release/falcon-lab .
1522026-11-09T11:42:09.004Z+ cp /input/build/work/release/mgd .
1532026-11-09T11:42:09.078Z+ cp /input/build/work/release/ddmd .
1542026-11-09T11:42:09.142Z+ chmod +x dhcp-server falcon-lab mgd ddmd
1552026-11-09T11:42:09.168Z+ mkdir -p cargo-bay
1562026-11-09T11:42:09.168Z+ mv mgd cargo-bay/
1572026-11-09T11:42:09.168Z+ mv ddmd cargo-bay/
1582026-11-09T11:42:09.168Z+ curl -sSfL --retry 10 --retry-all-errors -o cargo-bay/falcon-juniper-license.key http://catacomb.eng.oxide.computer:12346/falcon/jl
1592026-11-09T11:42:09.213Z+ chmod 0600 cargo-bay/falcon-juniper-license.key
1602026-11-09T11:42:09.238Z+ export EXT_INTERFACE=igb0
1612026-11-09T11:42:09.238Z+ EXT_INTERFACE=igb0
1622026-11-09T11:42:09.238Z++ bmat address ls -f extra -Ho first
1632026-11-09T11:42:09.263Z+ first=10.151.6.164
1642026-11-09T11:42:09.263Z++ bmat address ls -f extra -Ho last
1652026-11-09T11:42:09.263Z+ last=10.151.6.227
1662026-11-09T11:42:09.288Z++ bmat address ls -f extra -Ho gateway
1672026-11-09T11:42:09.288Z+ gw=10.151.6.1
1682026-11-09T11:42:09.313Z++ ipadm show-addr igb0/dhcp -po ADDR
1692026-11-09T11:42:09.313Z++ sed 's#/.*##g'
1702026-11-09T11:42:09.313Z+ server=10.151.6.100
1712026-11-09T11:42:09.313Z+ run_test mgd-duo bgp-unnumbered
1722026-11-09T11:42:09.314Z+ + local topology=mgd-duo
1732026-11-09T11:42:09.314Zpfexec ./dhcp-server 10.151.6.164 10.151.6.227 10.151.6.1 10.151.6.100
1742026-11-09T11:42:09.314Z+ local scenario=bgp-unnumbered
1752026-11-09T11:42:09.314Z+ local test_name=mgd-duo-bgp-unnumbered
1762026-11-09T11:42:09.314Z+ local status=0
1772026-11-09T11:42:09.314Z+ clear_falcon_workspace_files
1782026-11-09T11:42:09.314Z+ [[ -d .falcon ]]
1792026-11-09T11:42:09.314Z+ RUST_LOG=debug
1802026-11-09T11:42:09.314Z+ pfexec ./falcon-lab run mgd-duo bgp-unnumbered --no-cleanup
1812026-11-09T11:42:09.340ZNov 09 11:42:09.292 DEBG using default route interface igb0
1822026-11-09T11:42:09.340ZNov 09 11:42:09.293 DEBG using default route interface igb0
1832026-11-09T11:42:09.341ZNov 09 11:42:09.293 INFO launching runner: deployment(mgdduo_bgpu) persistent(true) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
1842026-11-09T11:42:09.341ZNov 09 11:42:09.293 INFO starting preflight for deployment mgdduo_bgpu
1852026-11-09T11:42:09.341ZNov 09 11:42:09.293 INFO propolis-server binary not found
1862026-11-09T11:42:09.341ZNov 09 11:42:09.293 INFO downloading propolis server rev 5e201ec4185ccb9182cc6ffcb09fadd9deee24ca, writing to .falcon/bin/propolis-server
1872026-11-09T11:42:18.578ZNov 09 11:42:18.555 INFO ovmf fd not found
1882026-11-09T11:42:18.578ZNov 09 11:42:18.555 INFO downloading ovmf
1892026-11-09T11:42:18.914ZNov 09 11:42:18.891 INFO base image for helios-3.0 does not exist, attempting to install
1902026-11-09T11:42:18.914ZNov 09 11:42:18.891 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/helios-3.0_0.raw.xz
1912026-11-09T11:42:50.209ZNov 09 11:42:50.191 INFO extracting image to /tmp/helios-3.0_0.raw
1922026-11-09T11:43:12.945ZNov 09 11:43:12.930 INFO creating zvol cpool/falcon/img/helios-3.0 of size 4508880896
1932026-11-09T11:43:12.992ZNov 09 11:43:12.979 INFO copying image data to zvol
1942026-11-09T11:43:23.515ZNov 09 11:43:23.502 INFO creating zfs snapshot cpool/falcon/img/helios-3.0@base
1952026-11-09T11:43:26.677ZNov 09 11:43:26.665 INFO creating links
1962026-11-09T11:43:26.677ZNov 09 11:43:26.665 DEBG destroying link mgdduo_bgpu_ox1_vn_vnic0
1972026-11-09T11:43:26.703ZNov 09 11:43:26.665 DEBG destroying link mgdduo_bgpu_ox1_vn_sim0
1982026-11-09T11:43:26.703ZNov 09 11:43:26.665 INFO creating simnet link 'mgdduo_bgpu_ox1_vn_sim0'
1992026-11-09T11:43:26.703ZNov 09 11:43:26.667 INFO creating vnic link 'mgdduo_bgpu_ox1_vn_vnic0'
2002026-11-09T11:43:26.703ZNov 09 11:43:26.672 DEBG link pair created
2012026-11-09T11:43:26.703ZNov 09 11:43:26.672 DEBG destroying link mgdduo_bgpu_ox2_vn_vnic0
2022026-11-09T11:43:26.703ZNov 09 11:43:26.672 DEBG destroying link mgdduo_bgpu_ox2_vn_sim0
2032026-11-09T11:43:26.703ZNov 09 11:43:26.672 INFO creating simnet link 'mgdduo_bgpu_ox2_vn_sim0'
2042026-11-09T11:43:26.703ZNov 09 11:43:26.673 INFO creating vnic link 'mgdduo_bgpu_ox2_vn_vnic0'
2052026-11-09T11:43:26.703ZNov 09 11:43:26.678 DEBG link pair created
2062026-11-09T11:43:26.703ZNov 09 11:43:26.678 INFO creating external links
2072026-11-09T11:43:26.703ZNov 09 11:43:26.678 DEBG destroying external link mgdduo_bgpu_ox1_vn_vnic1
2082026-11-09T11:43:26.703ZNov 09 11:43:26.678 INFO creating external link mgdduo_bgpu_ox1_vn_vnic1
2092026-11-09T11:43:26.703ZNov 09 11:43:26.681 DEBG external link mgdduo_bgpu_ox1_vn_vnic1@igb0 created
2102026-11-09T11:43:26.703ZNov 09 11:43:26.681 DEBG destroying external link mgdduo_bgpu_ox2_vn_vnic1
2112026-11-09T11:43:26.703ZNov 09 11:43:26.681 INFO creating external link mgdduo_bgpu_ox2_vn_vnic1
2122026-11-09T11:43:26.703ZNov 09 11:43:26.682 DEBG external link mgdduo_bgpu_ox2_vn_vnic1@igb0 created
2132026-11-09T11:43:26.704ZNov 09 11:43:26.682 INFO creating nodes
2142026-11-09T11:43:26.704ZNov 09 11:43:26.682 INFO ox1: launching node
2152026-11-09T11:43:26.704ZNov 09 11:43:26.683 INFO ox2: launching node
2162026-11-09T11:43:26.729ZNov 09 11:43:26.706 INFO launched instance ox1 with pid 863 on port 55458
2172026-11-09T11:43:26.730ZNov 09 11:43:26.708 INFO ox1: instance ensure
2182026-11-09T11:43:26.730ZNov 09 11:43:26.708 INFO launched instance ox2 with pid 864 on port 52693
2192026-11-09T11:43:26.732ZNov 09 11:43:26.709 INFO ox2: instance ensure
2202026-11-09T11:43:28.559ZNov 09 11:43:28.546 INFO ox2: instance ensure completed after 0 retries
2212026-11-09T11:43:28.559ZNov 09 11:43:28.546 INFO ox2: instance run
2222026-11-09T11:43:28.585ZNov 09 11:43:28.547 DEBG [sc] ox2: starting
2232026-11-09T11:43:28.585ZNov 09 11:43:28.547 DEBG [sc] ox2: connecting to [::1]:52693
2242026-11-09T11:43:28.585ZNov 09 11:43:28.549 DEBG [sc] ox2 waiting for prompt
2252026-11-09T11:43:28.585ZNov 09 11:43:28.550 INFO ox1: instance ensure completed after 0 retries
2262026-11-09T11:43:28.585ZNov 09 11:43:28.550 INFO ox1: instance run
2272026-11-09T11:43:28.585ZNov 09 11:43:28.551 DEBG [sc] ox1: starting
2282026-11-09T11:43:28.585ZNov 09 11:43:28.551 DEBG [sc] ox1: connecting to [::1]:55458
2292026-11-09T11:43:28.585ZNov 09 11:43:28.552 DEBG [sc] ox1 waiting for prompt
2302026-11-09T11:43:44.425ZNov 09 11:43:44.407 DEBG [sc] ox1: logging in
2312026-11-09T11:43:44.467ZNov 09 11:43:44.453 DEBG [sc] ox2: logging in
2322026-11-09T11:43:44.583ZNov 09 11:43:44.572 INFO ox1: mounting /opt/cargo-bay
2332026-11-09T11:43:44.583ZNov 09 11:43:44.572 DEBG [sc] ox1: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2342026-11-09T11:43:44.651ZNov 09 11:43:44.637 INFO ox2: mounting /opt/cargo-bay
2352026-11-09T11:43:44.651ZNov 09 11:43:44.637 DEBG [sc] ox2: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
2362026-11-09T11:43:46.322ZNov 09 11:43:46.310 DEBG [sc] ox1: executing command `cd`
2372026-11-09T11:43:46.346ZNov 09 11:43:46.320 INFO ox1: finished mounting /opt/cargo-bay
2382026-11-09T11:43:46.347ZNov 09 11:43:46.320 DEBG [sc] ox1: executing command `hostname ox1`
2392026-11-09T11:43:46.347ZNov 09 11:43:46.329 DEBG [sc] ox2: executing command `cd`
2402026-11-09T11:43:46.347ZNov 09 11:43:46.331 DEBG [sc] ox1: executing command `echo 'ox1' > /etc/nodename`
2412026-11-09T11:43:46.373ZNov 09 11:43:46.339 INFO ox2: finished mounting /opt/cargo-bay
2422026-11-09T11:43:46.373ZNov 09 11:43:46.339 DEBG [sc] ox2: executing command `hostname ox2`
2432026-11-09T11:43:46.373ZNov 09 11:43:46.343 DEBG [sc] ox1: executing command `echo '::1 ox1.local ox1' >> /etc/hosts`
2442026-11-09T11:43:46.373ZNov 09 11:43:46.350 DEBG [sc] ox2: executing command `echo 'ox2' > /etc/nodename`
2452026-11-09T11:43:46.373ZNov 09 11:43:46.354 DEBG [sc] ox1: executing command `echo '127.0.0.1 ox1.local ox1' >> /etc/hosts`
2462026-11-09T11:43:46.398ZNov 09 11:43:46.361 DEBG [sc] ox2: executing command `echo '::1 ox2.local ox2' >> /etc/hosts`
2472026-11-09T11:43:46.398ZNov 09 11:43:46.365 INFO ox1: logging out
2482026-11-09T11:43:46.398ZNov 09 11:43:46.373 DEBG [sc] ox2: executing command `echo '127.0.0.1 ox2.local ox2' >> /etc/hosts`
2492026-11-09T11:43:46.398ZNov 09 11:43:46.384 INFO ox2: logging out
2502026-11-09T11:43:46.500ZNov 09 11:43:46.473 INFO ox1: logged out
2512026-11-09T11:43:46.525ZNov 09 11:43:46.503 INFO ox2: logged out
2522026-11-09T11:43:46.525ZNov 09 11:43:46.504 DEBG [sc] ox1: starting
2532026-11-09T11:43:46.525ZNov 09 11:43:46.504 DEBG [sc] ox1: connecting to [::1]:55458
2542026-11-09T11:43:46.525ZNov 09 11:43:46.505 DEBG [sc] ox2: starting
2552026-11-09T11:43:46.525ZNov 09 11:43:46.505 DEBG [sc] ox2: connecting to [::1]:52693
2562026-11-09T11:43:46.525ZNov 09 11:43:46.506 DEBG [sc] ox2 waiting for prompt
2572026-11-09T11:43:46.525ZNov 09 11:43:46.507 DEBG [sc] ox1 waiting for prompt
2582026-11-09T11:43:46.550ZNov 09 11:43:46.515 DEBG [sc] ox2: logging in
2592026-11-09T11:43:46.550ZNov 09 11:43:46.518 DEBG [sc] ox1: logging in
2602026-11-09T11:43:46.638ZNov 09 11:43:46.626 DEBG [sc] ox2: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2612026-11-09T11:43:46.663ZNov 09 11:43:46.627 DEBG [sc] ox1: executing command `ipadm create-addr -T dhcp vioif1/dhcp`
2622026-11-09T11:43:51.607ZNov 09 11:43:51.595 DEBG [sc] ox2: starting
2632026-11-09T11:43:51.607ZNov 09 11:43:51.595 DEBG [sc] ox2: connecting to [::1]:52693
2642026-11-09T11:43:51.632ZNov 09 11:43:51.596 DEBG [sc] ox2 waiting for prompt
2652026-11-09T11:43:51.632ZNov 09 11:43:51.606 DEBG [sc] ox2: logging in
2662026-11-09T11:43:51.706ZNov 09 11:43:51.694 DEBG [sc] ox2: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2672026-11-09T11:43:51.793ZNov 09 11:43:51.782 DEBG [sc] ox2: starting
2682026-11-09T11:43:51.794ZNov 09 11:43:51.782 DEBG [sc] ox2: connecting to [::1]:52693
2692026-11-09T11:43:51.819ZNov 09 11:43:51.783 DEBG [sc] ox2 waiting for prompt
2702026-11-09T11:43:51.819ZNov 09 11:43:51.793 DEBG [sc] ox2: logging in
2712026-11-09T11:43:51.892ZNov 09 11:43:51.881 DEBG [sc] ox2: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2722026-11-09T11:43:52.151ZNov 09 11:43:52.140 DEBG [sc] ox1: starting
2732026-11-09T11:43:52.151ZNov 09 11:43:52.140 DEBG [sc] ox1: connecting to [::1]:55458
2742026-11-09T11:43:52.176ZNov 09 11:43:52.141 DEBG [sc] ox1 waiting for prompt
2752026-11-09T11:43:52.176ZNov 09 11:43:52.151 DEBG [sc] ox1: logging in
2762026-11-09T11:43:52.252ZNov 09 11:43:52.240 DEBG [sc] ox1: executing command `echo 'nameserver 1.1.1.1' > /etc/resolv.conf`
2772026-11-09T11:43:52.341ZNov 09 11:43:52.329 DEBG [sc] ox1: starting
2782026-11-09T11:43:52.341ZNov 09 11:43:52.329 DEBG [sc] ox1: connecting to [::1]:55458
2792026-11-09T11:43:52.366ZNov 09 11:43:52.331 DEBG [sc] ox1 waiting for prompt
2802026-11-09T11:43:52.366ZNov 09 11:43:52.340 DEBG [sc] ox1: logging in
2812026-11-09T11:43:52.439ZNov 09 11:43:52.428 DEBG [sc] ox1: executing command `ipadm show-addr vioif1/dhcp -p -o addr`
2822026-11-09T11:43:52.508ZNov 09 11:43:52.497 DEBG [sc] ox1: starting
2832026-11-09T11:43:52.509ZNov 09 11:43:52.497 DEBG [sc] ox1: connecting to [::1]:55458
2842026-11-09T11:43:52.534ZNov 09 11:43:52.498 DEBG [sc] ox1 waiting for prompt
2852026-11-09T11:43:52.534ZNov 09 11:43:52.506 DEBG [sc] ox1: logging in
2862026-11-09T11:43:52.605ZNov 09 11:43:52.594 DEBG [sc] ox1: executing command `ipadm create-addr -T addrconf vioif0/ll`
2872026-11-09T11:43:52.705ZNov 09 11:43:52.693 DEBG [sc] ox1: starting
2882026-11-09T11:43:52.705ZNov 09 11:43:52.693 DEBG [sc] ox1: connecting to [::1]:55458
2892026-11-09T11:43:52.730ZNov 09 11:43:52.694 DEBG [sc] ox1 waiting for prompt
2902026-11-09T11:43:52.730ZNov 09 11:43:52.704 DEBG [sc] ox1: logging in
2912026-11-09T11:43:52.806ZNov 09 11:43:52.794 DEBG [sc] ox1: executing command `ipadm show-addr vioif0/ll -p -o addr`
2922026-11-09T11:43:52.871ZNov 09 11:43:52.859 DEBG [sc] ox2: starting
2932026-11-09T11:43:52.871ZNov 09 11:43:52.859 DEBG [sc] ox2: connecting to [::1]:52693
2942026-11-09T11:43:52.896ZNov 09 11:43:52.861 DEBG [sc] ox2 waiting for prompt
2952026-11-09T11:43:52.896ZNov 09 11:43:52.872 DEBG [sc] ox2: logging in
2962026-11-09T11:43:52.972ZNov 09 11:43:52.960 DEBG [sc] ox2: executing command `ipadm create-addr -T addrconf vioif0/ll`
2972026-11-09T11:43:53.082ZNov 09 11:43:53.071 DEBG [sc] ox2: starting
2982026-11-09T11:43:53.083ZNov 09 11:43:53.071 DEBG [sc] ox2: connecting to [::1]:52693
2992026-11-09T11:43:53.107ZNov 09 11:43:53.072 DEBG [sc] ox2 waiting for prompt
3002026-11-09T11:43:53.107ZNov 09 11:43:53.082 DEBG [sc] ox2: logging in
3012026-11-09T11:43:53.182ZNov 09 11:43:53.171 DEBG [sc] ox2: executing command `ipadm show-addr vioif0/ll -p -o addr`
3022026-11-09T11:43:53.260ZNov 09 11:43:53.249 DEBG [sc] ox1: starting
3032026-11-09T11:43:53.260ZNov 09 11:43:53.249 DEBG [sc] ox1: connecting to [::1]:55458
3042026-11-09T11:43:53.285ZNov 09 11:43:53.250 DEBG [sc] ox2: starting
3052026-11-09T11:43:53.286ZNov 09 11:43:53.250 DEBG [sc] ox2: connecting to [::1]:52693
3062026-11-09T11:43:53.286ZNov 09 11:43:53.251 DEBG [sc] ox2 waiting for prompt
3072026-11-09T11:43:53.286ZNov 09 11:43:53.251 DEBG [sc] ox1 waiting for prompt
3082026-11-09T11:43:53.286ZNov 09 11:43:53.259 DEBG [sc] ox2: logging in
3092026-11-09T11:43:53.286ZNov 09 11:43:53.262 DEBG [sc] ox1: logging in
3102026-11-09T11:43:53.359ZNov 09 11:43:53.348 DEBG [sc] ox2: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
3112026-11-09T11:43:53.383ZNov 09 11:43:53.350 DEBG [sc] ox1: executing command `chmod +x /opt/cargo-bay/mgd && /opt/cargo-bay/mgd run &> /tmp/mgd.log &`
3122026-11-09T11:43:53.428ZNov 09 11:43:53.417 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/config/routers, method: GET, operation_id: read_routers
3132026-11-09T11:43:53.452ZNov 09 11:43:53.417 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/config/routers, method: GET, operation_id: read_routers
3142026-11-09T11:43:53.452ZNov 09 11:43:53.417 DEBG client response, result: Err(reqwest::Error { kind: Request, url: "http://10.151.6.165:4676/bgp/config/routers", source: hyper_util::client::legacy::Error(Connect, ConnectError("tcp connect error", 10.151.6.165:4676, Os { code: 146, kind: ConnectionRefused, message: "Connection refused" })) }), operation_id: read_routers
3152026-11-09T11:43:53.452ZNov 09 11:43:53.417 DEBG wait for mgd: Communication Error: error sending request for url (http://10.151.6.165:4676/bgp/config/routers)
3162026-11-09T11:43:53.452ZNov 09 11:43:53.417 DEBG client response, result: Err(reqwest::Error { kind: Request, url: "http://10.151.6.164:4676/bgp/config/routers", source: hyper_util::client::legacy::Error(Connect, ConnectError("tcp connect error", 10.151.6.164:4676, Os { code: 146, kind: ConnectionRefused, message: "Connection refused" })) }), operation_id: read_routers
3172026-11-09T11:43:53.453ZNov 09 11:43:53.417 DEBG wait for mgd: Communication Error: error sending request for url (http://10.151.6.164:4676/bgp/config/routers)
3182026-11-09T11:43:54.430ZNov 09 11:43:54.418 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/config/routers, method: GET, operation_id: read_routers
3192026-11-09T11:43:54.476ZNov 09 11:43:54.419 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/config/routers, method: GET, operation_id: read_routers
3202026-11-09T11:43:54.476ZNov 09 11:43:54.424 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/config/routers", status: 200, headers: {"content-type": "application/json", "x-request-id": "bab6ca6b-a92c-49a9-9ebf-b2be21f0b2c9", "content-length": "2", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: read_routers
3212026-11-09T11:43:54.477ZNov 09 11:43:54.424 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/config/routers", status: 200, headers: {"content-type": "application/json", "x-request-id": "aa305116-1b8c-40cc-a16b-4afc009a3e81", "content-length": "2", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: read_routers
3222026-11-09T11:43:54.477ZNov 09 11:43:54.424 INFO adding BGP routers to both mgd nodes
3232026-11-09T11:43:54.477ZNov 09 11:43:54.424 DEBG client request, body: Some(Body), uri: http://10.151.6.165:4676/bgp/config/router, method: PUT, operation_id: create_router
3242026-11-09T11:43:54.477ZNov 09 11:43:54.424 DEBG client request, body: Some(Body), uri: http://10.151.6.164:4676/bgp/config/router, method: PUT, operation_id: create_router
3252026-11-09T11:43:54.477ZNov 09 11:43:54.428 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/config/router", status: 204, headers: {"x-request-id": "90bacfb7-2dcc-4763-b2f6-e3f3051344c2", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: create_router
3262026-11-09T11:43:54.477ZNov 09 11:43:54.429 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/config/router", status: 204, headers: {"x-request-id": "02d30d66-4592-4c1f-b288-d5e7a7b6d535", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: create_router
3272026-11-09T11:43:54.477ZNov 09 11:43:54.429 INFO adding unnumbered BGP neighbors to both mgd nodes
3282026-11-09T11:43:54.477ZNov 09 11:43:54.429 DEBG client request, body: Some(Body), uri: http://10.151.6.165:4676/bgp/config/unnumbered-neighbor, method: PUT, operation_id: create_unnumbered_neighbor
3292026-11-09T11:43:54.477ZNov 09 11:43:54.429 DEBG client request, body: Some(Body), uri: http://10.151.6.164:4676/bgp/config/unnumbered-neighbor, method: PUT, operation_id: create_unnumbered_neighbor
3302026-11-09T11:43:54.477ZNov 09 11:43:54.434 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/config/unnumbered-neighbor", status: 204, headers: {"x-request-id": "55e26e32-c6cc-4f63-a002-27a5628dcabb", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: create_unnumbered_neighbor
3312026-11-09T11:43:54.477ZNov 09 11:43:54.435 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/config/unnumbered-neighbor", status: 204, headers: {"x-request-id": "80a62751-3701-4445-84ae-c6bb3b4a4cfd", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: create_unnumbered_neighbor
3322026-11-09T11:43:54.477ZNov 09 11:43:54.435 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3332026-11-09T11:43:54.477ZNov 09 11:43:54.435 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3342026-11-09T11:43:54.477ZNov 09 11:43:54.436 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "b500719f-318d-4a5d-bcbb-2e8df18016c2", "content-length": "2139", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: get_neighbors
3352026-11-09T11:43:54.477ZNov 09 11:43:54.437 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3362026-11-09T11:43:54.477ZNov 09 11:43:54.437 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "51f087c1-9e32-4f0d-a425-3cf43c663da2", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: get_neighbors
3372026-11-09T11:43:54.477ZNov 09 11:43:54.437 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3382026-11-09T11:43:54.477ZNov 09 11:43:54.437 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "ade41d53-9ca1-4440-a415-325b35b4c4be", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: get_neighbors
3392026-11-09T11:43:54.477Zmgd1 bgp ox2 established: iteration 1/20: expected Some(Established), got Some(Connect)
3402026-11-09T11:43:54.477Zmgd2 bgp ox1 established: iteration 1/20: expected Some(Established), got Some(Connect)
3412026-11-09T11:43:54.477ZNov 09 11:43:54.437 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "66779121-648c-4dbb-9640-7e3878db7443", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:54 GMT"} }), operation_id: get_neighbors
3422026-11-09T11:43:55.452ZNov 09 11:43:55.438 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3432026-11-09T11:43:55.452ZNov 09 11:43:55.439 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3442026-11-09T11:43:55.477ZNov 09 11:43:55.439 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "0923153a-5fba-416e-a1cd-3fd922fe9416", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:55 GMT"} }), operation_id: get_neighbors
3452026-11-09T11:43:55.478ZNov 09 11:43:55.439 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "93e21149-195c-4cee-b897-11684c03aa08", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:55 GMT"} }), operation_id: get_neighbors
3462026-11-09T11:43:55.478Zmgd1 bgp ox2 established: iteration 2/20: expected Some(Established), got Some(Connect)
3472026-11-09T11:43:55.478Zmgd2 bgp ox1 established: iteration 2/20: expected Some(Established), got Some(Connect)
3482026-11-09T11:43:56.452ZNov 09 11:43:56.441 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3492026-11-09T11:43:56.453ZNov 09 11:43:56.441 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3502026-11-09T11:43:56.478ZNov 09 11:43:56.441 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "ace6ec9e-a042-4d2b-8f36-3115eb22eaf6", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:56 GMT"} }), operation_id: get_neighbors
3512026-11-09T11:43:56.478Zmgd2 bgp ox1 established: iteration 3/20: expected Some(Established), got Some(Connect)
3522026-11-09T11:43:56.478ZNov 09 11:43:56.442 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "828030e1-7908-4ee9-96c5-c54365150214", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:56 GMT"} }), operation_id: get_neighbors
3532026-11-09T11:43:56.478Zmgd1 bgp ox2 established: iteration 3/20: expected Some(Established), got Some(Connect)
3542026-11-09T11:43:57.454ZNov 09 11:43:57.443 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3552026-11-09T11:43:57.455ZNov 09 11:43:57.443 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3562026-11-09T11:43:57.480Zmgd2 bgp ox1 established: iteration 4/20: expected Some(Established), got Some(Connect)
3572026-11-09T11:43:57.480Zmgd1 bgp ox2 established: iteration 4/20: expected Some(Established), got Some(Connect)
3582026-11-09T11:43:57.480ZNov 09 11:43:57.444 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "d9a0bed8-d08b-40d2-9792-59a0ec04a1ea", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:57 GMT"} }), operation_id: get_neighbors
3592026-11-09T11:43:57.480ZNov 09 11:43:57.444 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "2b10463e-0359-4f4c-9008-77189c950617", "content-length": "2140", "date": "Mon, 09 Nov 2026 11:43:57 GMT"} }), operation_id: get_neighbors
3602026-11-09T11:43:58.457ZNov 09 11:43:58.445 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3612026-11-09T11:43:58.457ZNov 09 11:43:58.445 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3622026-11-09T11:43:58.497ZNov 09 11:43:58.447 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "6b92fa0a-7c62-494f-84a1-cb5df11151b6", "content-length": "2141", "date": "Mon, 09 Nov 2026 11:43:58 GMT"} }), operation_id: get_neighbors
3632026-11-09T11:43:58.498Zmgd2 bgp ox1 established: iteration 5/20: expected Some(Established), got Some(Connect)
3642026-11-09T11:43:58.498Zmgd1 bgp ox2 established: iteration 5/20: expected Some(Established), got Some(Connect)
3652026-11-09T11:43:58.498ZNov 09 11:43:58.447 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "a18f3f02-1a1d-43a9-9d3c-de39715d3714", "content-length": "2141", "date": "Mon, 09 Nov 2026 11:43:58 GMT"} }), operation_id: get_neighbors
3662026-11-09T11:43:59.463ZNov 09 11:43:59.448 DEBG client request, body: None, uri: http://10.151.6.165:4676/bgp/status/neighbors?asn=33, method: GET, operation_id: get_neighbors
3672026-11-09T11:43:59.463ZNov 09 11:43:59.448 DEBG client request, body: None, uri: http://10.151.6.164:4676/bgp/status/neighbors?asn=44, method: GET, operation_id: get_neighbors
3682026-11-09T11:43:59.544ZNov 09 11:43:59.449 DEBG client response, result: Ok(Response { url: "http://10.151.6.164:4676/bgp/status/neighbors?asn=44", status: 200, headers: {"content-type": "application/json", "x-request-id": "908e1ad2-cb0a-4378-beb3-f45ea97dbc6b", "content-length": "2372", "date": "Mon, 09 Nov 2026 11:43:59 GMT"} }), operation_id: get_neighbors
3692026-11-09T11:43:59.544ZNov 09 11:43:59.449 DEBG client response, result: Ok(Response { url: "http://10.151.6.165:4676/bgp/status/neighbors?asn=33", status: 200, headers: {"content-type": "application/json", "x-request-id": "20e39e76-d686-417a-baac-78ef72fd828e", "content-length": "2372", "date": "Mon, 09 Nov 2026 11:43:59 GMT"} }), operation_id: get_neighbors
3702026-11-09T11:43:59.544ZNov 09 11:43:59.449 INFO mgd-to-mgd bgp unnumbered test passed 🎉
3712026-11-09T11:43:59.544Z+ (( status != 0 ))
3722026-11-09T11:43:59.544Z+ pfexec ./falcon-lab cleanup mgd-duo bgp-unnumbered
3732026-11-09T11:43:59.573ZNov 09 11:43:59.478 INFO destroying runner for deployment mgdduo_bgpu
3742026-11-09T11:43:59.573ZNov 09 11:43:59.479 INFO destroying deployment mgdduo_bgpu
3752026-11-09T11:43:59.574ZNov 09 11:43:59.479 INFO destroying nodes
3762026-11-09T11:43:59.574ZNov 09 11:43:59.484 INFO destroying links
3772026-11-09T11:43:59.574ZNov 09 11:43:59.484 INFO destroying link mgdduo_bgpu_ox1_vn_vnic0
3782026-11-09T11:44:00.500ZNov 09 11:44:00.488 INFO destroying link mgdduo_bgpu_ox1_vn_sim0
3792026-11-09T11:44:00.533ZNov 09 11:44:00.489 INFO destroying link mgdduo_bgpu_ox2_vn_vnic0
3802026-11-09T11:44:00.533ZNov 09 11:44:00.490 INFO destroying link mgdduo_bgpu_ox2_vn_sim0
3812026-11-09T11:44:00.533ZNov 09 11:44:00.491 INFO destroying external links
3822026-11-09T11:44:00.533ZNov 09 11:44:00.491 INFO destroying external link mgdduo_bgpu_ox1_vn_vnic1
3832026-11-09T11:44:00.533ZNov 09 11:44:00.492 INFO destroying external link mgdduo_bgpu_ox2_vn_vnic1
3842026-11-09T11:44:00.533ZNov 09 11:44:00.494 INFO destroying images
3852026-11-09T11:44:00.664ZNov 09 11:44:00.648 INFO destroying workspace at .falcon
3862026-11-09T11:44:00.745Z+ return 0
3872026-11-09T11:44:00.745Z+ run_test interop bgp-unnumbered
3882026-11-09T11:44:00.745Z+ local topology=interop
3892026-11-09T11:44:00.745Z+ local scenario=bgp-unnumbered
3902026-11-09T11:44:00.745Z+ local test_name=interop-bgp-unnumbered
3912026-11-09T11:44:00.745Z+ local status=0
3922026-11-09T11:44:00.745Z+ clear_falcon_workspace_files
3932026-11-09T11:44:00.745Z+ [[ -d .falcon ]]
3942026-11-09T11:44:00.745Z+ find .falcon -maxdepth 1 -type f -exec rm -f '{}' +
3952026-11-09T11:44:00.745Z+ RUST_LOG=debug
3962026-11-09T11:44:00.745Z+ pfexec ./falcon-lab run interop bgp-unnumbered --no-cleanup
3972026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
3982026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
3992026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
4002026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
4012026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
4022026-11-09T11:44:00.745ZNov 09 11:44:00.678 DEBG using default route interface igb0
4032026-11-09T11:44:00.745ZNov 09 11:44:00.678 INFO interop_bgpu: launching interop topology
4042026-11-09T11:44:00.745ZNov 09 11:44:00.678 INFO launching runner: deployment(interop_bgpu) persistent(true) custom_propolis_binary(None) dataset(cpool/falcon) falcon_dir(.falcon)
4052026-11-09T11:44:00.746ZNov 09 11:44:00.678 INFO starting preflight for deployment interop_bgpu
4062026-11-09T11:44:02.700ZNov 09 11:44:02.688 INFO base image for debian-13.2 does not exist, attempting to install
4072026-11-09T11:44:02.700ZNov 09 11:44:02.689 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/debian-13.2_0.raw.xz
4082026-11-09T11:44:26.197ZNov 09 11:44:26.187 INFO extracting image to /tmp/debian-13.2_0.raw
4092026-11-09T11:44:40.157ZNov 09 11:44:40.147 INFO creating zvol cpool/falcon/img/debian-13.2 of size 3221229568
4102026-11-09T11:44:40.182ZNov 09 11:44:40.171 INFO copying image data to zvol
4112026-11-09T11:44:47.395ZNov 09 11:44:47.385 INFO creating zfs snapshot cpool/falcon/img/debian-13.2@base
4122026-11-09T11:44:50.421ZNov 09 11:44:50.403 INFO base image for eos-4.35 does not exist, attempting to install
4132026-11-09T11:44:50.421ZNov 09 11:44:50.403 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/eos-4.35_0.raw.xz
4142026-11-09T11:45:42.800ZNov 09 11:45:42.792 INFO extracting image to /tmp/eos-4.35_0.raw
4152026-11-09T11:46:47.586ZNov 09 11:46:47.578 INFO creating zvol cpool/falcon/img/eos-4.35 of size 21474840576
4162026-11-09T11:46:47.611ZNov 09 11:46:47.601 INFO copying image data to zvol
4172026-11-09T11:47:36.102ZNov 09 11:47:36.094 INFO creating zfs snapshot cpool/falcon/img/eos-4.35@base
4182026-11-09T11:47:39.328ZNov 09 11:47:39.319 INFO base image for junos-23.2 does not exist, attempting to install
4192026-11-09T11:47:39.328ZNov 09 11:47:39.319 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/junos-23.2_0.raw.xz
4202026-11-09T11:48:14.401ZNov 09 11:48:14.392 INFO extracting image to /tmp/junos-23.2_0.raw
4212026-11-09T11:49:13.613ZNov 09 11:49:13.603 INFO creating zvol cpool/falcon/img/junos-23.2 of size 21474840576
4222026-11-09T11:49:13.646ZNov 09 11:49:13.629 INFO copying image data to zvol
4232026-11-09T11:50:02.341ZNov 09 11:50:02.330 INFO creating zfs snapshot cpool/falcon/img/junos-23.2@base
4242026-11-09T11:50:05.660ZNov 09 11:50:05.650 INFO base image for bird2 does not exist, attempting to install
4252026-11-09T11:50:05.660ZNov 09 11:50:05.650 INFO trying to download https://oxide-falcon-assets.s3.us-west-2.amazonaws.com/bird2_0.raw.xz
4262026-11-09T11:50:26.995ZNov 09 11:50:26.984 INFO extracting image to /tmp/bird2_0.raw
4272026-11-09T11:51:23.039ZNov 09 11:51:23.026 INFO creating zvol cpool/falcon/img/bird2 of size 21474840576
4282026-11-09T11:51:23.065ZNov 09 11:51:23.050 INFO copying image data to zvol
4292026-11-09T11:52:11.882ZNov 09 11:52:11.870 INFO creating zfs snapshot cpool/falcon/img/bird2@base
4302026-11-09T11:52:15.089ZNov 09 11:52:15.078 INFO creating links
4312026-11-09T11:52:15.090ZNov 09 11:52:15.078 DEBG destroying link interop_bgpu_ox_sn_vnic0
4322026-11-09T11:52:15.090ZNov 09 11:52:15.078 DEBG destroying link interop_bgpu_ox_sn_sim0
4332026-11-09T11:52:15.114ZNov 09 11:52:15.078 INFO creating simnet link 'interop_bgpu_ox_sn_sim0'
4342026-11-09T11:52:15.114ZNov 09 11:52:15.080 INFO creating vnic link 'interop_bgpu_ox_sn_vnic0'
4352026-11-09T11:52:15.114ZNov 09 11:52:15.085 DEBG link pair created
4362026-11-09T11:52:15.114ZNov 09 11:52:15.085 DEBG destroying link interop_bgpu_cr1_vn_vnic0
4372026-11-09T11:52:15.114ZNov 09 11:52:15.085 DEBG destroying link interop_bgpu_cr1_vn_sim0
4382026-11-09T11:52:15.114ZNov 09 11:52:15.085 INFO creating simnet link 'interop_bgpu_cr1_vn_sim0'
4392026-11-09T11:52:15.115ZNov 09 11:52:15.087 INFO creating vnic link 'interop_bgpu_cr1_vn_vnic0'
4402026-11-09T11:52:15.115ZNov 09 11:52:15.091 DEBG link pair created
4412026-11-09T11:52:15.115ZNov 09 11:52:15.091 DEBG destroying link interop_bgpu_ox_sn_vnic1
4422026-11-09T11:52:15.115ZNov 09 11:52:15.091 DEBG destroying link interop_bgpu_ox_sn_sim1
4432026-11-09T11:52:15.115ZNov 09 11:52:15.091 INFO creating simnet link 'interop_bgpu_ox_sn_sim1'
4442026-11-09T11:52:15.115ZNov 09 11:52:15.093 INFO creating vnic link 'interop_bgpu_ox_sn_vnic1'
4452026-11-09T11:52:15.115ZNov 09 11:52:15.097 DEBG link pair created
4462026-11-09T11:52:15.115ZNov 09 11:52:15.097 DEBG destroying link interop_bgpu_cr2_vn_vnic0
4472026-11-09T11:52:15.115ZNov 09 11:52:15.097 DEBG destroying link interop_bgpu_cr2_vn_sim0
4482026-11-09T11:52:15.115ZNov 09 11:52:15.097 INFO creating simnet link 'interop_bgpu_cr2_vn_sim0'
4492026-11-09T11:52:15.115ZNov 09 11:52:15.098 INFO creating vnic link 'interop_bgpu_cr2_vn_vnic0'
4502026-11-09T11:52:15.115ZNov 09 11:52:15.103 DEBG link pair created
4512026-11-09T11:52:15.115ZNov 09 11:52:15.103 DEBG destroying link interop_bgpu_ox_sn_vnic2
4522026-11-09T11:52:15.115ZNov 09 11:52:15.103 DEBG destroying link interop_bgpu_ox_sn_sim2
4532026-11-09T11:52:15.115ZNov 09 11:52:15.103 INFO creating simnet link 'interop_bgpu_ox_sn_sim2'
4542026-11-09T11:52:15.141ZNov 09 11:52:15.104 INFO creating vnic link 'interop_bgpu_ox_sn_vnic2'
4552026-11-09T11:52:15.141ZNov 09 11:52:15.108 DEBG link pair created
4562026-11-09T11:52:15.141ZNov 09 11:52:15.108 DEBG destroying link interop_bgpu_cr3_vn_vnic0
4572026-11-09T11:52:15.141ZNov 09 11:52:15.108 DEBG destroying link interop_bgpu_cr3_vn_sim0
4582026-11-09T11:52:15.141ZNov 09 11:52:15.108 INFO creating simnet link 'interop_bgpu_cr3_vn_sim0'
4592026-11-09T11:52:15.141ZNov 09 11:52:15.110 INFO creating vnic link 'interop_bgpu_cr3_vn_vnic0'
4602026-11-09T11:52:15.141ZNov 09 11:52:15.114 DEBG link pair created
4612026-11-09T11:52:15.141ZNov 09 11:52:15.114 DEBG destroying link interop_bgpu_ox_sn_vnic3
4622026-11-09T11:52:15.141ZNov 09 11:52:15.114 DEBG destroying link interop_bgpu_ox_sn_sim3
4632026-11-09T11:52:15.141ZNov 09 11:52:15.114 INFO creating simnet link 'interop_bgpu_ox_sn_sim3'
4642026-11-09T11:52:15.141ZNov 09 11:52:15.116 INFO creating vnic link 'interop_bgpu_ox_sn_vnic3'
4652026-11-09T11:52:15.141ZNov 09 11:52:15.120 DEBG link pair created
4662026-11-09T11:52:15.141ZNov 09 11:52:15.120 DEBG destroying link interop_bgpu_peer_vn_vnic0
4672026-11-09T11:52:15.141ZNov 09 11:52:15.120 DEBG destroying link interop_bgpu_peer_vn_sim0
4682026-11-09T11:52:15.141ZNov 09 11:52:15.120 INFO creating simnet link 'interop_bgpu_peer_vn_sim0'
4692026-11-09T11:52:15.141ZNov 09 11:52:15.121 INFO creating vnic link 'interop_bgpu_peer_vn_vnic0'
4702026-11-09T11:52:15.141ZNov 09 11:52:15.126 DEBG link pair created
4712026-11-09T11:52:15.141ZNov 09 11:52:15.126 DEBG destroying link interop_bgpu_ox_sn_vnic4
4722026-11-09T11:52:15.141ZNov 09 11:52:15.126 DEBG destroying link interop_bgpu_ox_sn_sim4
4732026-11-09T11:52:15.141ZNov 09 11:52:15.126 INFO creating simnet link 'interop_bgpu_ox_sn_sim4'
4742026-11-09T11:52:15.141ZNov 09 11:52:15.127 INFO creating vnic link 'interop_bgpu_ox_sn_vnic4'
4752026-11-09T11:52:15.166ZNov 09 11:52:15.132 DEBG link pair created
4762026-11-09T11:52:15.166ZNov 09 11:52:15.132 DEBG destroying link interop_bgpu_bird_vn_vnic0
4772026-11-09T11:52:15.166ZNov 09 11:52:15.132 DEBG destroying link interop_bgpu_bird_vn_sim0
4782026-11-09T11:52:15.166ZNov 09 11:52:15.132 INFO creating simnet link 'interop_bgpu_bird_vn_sim0'
4792026-11-09T11:52:15.166ZNov 09 11:52:15.133 INFO creating vnic link 'interop_bgpu_bird_vn_vnic0'
4802026-11-09T11:52:15.166ZNov 09 11:52:15.138 DEBG link pair created
4812026-11-09T11:52:15.166ZNov 09 11:52:15.138 INFO creating external links
4822026-11-09T11:52:15.167ZNov 09 11:52:15.138 DEBG destroying external link interop_bgpu_ox_vn_vnic5
4832026-11-09T11:52:15.167ZNov 09 11:52:15.138 INFO creating external link interop_bgpu_ox_vn_vnic5
4842026-11-09T11:52:15.167ZNov 09 11:52:15.140 DEBG external link interop_bgpu_ox_vn_vnic5@igb0 created
4852026-11-09T11:52:15.167ZNov 09 11:52:15.140 DEBG destroying external link interop_bgpu_cr1_vn_vnic1
4862026-11-09T11:52:15.167ZNov 09 11:52:15.140 INFO creating external link interop_bgpu_cr1_vn_vnic1
4872026-11-09T11:52:15.167ZNov 09 11:52:15.141 DEBG external link interop_bgpu_cr1_vn_vnic1@igb0 created
4882026-11-09T11:52:15.167ZNov 09 11:52:15.141 DEBG destroying external link interop_bgpu_cr2_vn_vnic1
4892026-11-09T11:52:15.167ZNov 09 11:52:15.141 INFO creating external link interop_bgpu_cr2_vn_vnic1
4902026-11-09T11:52:15.167ZNov 09 11:52:15.142 DEBG external link interop_bgpu_cr2_vn_vnic1@igb0 created
4912026-11-09T11:52:15.167ZNov 09 11:52:15.142 DEBG destroying external link interop_bgpu_cr3_vn_vnic1
4922026-11-09T11:52:15.167ZNov 09 11:52:15.142 INFO creating external link interop_bgpu_cr3_vn_vnic1
4932026-11-09T11:52:15.167ZNov 09 11:52:15.144 DEBG external link interop_bgpu_cr3_vn_vnic1@igb0 created
4942026-11-09T11:52:15.167ZNov 09 11:52:15.144 DEBG destroying external link interop_bgpu_peer_vn_vnic1
4952026-11-09T11:52:15.167ZNov 09 11:52:15.144 INFO creating external link interop_bgpu_peer_vn_vnic1
4962026-11-09T11:52:15.167ZNov 09 11:52:15.145 DEBG external link interop_bgpu_peer_vn_vnic1@igb0 created
4972026-11-09T11:52:15.167ZNov 09 11:52:15.145 DEBG destroying external link interop_bgpu_bird_vn_vnic1
4982026-11-09T11:52:15.167ZNov 09 11:52:15.145 INFO creating external link interop_bgpu_bird_vn_vnic1
4992026-11-09T11:52:15.167ZNov 09 11:52:15.146 DEBG external link interop_bgpu_bird_vn_vnic1@igb0 created
5002026-11-09T11:52:15.167ZNov 09 11:52:15.146 INFO creating nodes
5012026-11-09T11:52:15.167ZNov 09 11:52:15.146 INFO ox: launching node
5022026-11-09T11:52:15.167ZNov 09 11:52:15.147 INFO cr1: launching node
5032026-11-09T11:52:15.167ZNov 09 11:52:15.148 INFO cr2: launching node
5042026-11-09T11:52:15.167ZNov 09 11:52:15.148 INFO cr3: launching node
5052026-11-09T11:52:15.168ZNov 09 11:52:15.149 INFO peer: launching node
5062026-11-09T11:52:15.168ZNov 09 11:52:15.150 INFO bird: launching node
5072026-11-09T11:52:15.193ZNov 09 11:52:15.163 INFO launched instance ox with pid 929 on port 47025
5082026-11-09T11:52:15.193ZNov 09 11:52:15.165 INFO ox: instance ensure
5092026-11-09T11:52:15.193ZNov 09 11:52:15.165 INFO launched instance cr1 with pid 930 on port 35286
5102026-11-09T11:52:15.193ZNov 09 11:52:15.166 INFO cr1: instance ensure
5112026-11-09T11:52:15.193ZNov 09 11:52:15.166 INFO launched instance cr2 with pid 931 on port 40781
5122026-11-09T11:52:15.193ZNov 09 11:52:15.167 INFO cr2: instance ensure
5132026-11-09T11:52:15.193ZNov 09 11:52:15.167 INFO launched instance cr3 with pid 932 on port 38009
5142026-11-09T11:52:15.193ZNov 09 11:52:15.168 INFO cr3: instance ensure
5152026-11-09T11:52:15.193ZNov 09 11:52:15.168 INFO launched instance peer with pid 933 on port 34216
5162026-11-09T11:52:15.193ZNov 09 11:52:15.169 INFO peer: instance ensure
5172026-11-09T11:52:15.193ZNov 09 11:52:15.169 INFO launched instance bird with pid 934 on port 61877
5182026-11-09T11:52:15.193ZNov 09 11:52:15.170 INFO bird: instance ensure
5192026-11-09T11:52:19.176ZNov 09 11:52:19.165 INFO cr1: instance ensure completed after 0 retries
5202026-11-09T11:52:19.176ZNov 09 11:52:19.165 INFO cr1: instance run
5212026-11-09T11:52:19.201ZNov 09 11:52:19.166 DEBG [sc] cr1: starting
5222026-11-09T11:52:19.201ZNov 09 11:52:19.166 DEBG [sc] cr1: connecting to [::1]:35286
5232026-11-09T11:52:19.201ZNov 09 11:52:19.167 DEBG [sc] cr1 waiting for prompt
5242026-11-09T11:52:19.225ZNov 09 11:52:19.192 INFO peer: instance ensure completed after 0 retries
5252026-11-09T11:52:19.225ZNov 09 11:52:19.192 INFO peer: instance run
5262026-11-09T11:52:19.226ZNov 09 11:52:19.193 DEBG [sc] peer: starting
5272026-11-09T11:52:19.226ZNov 09 11:52:19.193 DEBG [sc] peer: connecting to [::1]:34216
5282026-11-09T11:52:19.226ZNov 09 11:52:19.194 DEBG [sc] peer waiting for prompt
5292026-11-09T11:52:19.772ZNov 09 11:52:19.760 INFO cr2: instance ensure completed after 0 retries
5302026-11-09T11:52:19.772ZNov 09 11:52:19.760 INFO cr2: instance run
5312026-11-09T11:52:19.796ZNov 09 11:52:19.761 DEBG [sc] cr2: starting
5322026-11-09T11:52:19.796ZNov 09 11:52:19.761 DEBG [sc] cr2: connecting to [::1]:40781
5332026-11-09T11:52:19.796ZNov 09 11:52:19.762 DEBG [sc] cr2 waiting for prompt
5342026-11-09T11:52:19.796ZNov 09 11:52:19.765 INFO ox: instance ensure completed after 0 retries
5352026-11-09T11:52:19.797ZNov 09 11:52:19.765 INFO ox: instance run
5362026-11-09T11:52:19.797ZNov 09 11:52:19.766 DEBG [sc] ox: starting
5372026-11-09T11:52:19.797ZNov 09 11:52:19.766 DEBG [sc] ox: connecting to [::1]:47025
5382026-11-09T11:52:19.797ZNov 09 11:52:19.767 DEBG [sc] ox waiting for prompt
5392026-11-09T11:52:19.945ZNov 09 11:52:19.934 INFO cr3: instance ensure completed after 0 retries
5402026-11-09T11:52:19.945ZNov 09 11:52:19.934 INFO cr3: instance run
5412026-11-09T11:52:19.983ZNov 09 11:52:19.972 INFO bird: instance ensure completed after 0 retries
5422026-11-09T11:52:19.983ZNov 09 11:52:19.972 INFO bird: instance run
5432026-11-09T11:52:20.008ZNov 09 11:52:19.972 DEBG [sc] bird: starting
5442026-11-09T11:52:20.008ZNov 09 11:52:19.972 DEBG [sc] bird: connecting to [::1]:61877
5452026-11-09T11:52:20.008ZNov 09 11:52:19.974 DEBG [sc] bird waiting for prompt
5462026-11-09T11:52:35.771ZNov 09 11:52:35.760 DEBG [sc] ox: logging in
5472026-11-09T11:52:35.796ZNov 09 11:52:35.780 DEBG [sc] peer: logging in
5482026-11-09T11:52:35.996ZNov 09 11:52:35.985 INFO ox: mounting /opt/cargo-bay
5492026-11-09T11:52:35.996ZNov 09 11:52:35.985 DEBG [sc] ox: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5502026-11-09T11:52:36.039ZNov 09 11:52:36.028 INFO peer: mounting /opt/cargo-bay
5512026-11-09T11:52:36.039ZNov 09 11:52:36.028 DEBG [sc] peer: executing command `mkdir -p /opt/cargo-bay; cd /opt/cargo-bay; p9kp pull`
5522026-11-09T11:52:37.422ZNov 09 11:52:37.410 DEBG [sc] peer: executing command `cd`
5532026-11-09T11:52:37.446ZNov 09 11:52:37.421 INFO peer: finished mounting /opt/cargo-bay
5542026-11-09T11:52:37.446ZNov 09 11:52:37.421 DEBG [sc] peer: executing command `hostname peer`
5552026-11-09T11:52:37.446ZNov 09 11:52:37.433 DEBG [sc] peer: executing command `echo 'peer' > /etc/nodename`
5562026-11-09T11:52:37.471ZNov 09 11:52:37.443 DEBG [sc] peer: executing command `echo '::1 peer.local peer' >> /etc/hosts`
5572026-11-09T11:52:37.471ZNov 09 11:52:37.454 DEBG [sc] peer: executing command `echo '127.0.0.1 peer.local peer' >> /etc/hosts`
5582026-11-09T11:52:37.495ZNov 09 11:52:37.465 INFO peer: logging out
5592026-11-09T11:52:37.519ZNov 09 11:52:37.507 DEBG [sc] ox: executing command `cd`
5602026-11-09T11:52:37.543ZNov 09 11:52:37.519 INFO ox: finished mounting /opt/cargo-bay
5612026-11-09T11:52:37.543ZNov 09 11:52:37.519 DEBG [sc] ox: executing command `hostname ox`
5622026-11-09T11:52:37.543ZNov 09 11:52:37.530 DEBG [sc] ox: executing command `echo 'ox' > /etc/nodename`
5632026-11-09T11:52:37.568ZNov 09 11:52:37.541 DEBG [sc] ox: executing command `echo '::1 ox.local ox' >> /etc/hosts`
5642026-11-09T11:52:37.568ZNov 09 11:52:37.552 DEBG [sc] ox: executing command `echo '127.0.0.1 ox.local ox' >> /etc/hosts`
5652026-11-09T11:52:37.568ZNov 09 11:52:37.554 INFO peer: logged out
5662026-11-09T11:52:37.592ZNov 09 11:52:37.563 INFO ox: logging out
5672026-11-09T11:52:37.641ZNov 09 11:52:37.630 INFO ox: logged out
5682026-11-09T11:52:38.307ZNov 09 11:52:38.296 DEBG [sc] cr1: logging in
5692026-11-09T11:52:38.464ZNov 09 11:52:38.453 DEBG [sc] cr2: logging in
5702026-11-09T11:52:38.627ZNov 09 11:52:38.616 DEBG [sc] bird: logging in
5712026-11-09T11:52:48.685ZNov 09 11:52:48.673 ERRO launch failed: exec: [sc] cr1: timeout waiting for data
5722026-11-09T11:52:48.710ZError: launch failed
5732026-11-09T11:52:48.710Z
5742026-11-09T11:52:48.710ZCaused by:
5752026-11-09T11:52:48.710Z exec: [sc] cr1: timeout waiting for data
5762026-11-09T11:52:48.710Z+ status=1
5772026-11-09T11:52:48.710Z+ (( status != 0 ))
5782026-11-09T11:52:48.710Z+ collect_falcon_artifacts interop-bgp-unnumbered
5792026-11-09T11:52:48.710Z+ local test_name=interop-bgp-unnumbered
5802026-11-09T11:52:48.710Z+ local artifact_dir=/work/falcon-interop-bgp-unnumbered
5812026-11-09T11:52:48.710Z+ local path
5822026-11-09T11:52:48.710Z+ [[ ! -d .falcon ]]
5832026-11-09T11:52:48.710Z+ rm -rf /work/falcon-interop-bgp-unnumbered
5842026-11-09T11:52:48.735Z+ mkdir -p /work/falcon-interop-bgp-unnumbered
5852026-11-09T11:52:48.735Z+ for path in .falcon/*.{out,err}
5862026-11-09T11:52:48.735Z+ [[ -e .falcon/bird.out ]]
5872026-11-09T11:52:48.735Z+ cp -p .falcon/bird.out /work/falcon-interop-bgp-unnumbered/
5882026-11-09T11:52:48.735Z+ for path in .falcon/*.{out,err}
5892026-11-09T11:52:48.735Z+ [[ -e .falcon/cr1.out ]]
5902026-11-09T11:52:48.735Z+ cp -p .falcon/cr1.out /work/falcon-interop-bgp-unnumbered/
5912026-11-09T11:52:48.735Z+ for path in .falcon/*.{out,err}
5922026-11-09T11:52:48.735Z+ [[ -e .falcon/cr2.out ]]
5932026-11-09T11:52:48.735Z+ cp -p .falcon/cr2.out /work/falcon-interop-bgp-unnumbered/
5942026-11-09T11:52:48.735Z+ for path in .falcon/*.{out,err}
5952026-11-09T11:52:48.735Z+ [[ -e .falcon/cr3.out ]]
5962026-11-09T11:52:48.735Z+ cp -p .falcon/cr3.out /work/falcon-interop-bgp-unnumbered/
5972026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
5982026-11-09T11:52:48.760Z+ [[ -e .falcon/ox.out ]]
5992026-11-09T11:52:48.760Z+ cp -p .falcon/ox.out /work/falcon-interop-bgp-unnumbered/
6002026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
6012026-11-09T11:52:48.760Z+ [[ -e .falcon/peer.out ]]
6022026-11-09T11:52:48.760Z+ cp -p .falcon/peer.out /work/falcon-interop-bgp-unnumbered/
6032026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
6042026-11-09T11:52:48.760Z+ [[ -e .falcon/bird.err ]]
6052026-11-09T11:52:48.760Z+ cp -p .falcon/bird.err /work/falcon-interop-bgp-unnumbered/
6062026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
6072026-11-09T11:52:48.760Z+ [[ -e .falcon/cr1.err ]]
6082026-11-09T11:52:48.760Z+ cp -p .falcon/cr1.err /work/falcon-interop-bgp-unnumbered/
6092026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
6102026-11-09T11:52:48.760Z+ [[ -e .falcon/cr2.err ]]
6112026-11-09T11:52:48.760Z+ cp -p .falcon/cr2.err /work/falcon-interop-bgp-unnumbered/
6122026-11-09T11:52:48.760Z+ for path in .falcon/*.{out,err}
6132026-11-09T11:52:48.760Z+ [[ -e .falcon/cr3.err ]]
6142026-11-09T11:52:48.760Z+ cp -p .falcon/cr3.err /work/falcon-interop-bgp-unnumbered/
6152026-11-09T11:52:48.785Z+ for path in .falcon/*.{out,err}
6162026-11-09T11:52:48.785Z+ [[ -e .falcon/ox.err ]]
6172026-11-09T11:52:48.785Z+ cp -p .falcon/ox.err /work/falcon-interop-bgp-unnumbered/
6182026-11-09T11:52:48.785Z+ for path in .falcon/*.{out,err}
6192026-11-09T11:52:48.786Z+ [[ -e .falcon/peer.err ]]
6202026-11-09T11:52:48.786Z+ cp -p .falcon/peer.err /work/falcon-interop-bgp-unnumbered/
6212026-11-09T11:52:48.786Z+ tar cvfz /work/falcon-interop-bgp-unnumbered.tar.gz -C /work falcon-interop-bgp-unnumbered
6222026-11-09T11:52:48.786ZCompressing '/work/falcon-interop-bgp-unnumbered.tar.gz' with '/usr/bin/gzip'...
6232026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/ 0K
6242026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/peer.out 50K
6252026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/ox.out 54K
6262026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/bird.err 1K
6272026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr3.err 1K
6282026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr1.out 50K
6292026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr2.err 1K
6302026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr3.out 49K
6312026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/bird.out 50K
6322026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr1.err 1K
6332026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/ox.err 1K
6342026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/peer.err 1K
6352026-11-09T11:52:48.786Za falcon-interop-bgp-unnumbered/cr2.out 50K
6362026-11-09T11:52:48.786Z+ rm -rf /work/falcon-interop-bgp-unnumbered
6372026-11-09T11:52:48.811Z+ pfexec ./falcon-lab cleanup interop bgp-unnumbered
6382026-11-09T11:52:48.811ZNov 09 11:52:48.794 INFO destroying runner for deployment interop_bgpu
6392026-11-09T11:52:48.811ZNov 09 11:52:48.794 INFO destroying deployment interop_bgpu
6402026-11-09T11:52:48.811ZNov 09 11:52:48.794 INFO destroying nodes
6412026-11-09T11:52:48.840ZNov 09 11:52:48.828 INFO destroying links
6422026-11-09T11:52:48.840ZNov 09 11:52:48.828 INFO destroying link interop_bgpu_ox_sn_vnic0
6432026-11-09T11:52:48.866ZNov 09 11:52:48.832 INFO destroying link interop_bgpu_ox_sn_sim0
6442026-11-09T11:52:48.866ZNov 09 11:52:48.833 INFO destroying link interop_bgpu_cr1_vn_vnic0
6452026-11-09T11:52:49.847ZNov 09 11:52:49.836 INFO destroying link interop_bgpu_cr1_vn_sim0
6462026-11-09T11:52:50.344ZNov 09 11:52:49.837 INFO destroying link interop_bgpu_ox_sn_vnic1
6472026-11-09T11:52:50.344ZNov 09 11:52:49.838 INFO destroying link interop_bgpu_ox_sn_sim1
6482026-11-09T11:52:50.344ZNov 09 11:52:49.839 INFO destroying link interop_bgpu_cr2_vn_vnic0
6492026-11-09T11:52:50.344ZNov 09 11:52:49.840 INFO destroying link interop_bgpu_cr2_vn_sim0
6502026-11-09T11:52:50.344ZNov 09 11:52:49.841 INFO destroying link interop_bgpu_ox_sn_vnic2
6512026-11-09T11:52:50.344ZNov 09 11:52:49.842 INFO destroying link interop_bgpu_ox_sn_sim2
6522026-11-09T11:52:50.344ZNov 09 11:52:49.843 INFO destroying link interop_bgpu_cr3_vn_vnic0
6532026-11-09T11:52:50.345ZNov 09 11:52:49.844 INFO destroying link interop_bgpu_cr3_vn_sim0
6542026-11-09T11:52:50.345ZNov 09 11:52:49.845 INFO destroying link interop_bgpu_ox_sn_vnic3
6552026-11-09T11:52:50.345ZNov 09 11:52:49.847 INFO destroying link interop_bgpu_ox_sn_sim3
6562026-11-09T11:52:50.345ZNov 09 11:52:49.848 INFO destroying link interop_bgpu_peer_vn_vnic0
6572026-11-09T11:52:50.345ZNov 09 11:52:49.849 INFO destroying link interop_bgpu_peer_vn_sim0
6582026-11-09T11:52:50.345ZNov 09 11:52:49.850 INFO destroying link interop_bgpu_ox_sn_vnic4
6592026-11-09T11:52:50.345ZNov 09 11:52:49.851 INFO destroying link interop_bgpu_ox_sn_sim4
6602026-11-09T11:52:50.345ZNov 09 11:52:49.852 INFO destroying link interop_bgpu_bird_vn_vnic0
6612026-11-09T11:52:50.345ZNov 09 11:52:49.853 INFO destroying link interop_bgpu_bird_vn_sim0
6622026-11-09T11:52:50.345ZNov 09 11:52:49.854 INFO destroying external links
6632026-11-09T11:52:50.345ZNov 09 11:52:49.854 INFO destroying external link interop_bgpu_ox_vn_vnic5
6642026-11-09T11:52:50.345ZNov 09 11:52:49.855 INFO destroying external link interop_bgpu_cr1_vn_vnic1
6652026-11-09T11:52:50.345ZNov 09 11:52:49.856 INFO destroying external link interop_bgpu_cr2_vn_vnic1
6662026-11-09T11:52:50.345ZNov 09 11:52:49.857 INFO destroying external link interop_bgpu_cr3_vn_vnic1
6672026-11-09T11:52:50.345ZNov 09 11:52:49.858 INFO destroying external link interop_bgpu_peer_vn_vnic1
6682026-11-09T11:52:50.345ZNov 09 11:52:49.859 INFO destroying external link interop_bgpu_bird_vn_vnic1
6692026-11-09T11:52:50.345ZNov 09 11:52:49.861 INFO destroying images
6702026-11-09T11:52:50.345ZNov 09 11:52:50.152 INFO destroying workspace at .falcon
6712026-11-09T11:52:50.345Z+ return 1
6722026-11-09T11:52:50.345Zprocess exited: duration 661745 ms, exit code 1
 
6732026-11-09T11:52:50.430Zfound 2 output files
6742026-11-09T11:52:50.430Zuploading: /work/dhcp-server.log (6555 bytes)
6752026-11-09T11:52:51.551Zuploaded: /work/dhcp-server.log
6762026-11-09T11:52:51.551Zuploading: /work/falcon-interop-bgp-unnumbered.tar.gz (28767 bytes)
6772026-11-09T11:52:52.693Zuploaded: /work/falcon-interop-bgp-unnumbered.tar.gz