2026-05-01 00:25:20.426078 : Get input param file /home/super/workspace/PhoenixWingDailySRv6Test/jenkins_835/input_param_json.txt
2026-05-01 00:25:20.426471 : Get file lock for {'user_info': 'PhoenixWingDailySRv6Test_835', 'testbed_location': 'NO_PREFERENCE'}
2026-05-01 00:25:21.427610 : Before: testbed_location NO_PREFERENCE, uinfo PhoenixWingDailySRv6Test_835, action read, index -1, current index 0
2026-05-01 00:25:21.427619 : After: testbed_location NO_PREFERENCE, uinfo PhoenixWingDailySRv6Test_835, action read, index -1, current index 0
2026-05-01 00:25:21.427623 : Found index 0 for action read, user_info PhoenixWingDailySRv6Test_835
2026-05-01 00:25:21.427642 : Release file lock for {'user_info': 'PhoenixWingDailySRv6Test_835', 'testbed_location': 'NO_PREFERENCE', 'action': 'read', 'output_vm': {'index': 2, 'user_info': 'PhoenixWingDailySRv6Test_835', 'time': 'Fri May  1 00:07:56 2026'}, 'output_index': 0, 'output_prefix': '192.168.0'}
2026-05-01 00:25:21.427689 : read_vm_reservation : {"user_info": "PhoenixWingDailySRv6Test_835", "testbed_location": "NO_PREFERENCE", "action": "read", "output_vm": {"index": 2, "user_info": "PhoenixWingDailySRv6Test_835", "time": "Fri May  1 00:07:56 2026"}, "output_index": 0, "output_prefix": "192.168.0"}
2026-05-01 00:25:21.427865 : ifconfig | grep 30.57.186.111
2026-05-01 00:25:21.430890 : DEBUG_ARR:         inet 30.57.186.111  netmask 255.255.255.0  broadcast 30.57.186.255
2026-05-01 00:25:21.430942 : Found local server setting forr 30.57.186.111
2026-05-01 00:25:21.430955 : Set local ip as 192.168.0.2
{   'address': '30.57.186.111',
    'host_port': 'br0',
    'jenkin_node_name': 'Pytest_node3',
    'password': 'ais12#$',
    'user': 'super',
    'vm_bridge': 'vmbr0',
    'vm_gw': '192.168.0.1',
    'vmip': '192.168.0.2'}
2026-05-01 00:25:21.431162 : mkdir -p /tmp/local_cache//1777620320.4260683/
Run pytest on 30.57.186.111 vmip 192.168.0.2, vm name pytest_vm_192.168.0.2
2026-05-01 00:25:21.433628 : Start bringing up test VMs
2026-05-01 00:25:21.433667 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "cd ~/sonic-mgmt/ansible; sudo ./setup-management-network.sh"
2026-05-01 00:25:37.957077 : DEBUG_ARR: Refreshing apt package lists...
2026-05-01 00:25:37.957128 : DEBUG_ARR: Hit:1 http://archive.ubuntu.com/ubuntu focal InRelease
2026-05-01 00:25:37.957137 : DEBUG_ARR: Get:2 http://archive.ubuntu.com/ubuntu focal-updates InRelease [128 kB]
2026-05-01 00:25:37.957151 : DEBUG_ARR: Get:3 http://security.ubuntu.com/ubuntu focal-security InRelease [128 kB]
2026-05-01 00:25:37.957158 : DEBUG_ARR: Get:4 http://archive.ubuntu.com/ubuntu focal-backports InRelease [128 kB]
2026-05-01 00:25:37.957164 : DEBUG_ARR: Get:5 http://archive.ubuntu.com/ubuntu focal-updates/main amd64 Packages [4004 kB]
2026-05-01 00:25:37.957170 : DEBUG_ARR: Get:6 http://archive.ubuntu.com/ubuntu focal-updates/main Translation-en [601 kB]
2026-05-01 00:25:37.957173 : DEBUG_ARR: Get:7 http://archive.ubuntu.com/ubuntu focal-updates/main amd64 c-n-f Metadata [18.0 kB]
2026-05-01 00:25:37.957176 : DEBUG_ARR: Get:8 http://archive.ubuntu.com/ubuntu focal-updates/restricted amd64 Packages [3983 kB]
2026-05-01 00:25:37.957179 : DEBUG_ARR: Get:9 http://security.ubuntu.com/ubuntu focal-security/main amd64 Packages [3610 kB]
2026-05-01 00:25:37.957182 : DEBUG_ARR: Get:10 http://archive.ubuntu.com/ubuntu focal-updates/restricted Translation-en [548 kB]
2026-05-01 00:25:37.957185 : DEBUG_ARR: Get:11 http://archive.ubuntu.com/ubuntu focal-updates/restricted amd64 c-n-f Metadata [604 B]
2026-05-01 00:25:37.957188 : DEBUG_ARR: Get:12 http://archive.ubuntu.com/ubuntu focal-updates/universe amd64 Packages [1275 kB]
2026-05-01 00:25:37.957191 : DEBUG_ARR: Get:13 http://archive.ubuntu.com/ubuntu focal-updates/universe Translation-en [302 kB]
2026-05-01 00:25:37.957194 : DEBUG_ARR: Get:14 http://archive.ubuntu.com/ubuntu focal-updates/universe amd64 c-n-f Metadata [29.3 kB]
2026-05-01 00:25:37.957197 : DEBUG_ARR: Get:15 http://archive.ubuntu.com/ubuntu focal-updates/multiverse amd64 Packages [29.8 kB]
2026-05-01 00:25:37.957200 : DEBUG_ARR: Get:16 http://archive.ubuntu.com/ubuntu focal-updates/multiverse Translation-en [8284 B]
2026-05-01 00:25:37.957203 : DEBUG_ARR: Get:17 http://archive.ubuntu.com/ubuntu focal-updates/multiverse amd64 c-n-f Metadata [688 B]
2026-05-01 00:25:37.957206 : DEBUG_ARR: Get:18 http://archive.ubuntu.com/ubuntu focal-backports/main amd64 Packages [46.1 kB]
2026-05-01 00:25:37.957209 : DEBUG_ARR: Get:19 http://archive.ubuntu.com/ubuntu focal-backports/main Translation-en [16.2 kB]
2026-05-01 00:25:37.957212 : DEBUG_ARR: Get:20 http://archive.ubuntu.com/ubuntu focal-backports/universe amd64 Packages [25.0 kB]
2026-05-01 00:25:37.957214 : DEBUG_ARR: Get:21 http://archive.ubuntu.com/ubuntu focal-backports/universe Translation-en [16.3 kB]
2026-05-01 00:25:37.957217 : DEBUG_ARR: Get:22 http://security.ubuntu.com/ubuntu focal-security/main Translation-en [518 kB]
2026-05-01 00:25:37.957220 : DEBUG_ARR: Get:23 http://security.ubuntu.com/ubuntu focal-security/main amd64 c-n-f Metadata [14.4 kB]
2026-05-01 00:25:37.957223 : DEBUG_ARR: Get:24 http://security.ubuntu.com/ubuntu focal-security/restricted amd64 Packages [3828 kB]
2026-05-01 00:25:37.957226 : DEBUG_ARR: Get:25 http://security.ubuntu.com/ubuntu focal-security/restricted Translation-en [527 kB]
2026-05-01 00:25:37.957229 : DEBUG_ARR: Get:26 http://security.ubuntu.com/ubuntu focal-security/restricted amd64 c-n-f Metadata [584 B]
2026-05-01 00:25:37.957232 : DEBUG_ARR: Get:27 http://security.ubuntu.com/ubuntu focal-security/universe amd64 Packages [1052 kB]
2026-05-01 00:25:37.957234 : DEBUG_ARR: Get:28 http://security.ubuntu.com/ubuntu focal-security/universe Translation-en [220 kB]
2026-05-01 00:25:37.957237 : DEBUG_ARR: Get:29 http://security.ubuntu.com/ubuntu focal-security/universe amd64 c-n-f Metadata [22.4 kB]
2026-05-01 00:25:37.957240 : DEBUG_ARR: Get:30 http://security.ubuntu.com/ubuntu focal-security/multiverse amd64 Packages [26.7 kB]
2026-05-01 00:25:37.957243 : DEBUG_ARR: Get:31 http://security.ubuntu.com/ubuntu focal-security/multiverse Translation-en [6416 B]
2026-05-01 00:25:37.957246 : DEBUG_ARR: Get:32 http://security.ubuntu.com/ubuntu focal-security/multiverse amd64 c-n-f Metadata [604 B]
2026-05-01 00:25:37.957252 : DEBUG_ARR: Fetched 21.1 MB in 5s (4372 kB/s)
2026-05-01 00:25:37.957255 : DEBUG_ARR: Reading package lists...
2026-05-01 00:25:37.957259 : DEBUG_ARR: 
2026-05-01 00:25:37.957262 : DEBUG_ARR: STEP 1: Checking for j2cli package...
2026-05-01 00:25:37.957265 : DEBUG_ARR: /usr/local/bin/j2
2026-05-01 00:25:37.957268 : DEBUG_ARR: 
2026-05-01 00:25:37.957270 : DEBUG_ARR: STEP 2: Checking for bridge-utils package...
2026-05-01 00:25:37.957273 : DEBUG_ARR: /usr/sbin/brctl
2026-05-01 00:25:37.957276 : DEBUG_ARR: 
2026-05-01 00:25:37.957279 : DEBUG_ARR: STEP 3: Checking for net-tools package...
2026-05-01 00:25:37.957282 : DEBUG_ARR: /usr/sbin/ifconfig
2026-05-01 00:25:37.957285 : DEBUG_ARR: 
2026-05-01 00:25:37.957288 : DEBUG_ARR: STEP 4: Checking for ethtool package...
2026-05-01 00:25:37.957291 : DEBUG_ARR: /usr/sbin/ethtool
2026-05-01 00:25:37.957293 : DEBUG_ARR: 
2026-05-01 00:25:37.957299 : DEBUG_ARR: STEP 5: Delete existed br1...
2026-05-01 00:25:37.957302 : DEBUG_ARR: Not delete existed bridge or br1 not exists, skipping...
2026-05-01 00:25:37.957305 : DEBUG_ARR: 
2026-05-01 00:25:37.957308 : DEBUG_ARR: STEP 6: Checking if bridge br1 already exists...
2026-05-01 00:25:37.957311 : DEBUG_ARR: br1: error fetching interface information: Device not found
2026-05-01 00:25:37.957313 : DEBUG_ARR: br1 not found, creating bridge network
2026-05-01 00:25:37.957316 : DEBUG_ARR: bridge name	bridge id		STP enabled	interfaces
2026-05-01 00:25:37.957319 : DEBUG_ARR: br1		8000.000000000000	no		
2026-05-01 00:25:37.957322 : DEBUG_ARR: 
2026-05-01 00:25:37.957325 : DEBUG_ARR: STEP 7: Configuring br1 interface...
2026-05-01 00:25:37.957328 : DEBUG_ARR: Assigning 10.250.0.1/24 to br1
2026-05-01 00:25:37.957331 : DEBUG_ARR: Bringing up br1
2026-05-01 00:25:37.957333 : DEBUG_ARR: 
2026-05-01 00:25:37.957336 : DEBUG_ARR: COMPLETE. Bridge info:
2026-05-01 00:25:37.957411 : DEBUG_ARR: 
2026-05-01 00:25:37.957416 : DEBUG_ARR: bridge name	bridge id		STP enabled	interfaces
2026-05-01 00:25:37.957419 : DEBUG_ARR: br1		8000.000000000000	no		
2026-05-01 00:25:37.957422 : DEBUG_ARR: 
2026-05-01 00:25:37.957425 : DEBUG_ARR: br1: flags=4163<UP,BROADCAST,RUNNING,MULTICAST>  mtu 1500
2026-05-01 00:25:37.957428 : DEBUG_ARR:         inet 10.250.0.1  netmask 255.255.255.0  broadcast 10.250.0.255
2026-05-01 00:25:37.957431 : DEBUG_ARR:         inet6 fe80::8805:6eff:febf:2cb3  prefixlen 64  scopeid 0x20<link>
2026-05-01 00:25:37.957434 : DEBUG_ARR:         inet6 fec0::1  prefixlen 64  scopeid 0x40<site>
2026-05-01 00:25:37.957436 : DEBUG_ARR:         ether 8a:05:6e:bf:2c:b3  txqueuelen 1000  (Ethernet)
2026-05-01 00:25:37.957440 : DEBUG_ARR:         RX packets 0  bytes 0 (0.0 B)
2026-05-01 00:25:37.957443 : DEBUG_ARR:         RX errors 0  dropped 0  overruns 0  frame 0
2026-05-01 00:25:37.957445 : DEBUG_ARR:         TX packets 0  bytes 0 (0.0 B)
2026-05-01 00:25:37.957448 : DEBUG_ARR:         TX errors 0  dropped 0 overruns 0  carrier 0  collisions 0
2026-05-01 00:25:37.957455 : DEBUG_ARR: 
2026-05-01 00:25:37.957487 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker system prune --force"
2026-05-01 00:25:40.969530 : DEBUG_ARR: Deleted Containers:
2026-05-01 00:25:40.969569 : DEBUG_ARR: 477d0e6e44a4425b0bec9d20c55ff11e9a1120037f08bcafba4f0cb158da4f14
2026-05-01 00:25:40.969574 : DEBUG_ARR: 
2026-05-01 00:25:40.969581 : DEBUG_ARR: Deleted Images:
2026-05-01 00:25:40.969584 : DEBUG_ARR: deleted: sha256:d0e75110437359207d09aee6d06c911ed810fdbe902b35e89ba81cc2afbb99c0
2026-05-01 00:25:40.969587 : DEBUG_ARR: deleted: sha256:392a5abe4ef46dcc470d372a7d5bef90bbcc4020675aebce009497644b56211b
2026-05-01 00:25:40.969590 : DEBUG_ARR: deleted: sha256:68fea0acce8ce064fbc73abb7eb608b8f8d9ce67b4d4b864c4bf5fd93414a200
2026-05-01 00:25:40.969593 : DEBUG_ARR: deleted: sha256:b1840c48e4f86f4927eaafad792d3f7fe2bb48e0c49eca20e82db361a672bdd6
2026-05-01 00:25:40.969596 : DEBUG_ARR: deleted: sha256:597a83131ddad3c576ce8c87ab7641c2866673c5a3f0f6a4709238e4c7eaab02
2026-05-01 00:25:40.969599 : DEBUG_ARR: deleted: sha256:3427583a4cbc30c2af8d048c85bd01b3d292425bf6387dba12038264301faff8
2026-05-01 00:25:40.969602 : DEBUG_ARR: deleted: sha256:027c9a6fc18b21172a9e82984949144f8d13c2776fffde42c75fea0384803afb
2026-05-01 00:25:40.969605 : DEBUG_ARR: deleted: sha256:e17aa51c03089b366c4af99f41e8f64c1f776797be1b8444f8d7efc06f8a8b99
2026-05-01 00:25:40.969608 : DEBUG_ARR: deleted: sha256:05ee2769ae30b3193aa20a1385642030596c5603f17f7d889eacdf30fd57492d
2026-05-01 00:25:40.969610 : DEBUG_ARR: deleted: sha256:110e95e02f774c7b02f2de60eb6fa5c92b246db233ab05431c22ffffa7bc5091
2026-05-01 00:25:40.969613 : DEBUG_ARR: deleted: sha256:f03554f4869b0154163f9103c6b27335b295d7844a6a820d1c9c605866a32fd9
2026-05-01 00:25:40.969619 : DEBUG_ARR: deleted: sha256:95c6c0153730bf89349fe2804e5734593721f48b6ba859ec23e23de1b1eea563
2026-05-01 00:25:40.969621 : DEBUG_ARR: deleted: sha256:318ae74b22402f342c37731c92f614e980994991cfd904e6ca5bf3c2728bf0ee
2026-05-01 00:25:40.969624 : DEBUG_ARR: deleted: sha256:e286be8a15ac347e5338536ffc0157d96248d43b99c2a6fe26847be217faf841
2026-05-01 00:25:40.969627 : DEBUG_ARR: deleted: sha256:a32205164a8c2c265d4654a790f20c0eed53e201cba586def162a6e240fe48ff
2026-05-01 00:25:40.969630 : DEBUG_ARR: 
2026-05-01 00:25:40.969635 : DEBUG_ARR: Total reclaimed space: 535.3MB
2026-05-01 00:25:40.969936 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "cd ~/sonic-mgmt; ./setup-container.sh -n sonic-mgmt-test -d /data -v"
2026-05-01 00:32:06.317432 : DEBUG_ARR: NOTICE: using default docker image: sonicdev-microsoft.azurecr.io:443/docker-sonic-mgmt
2026-05-01 00:32:06.317471 : DEBUG_ARR: INFO: read SSH public key: /home/ubuntu/.ssh/id_rsa_docker_sonic_mgmt.pub
2026-05-01 00:32:06.317476 : DEBUG_ARR: INFO: setup a temporary dir: /tmp/tmp.jjr3pEX5LP
2026-05-01 00:32:06.317479 : DEBUG_ARR: INFO: copy SSH key pair: id_rsa_docker_sonic_mgmt/id_rsa_docker_sonic_mgmt.pub
2026-05-01 00:32:06.317482 : DEBUG_ARR: '/home/ubuntu/.ssh/id_rsa_docker_sonic_mgmt' -> '/tmp/tmp.jjr3pEX5LP/id_rsa'
2026-05-01 00:32:06.317485 : DEBUG_ARR: '/home/ubuntu/.ssh/id_rsa_docker_sonic_mgmt.pub' -> '/tmp/tmp.jjr3pEX5LP/id_rsa.pub'
2026-05-01 00:32:06.317489 : DEBUG_ARR: INFO: prepare a Dockerfile template: /tmp/tmp.jjr3pEX5LP/Dockerfile.j2
2026-05-01 00:32:06.317493 : DEBUG_ARR: INFO: prepare an environment file: /tmp/tmp.jjr3pEX5LP/data.env
2026-05-01 00:32:06.317497 : DEBUG_ARR: INFO: generate a Dockerfile: /tmp/tmp.jjr3pEX5LP/Dockerfile
2026-05-01 00:32:06.317500 : DEBUG_ARR: INFO: building docker image from /tmp/tmp.jjr3pEX5LP: docker-sonic-mgmt-ubuntu:master ...
2026-05-01 00:32:06.317503 : DEBUG_ARR: DEPRECATED: The legacy builder is deprecated and will be removed in a future release.
2026-05-01 00:32:06.317509 : DEBUG_ARR:             Install the buildx component to build images with BuildKit:
2026-05-01 00:32:06.317512 : DEBUG_ARR:             https://docs.docker.com/go/buildx/
2026-05-01 00:32:06.317515 : DEBUG_ARR: 
2026-05-01 00:32:06.317518 : DEBUG_ARR: Sending build context to Docker daemon  15.36kB
2026-05-01 00:32:06.317521 : DEBUG_ARR: 
2026-05-01 00:32:06.317524 : DEBUG_ARR: Step 1/26 : FROM sonicdev-microsoft.azurecr.io:443/docker-sonic-mgmt
2026-05-01 00:32:06.317527 : DEBUG_ARR:  ---> 0c6bcf119fc8
2026-05-01 00:32:06.317531 : DEBUG_ARR: Step 2/26 : USER root
2026-05-01 00:32:06.317534 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317537 : DEBUG_ARR:  ---> 8999f4040729
2026-05-01 00:32:06.317539 : DEBUG_ARR: Step 3/26 : RUN if getent group ubuntu; then groupmod -o -g 1000 ubuntu; else groupadd -o -g 1000 ubuntu; fi
2026-05-01 00:32:06.317544 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317549 : DEBUG_ARR:  ---> a2d4c2f72772
2026-05-01 00:32:06.317552 : DEBUG_ARR: Step 4/26 : RUN if getent passwd ubuntu; then userdel ubuntu; fi
2026-05-01 00:32:06.317555 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317557 : DEBUG_ARR:  ---> 45011e85c0f8
2026-05-01 00:32:06.317561 : DEBUG_ARR: Step 5/26 : RUN useradd -o -l -g 1000 -u 1000 -m -d /home/ubuntu -s /bin/bash ubuntu;
2026-05-01 00:32:06.317564 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317567 : DEBUG_ARR:  ---> 1368fe9ba835
2026-05-01 00:32:06.317569 : DEBUG_ARR: Step 6/26 : RUN if getent group docker; then groupmod -o -g 120 docker; else groupadd -o -g 120 docker; fi
2026-05-01 00:32:06.317572 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317575 : DEBUG_ARR:  ---> 0b7cd958511b
2026-05-01 00:32:06.317580 : DEBUG_ARR: Step 7/26 : RUN if [ 'ubuntu' != 'AzDevOps' ]; then /bin/bash -O extglob -c 'cp -a -f /var/AzDevOps/!(env-*) /home/ubuntu/'; for hidden_stuff in '.profile .local .ssh'; do /bin/bash -c 'cp -a -f /var/AzDevOps/$hidden_stuff /home/ubuntu/ || true'; done fi
2026-05-01 00:32:06.317584 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317588 : DEBUG_ARR:  ---> bdaa22f28047
2026-05-01 00:32:06.317591 : DEBUG_ARR: Step 8/26 : RUN usermod -a -G sudo ubuntu
2026-05-01 00:32:06.317594 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317597 : DEBUG_ARR:  ---> 4cb207ac802b
2026-05-01 00:32:06.317601 : DEBUG_ARR: Step 9/26 : RUN usermod -a -G docker ubuntu
2026-05-01 00:32:06.317603 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317606 : DEBUG_ARR:  ---> 13afb2c43198
2026-05-01 00:32:06.317609 : DEBUG_ARR: Step 10/26 : RUN echo 'ubuntu ALL=(ALL) NOPASSWD:ALL' > /etc/sudoers.d/ubuntu
2026-05-01 00:32:06.317612 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317615 : DEBUG_ARR:  ---> fd1409b34b8d
2026-05-01 00:32:06.317618 : DEBUG_ARR: Step 11/26 : RUN chmod 0440 /etc/sudoers.d/ubuntu
2026-05-01 00:32:06.317621 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317623 : DEBUG_ARR:  ---> dd6caf951fe5
2026-05-01 00:32:06.317626 : DEBUG_ARR: Step 12/26 : RUN chown -R '1000:1000' /home/ubuntu
2026-05-01 00:32:06.317629 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317632 : DEBUG_ARR:  ---> e79af252f823
2026-05-01 00:32:06.317716 : DEBUG_ARR: Step 13/26 : RUN sed -i -E 's/^#?PermitRootLogin.*$/PermitRootLogin yes/g' /etc/ssh/sshd_config
2026-05-01 00:32:06.317727 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317733 : DEBUG_ARR:  ---> bddd8de75ba6
2026-05-01 00:32:06.317738 : DEBUG_ARR: Step 14/26 : RUN echo 'root:root' | chpasswd
2026-05-01 00:32:06.317743 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317749 : DEBUG_ARR:  ---> 3b06de70a506
2026-05-01 00:32:06.317755 : DEBUG_ARR: Step 15/26 : RUN echo 'ubuntu:12345' | chpasswd
2026-05-01 00:32:06.317760 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317766 : DEBUG_ARR:  ---> efba30a8da09
2026-05-01 00:32:06.317771 : DEBUG_ARR: Step 16/26 : USER ubuntu
2026-05-01 00:32:06.317778 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317784 : DEBUG_ARR:  ---> cb0d451ddaf7
2026-05-01 00:32:06.317790 : DEBUG_ARR: Step 17/26 : ENV HOME=/home/ubuntu
2026-05-01 00:32:06.317795 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317800 : DEBUG_ARR:  ---> 593563140b4b
2026-05-01 00:32:06.317806 : DEBUG_ARR: Step 18/26 : ENV USER=ubuntu
2026-05-01 00:32:06.317812 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317817 : DEBUG_ARR:  ---> 702c7785b3ca
2026-05-01 00:32:06.317828 : DEBUG_ARR: Step 19/26 : COPY --chown=1000:1000 id_rsa id_rsa.pub ${HOME}/.ssh/
2026-05-01 00:32:06.317835 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317840 : DEBUG_ARR:  ---> 2acceb0ea3b7
2026-05-01 00:32:06.317845 : DEBUG_ARR: Step 20/26 : RUN chmod 0700 ${HOME}/.ssh
2026-05-01 00:32:06.317850 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317855 : DEBUG_ARR:  ---> aa8e43f1477f
2026-05-01 00:32:06.317861 : DEBUG_ARR: Step 21/26 : RUN chmod 0600 ${HOME}/.ssh/id_rsa
2026-05-01 00:32:06.317866 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317872 : DEBUG_ARR:  ---> 267823550bc7
2026-05-01 00:32:06.317878 : DEBUG_ARR: Step 22/26 : RUN chmod 0644 ${HOME}/.ssh/id_rsa.pub
2026-05-01 00:32:06.317882 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317887 : DEBUG_ARR:  ---> d6adcc78ffff
2026-05-01 00:32:06.317894 : DEBUG_ARR: Step 23/26 : RUN cat ${HOME}/.ssh/id_rsa.pub >> ${HOME}/.ssh/authorized_keys
2026-05-01 00:32:06.317900 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317905 : DEBUG_ARR:  ---> 3d3d2655a7f0
2026-05-01 00:32:06.317911 : DEBUG_ARR: Step 24/26 : RUN chmod 0600 ${HOME}/.ssh/authorized_keys
2026-05-01 00:32:06.317917 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317923 : DEBUG_ARR:  ---> b626369daccd
2026-05-01 00:32:06.317929 : DEBUG_ARR: Step 25/26 : WORKDIR ${HOME}
2026-05-01 00:32:06.317936 : DEBUG_ARR:  ---> Using cache
2026-05-01 00:32:06.317942 : DEBUG_ARR:  ---> bb450819555d
2026-05-01 00:32:06.317950 : DEBUG_ARR: Step 26/26 : RUN if ! pip3 list | grep -c pytest >/dev/null && [ 'ubuntu' != 'AzDevOps' ] && [ -d /var/AzDevOps/env-python3 ]; then /bin/bash -c 'python3 -m venv ${HOME}/env-python3'; /bin/bash -c "${HOME}/env-python3/bin/pip install  -i https://mirrors.aliyun.com/pypi/simple/ --upgrade 'pip<24.1'"; /bin/bash -c '${HOME}/env-python3/bin/pip install  -i https://mirrors.aliyun.com/pypi/simple/ wheel'; /bin/bash -c '${HOME}/env-python3/bin/pip  install  -i https://mirrors.aliyun.com/pypi/simple/ --upgrade paramiko'; /bin/bash -c '${HOME}/env-python3/bin/pip install  -i https://mirrors.aliyun.com/pypi/simple/ $(/var/AzDevOps/env-python3/bin/pip freeze | grep -vE "distro|PyGObject|python-apt|unattended-upgrades|dbus-python")'; fi
2026-05-01 00:32:06.317957 : DEBUG_ARR:  ---> Running in 4e193a47eb51
2026-05-01 00:32:06.317963 : DEBUG_ARR: Looking in indexes: https://mirrors.aliyun.com/pypi/simple/
2026-05-01 00:32:06.317969 : DEBUG_ARR: Collecting pip<24.1
2026-05-01 00:32:06.317975 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8a/6a/19e9fe04fca059ccf770861c7d5721ab4c2aebc539889e97c7977528a53b/pip-24.0-py3-none-any.whl (2.1 MB)
2026-05-01 00:32:06.317981 : DEBUG_ARR: Installing collected packages: pip
2026-05-01 00:32:06.317987 : DEBUG_ARR:   Attempting uninstall: pip
2026-05-01 00:32:06.317992 : DEBUG_ARR:     Found existing installation: pip 20.0.2
2026-05-01 00:32:06.317998 : DEBUG_ARR:     Uninstalling pip-20.0.2:
2026-05-01 00:32:06.318003 : DEBUG_ARR:       Successfully uninstalled pip-20.0.2
2026-05-01 00:32:06.318009 : DEBUG_ARR: Successfully installed pip-24.0
2026-05-01 00:32:06.318015 : DEBUG_ARR: Looking in indexes: https://mirrors.aliyun.com/pypi/simple/
2026-05-01 00:32:06.318020 : DEBUG_ARR: Collecting wheel
2026-05-01 00:32:06.318026 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/0b/2c/87f3254fd8ffd29e4c02732eee68a83a1d3c346ae39bc6822dcbcb697f2b/wheel-0.45.1-py3-none-any.whl (72 kB)
2026-05-01 00:32:06.318033 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 72.5/72.5 kB 803.3 kB/s eta 0:00:00
2026-05-01 00:32:06.318050 : DEBUG_ARR: Installing collected packages: wheel
2026-05-01 00:32:06.318057 : DEBUG_ARR: Successfully installed wheel-0.45.1
2026-05-01 00:32:06.318062 : DEBUG_ARR: [91m
2026-05-01 00:32:06.318068 : DEBUG_ARR: [notice] A new release of pip is available: 24.0 -> 25.0.1
2026-05-01 00:32:06.318073 : DEBUG_ARR: [notice] To update, run: python3 -m pip install --upgrade pip
2026-05-01 00:32:06.318078 : DEBUG_ARR: [0mLooking in indexes: https://mirrors.aliyun.com/pypi/simple/
2026-05-01 00:32:06.318084 : DEBUG_ARR: Collecting paramiko
2026-05-01 00:32:06.318090 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/15/f8/c7bd0ef12954a81a1d3cea60a13946bd9a49a0036a5927770c461eade7ae/paramiko-3.5.1-py3-none-any.whl (227 kB)
2026-05-01 00:32:06.318097 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 227.3/227.3 kB 1.1 MB/s eta 0:00:00
2026-05-01 00:32:06.318105 : DEBUG_ARR: Collecting bcrypt>=3.2 (from paramiko)
2026-05-01 00:32:06.318112 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/0f/c3/0ae57a68be2039287ec28bc463b82e4b8dc23f9d12c0be331f4782e19108/bcrypt-5.0.0-cp38-abi3-manylinux_2_28_x86_64.whl (278 kB)
2026-05-01 00:32:06.318118 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 278.4/278.4 kB 3.1 MB/s eta 0:00:00
2026-05-01 00:32:06.318125 : DEBUG_ARR: Collecting cryptography>=3.3 (from paramiko)
2026-05-01 00:32:06.318131 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7e/b8/ac57107ef32749d2b244e36069bb688792a363aaaa3acc9e3cf84c130315/cryptography-47.0.0-cp38-abi3-manylinux_2_28_x86_64.whl (4.7 MB)
2026-05-01 00:32:06.318137 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.7/4.7 MB 5.2 MB/s eta 0:00:00
2026-05-01 00:32:06.318144 : DEBUG_ARR: Collecting pynacl>=1.5 (from paramiko)
2026-05-01 00:32:06.318150 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3e/d0/f301f83ac8dbe53442c5a43f6a39016f94f754d7a9815a875b65e218a307/pynacl-1.6.2-cp38-abi3-manylinux_2_26_x86_64.manylinux_2_28_x86_64.whl (1.4 MB)
2026-05-01 00:32:06.318155 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.4/1.4 MB 6.8 MB/s eta 0:00:00
2026-05-01 00:32:06.318161 : DEBUG_ARR: Collecting cffi>=1.14 (from cryptography>=3.3->paramiko)
2026-05-01 00:32:06.318166 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/bb/19/b51af9f4a4faa4a8ac5a0e5d5c2522dcd9703d07fac69da34a36c4d960d3/cffi-1.17.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (446 kB)
2026-05-01 00:32:06.318172 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 446.5/446.5 kB 7.8 MB/s eta 0:00:00
2026-05-01 00:32:06.318178 : DEBUG_ARR: Collecting typing-extensions>=4.13.2 (from cryptography>=3.3->paramiko)
2026-05-01 00:32:06.318183 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8b/54/b1ae86c0973cc6f0210b53d508ca3641fb6d0c56823f288d108bc7ab3cc8/typing_extensions-4.13.2-py3-none-any.whl (45 kB)
2026-05-01 00:32:06.318227 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 45.8/45.8 kB 1.6 MB/s eta 0:00:00
2026-05-01 00:32:06.318236 : DEBUG_ARR: Collecting pycparser (from cffi>=1.14->cryptography>=3.3->paramiko)
2026-05-01 00:32:06.318242 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/a0/e3/59cd50310fc9b59512193629e1984c1f95e5c8ae6e5d8c69532ccc65a7fe/pycparser-2.23-py3-none-any.whl (118 kB)
2026-05-01 00:32:06.318247 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 118.1/118.1 kB 4.5 MB/s eta 0:00:00
2026-05-01 00:32:06.318253 : DEBUG_ARR: Installing collected packages: typing-extensions, pycparser, bcrypt, cffi, pynacl, cryptography, paramiko
2026-05-01 00:32:06.318259 : DEBUG_ARR: Successfully installed bcrypt-5.0.0 cffi-1.17.1 cryptography-47.0.0 paramiko-3.5.1 pycparser-2.23 pynacl-1.6.2 typing-extensions-4.13.2
2026-05-01 00:32:06.318265 : DEBUG_ARR: [91m
2026-05-01 00:32:06.318270 : DEBUG_ARR: [notice] A new release of pip is available: 24.0 -> 25.0.1
2026-05-01 00:32:06.318275 : DEBUG_ARR: [notice] To update, run: python3 -m pip install --upgrade pip
2026-05-01 00:32:06.318281 : DEBUG_ARR: [0mLooking in indexes: https://mirrors.aliyun.com/pypi/simple/
2026-05-01 00:32:06.318286 : DEBUG_ARR: Collecting abstract-open-traffic-generator==0.0.68
2026-05-01 00:32:06.318291 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/21/1c/1c5e5ee6a05a098cdacdb826f247c2c8eb416ecefd006966e4ffd9d7d912/abstract_open_traffic_generator-0.0.68-py2.py3-none-any.whl (48 kB)
2026-05-01 00:32:06.318297 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.3/48.3 kB 552.9 kB/s eta 0:00:00
2026-05-01 00:32:06.318303 : DEBUG_ARR: Collecting aiohttp==3.8.4
2026-05-01 00:32:06.318308 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d2/e5/cef5eeb11d7e8bac830b3bee1c8311b19bf8e8a1c45fe14b876c70adcd06/aiohttp-3.8.4-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (1.0 MB)
2026-05-01 00:32:06.318314 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.0/1.0 MB 6.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318320 : DEBUG_ARR: Collecting aiosignal==1.3.1
2026-05-01 00:32:06.318326 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/76/ac/a7305707cb852b7e16ff80eaf5692309bde30e2b1100a1fcacdc8f731d97/aiosignal-1.3.1-py3-none-any.whl (7.6 kB)
2026-05-01 00:32:06.318331 : DEBUG_ARR: Collecting allure-pytest==2.8.22
2026-05-01 00:32:06.318336 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/88/39/d4bc2f810dfb0bfcde973f1a82491330663b04fd5c6fb48e9a113449f0e6/allure_pytest-2.8.22-py3-none-any.whl (9.5 kB)
2026-05-01 00:32:06.318341 : DEBUG_ARR: Collecting allure-python-commons==2.8.22
2026-05-01 00:32:06.318347 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c9/18/cdb7305f81664b5bcc65a02329667e2e1728caaa46115d63af7592be3f72/allure_python_commons-2.8.22-py3-none-any.whl (15 kB)
2026-05-01 00:32:06.318352 : DEBUG_ARR: Collecting amqp==2.6.1
2026-05-01 00:32:06.318358 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/bc/90/bb5ce93521772f083cb2d7a413bb82eda5afc62b4192adb7ea4c7b4858b9/amqp-2.6.1-py2.py3-none-any.whl (48 kB)
2026-05-01 00:32:06.318364 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.0/48.0 kB 577.9 kB/s eta 0:00:00
2026-05-01 00:32:06.318370 : DEBUG_ARR: Collecting ansible==2.9.27
2026-05-01 00:32:06.318375 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/5b/99/ce005d0314840e1a6eef34e0faf0ba4f7bccd8172b33cc84fee21afab7ad/ansible-2.9.27.tar.gz (14.8 MB)
2026-05-01 00:32:06.318382 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 14.8/14.8 MB 5.1 MB/s eta 0:00:00
2026-05-01 00:32:06.318389 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.318395 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.318400 : DEBUG_ARR: Collecting astroid==1.6.6
2026-05-01 00:32:06.318406 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8b/29/0f7ec6fbf28a158886b7de49aee3a77a8a47a7e24c60e9fd6ec98ee2ec02/astroid-1.6.6-py2.py3-none-any.whl (305 kB)
2026-05-01 00:32:06.318412 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 305.6/305.6 kB 7.8 MB/s eta 0:00:00
2026-05-01 00:32:06.318419 : DEBUG_ARR: Collecting async-timeout==4.0.2
2026-05-01 00:32:06.318432 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d6/c1/8991e7c5385b897b8c020cdaad718c5b087a6626d1d11a23e1ea87e325a7/async_timeout-4.0.2-py3-none-any.whl (5.8 kB)
2026-05-01 00:32:06.318438 : DEBUG_ARR: Collecting attrs==23.1.0
2026-05-01 00:32:06.318444 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/f0/eb/fcb708c7bf5056045e9e98f62b93bd7467eb718b0202e7698eb11d66416c/attrs-23.1.0-py3-none-any.whl (61 kB)
2026-05-01 00:32:06.318449 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.2/61.2 kB 1.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318455 : DEBUG_ARR: Collecting azure-core==1.26.4
2026-05-01 00:32:06.318460 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8d/12/8d1b124dcce9a695a8a8907461684ad08af4eca575e59fb2c8c70539caf7/azure_core-1.26.4-py3-none-any.whl (173 kB)
2026-05-01 00:32:06.318466 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 173.9/173.9 kB 464.9 kB/s eta 0:00:00
2026-05-01 00:32:06.318472 : DEBUG_ARR: Collecting azure-identity==1.12.0
2026-05-01 00:32:06.318477 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ce/96/942f03d8a80e30e2289496c10d99e3a8b71f10c0b70b5337fd8ec2ae85e5/azure_identity-1.12.0-py3-none-any.whl (135 kB)
2026-05-01 00:32:06.318483 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 135.5/135.5 kB 5.4 MB/s eta 0:00:00
2026-05-01 00:32:06.318488 : DEBUG_ARR: Collecting azure-kusto-data==4.1.4
2026-05-01 00:32:06.318494 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/45/a7/6a0d837feb034e15a35b8bd82d9f5bdca609517b1aef9ba6f6236a22d0e4/azure_kusto_data-4.1.4-py2.py3-none-any.whl (53 kB)
2026-05-01 00:32:06.318499 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 53.2/53.2 kB 1.5 MB/s eta 0:00:00
2026-05-01 00:32:06.318505 : DEBUG_ARR: Collecting azure-kusto-ingest==4.1.4
2026-05-01 00:32:06.318510 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/78/5a/174bea70200b85096682aaf6f760a58dfa445c9b85787a80ec50febad79f/azure_kusto_ingest-4.1.4-py2.py3-none-any.whl (25 kB)
2026-05-01 00:32:06.318516 : DEBUG_ARR: Collecting azure-storage-blob==12.9.0
2026-05-01 00:32:06.318523 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/41/f3/e2b3fa9de629ab76031588daf54b4c28d71bd3c209d8a3d4f470d87e98a7/azure_storage_blob-12.9.0-py2.py3-none-any.whl (356 kB)
2026-05-01 00:32:06.318528 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 356.5/356.5 kB 12.0 MB/s eta 0:00:00
2026-05-01 00:32:06.318534 : DEBUG_ARR: Collecting azure-storage-queue==12.6.0
2026-05-01 00:32:06.318539 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/10/a5/970149b9357d1ae1578fa3650fa9348a47b2e113f651d47398f156c4f908/azure_storage_queue-12.6.0-py3-none-any.whl (170 kB)
2026-05-01 00:32:06.318583 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 170.9/170.9 kB 2.7 MB/s eta 0:00:00
2026-05-01 00:32:06.318592 : DEBUG_ARR: Collecting bcrypt==4.0.1
2026-05-01 00:32:06.318598 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/64/fe/da28a5916128d541da0993328dc5cf4b43dfbf6655f2c7a2abe26ca2dc88/bcrypt-4.0.1-cp36-abi3-manylinux_2_28_x86_64.whl (593 kB)
2026-05-01 00:32:06.318605 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 593.7/593.7 kB 6.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318611 : DEBUG_ARR: Collecting billiard==3.6.4.0
2026-05-01 00:32:06.318617 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/2b/89/0c43de91d4e52eaa7bd748771d417f6ac9e51e66b2f61928c2151bf65878/billiard-3.6.4.0-py3-none-any.whl (89 kB)
2026-05-01 00:32:06.318622 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 89.5/89.5 kB 2.6 MB/s eta 0:00:00
2026-05-01 00:32:06.318629 : DEBUG_ARR: Collecting celery==4.4.7
2026-05-01 00:32:06.318634 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c8/0c/609e3611d20c9f8d883852d1be5516671f630fb08c8c1e56911567dfba7b/celery-4.4.7-py2.py3-none-any.whl (427 kB)
2026-05-01 00:32:06.318640 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 427.6/427.6 kB 1.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318646 : DEBUG_ARR: Collecting certifi==2022.12.7
2026-05-01 00:32:06.318652 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/71/4c/3db2b8021bd6f2f0ceb0e088d6b2d49147671f25832fb17970e9b583d742/certifi-2022.12.7-py3-none-any.whl (155 kB)
2026-05-01 00:32:06.318657 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 155.3/155.3 kB 2.0 MB/s eta 0:00:00
2026-05-01 00:32:06.318663 : DEBUG_ARR: Collecting cffi==1.15.1
2026-05-01 00:32:06.318668 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/b7/8b/06f30caa03b5b3ac006de4f93478dbd0239e2a16566d81a106c322dc4f79/cffi-1.15.1-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (442 kB)
2026-05-01 00:32:06.318674 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 442.7/442.7 kB 7.8 MB/s eta 0:00:00
2026-05-01 00:32:06.318681 : DEBUG_ARR: Collecting charset-normalizer==3.1.0
2026-05-01 00:32:06.318686 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/74/5f/361202de730532028458b729781b8435f320e31a622c27f30e25eec80513/charset_normalizer-3.1.0-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (195 kB)
2026-05-01 00:32:06.318692 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 195.9/195.9 kB 5.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318698 : DEBUG_ARR: Collecting contextlib2==0.6.0.post1
2026-05-01 00:32:06.318704 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/85/60/370352f7ef6aa96c52fb001831622f50f923c1d575427d021b8ab3311236/contextlib2-0.6.0.post1-py2.py3-none-any.whl (9.8 kB)
2026-05-01 00:32:06.318709 : DEBUG_ARR: Collecting cryptography==3.3.2
2026-05-01 00:32:06.318715 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c6/d1/800ec785c9e66cc6d0ac587bd666eb22f7b2ff6c150e053d35881acd2f57/cryptography-3.3.2-cp36-abi3-manylinux2010_x86_64.whl (2.6 MB)
2026-05-01 00:32:06.318720 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 2.6/2.6 MB 1.3 MB/s eta 0:00:00
2026-05-01 00:32:06.318727 : DEBUG_ARR: Collecting decorator==5.1.1
2026-05-01 00:32:06.318733 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d5/50/83c593b07763e1161326b3b8c6686f0f4b0f24d5526546bee538c89837d6/decorator-5.1.1-py3-none-any.whl (9.1 kB)
2026-05-01 00:32:06.318738 : DEBUG_ARR: Collecting defusedxml==0.7.1
2026-05-01 00:32:06.318744 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/07/6c/aa3f2f849e01cb6a001cd8554a88d4c77c5c1a31c95bdf1cf9301e6d9ef4/defusedxml-0.7.1-py2.py3-none-any.whl (25 kB)
2026-05-01 00:32:06.318749 : DEBUG_ARR: Collecting distlib==0.3.6
2026-05-01 00:32:06.318755 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/76/cb/6bbd2b10170ed991cf64e8c8b85e01f2fb38f95d1bc77617569e0b0b26ac/distlib-0.3.6-py2.py3-none-any.whl (468 kB)
2026-05-01 00:32:06.318760 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 468.5/468.5 kB 8.0 MB/s eta 0:00:00
2026-05-01 00:32:06.318766 : DEBUG_ARR: Collecting dpkt==1.9.8
2026-05-01 00:32:06.318772 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/11/79/479e2194c9096b92aecdf33634ae948d2be306c6011673e98ee1917f32c2/dpkt-1.9.8-py3-none-any.whl (194 kB)
2026-05-01 00:32:06.318778 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 195.0/195.0 kB 4.2 MB/s eta 0:00:00
2026-05-01 00:32:06.318784 : DEBUG_ARR: Collecting execnet==1.9.0
2026-05-01 00:32:06.318789 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/81/c0/3072ecc23f4c5e0a1af35e3a222855cfd9c80a1a105ca67be3b6172637dd/execnet-1.9.0-py2.py3-none-any.whl (39 kB)
2026-05-01 00:32:06.318795 : DEBUG_ARR: Collecting filelock==3.12.0
2026-05-01 00:32:06.318801 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ad/73/b094a662ae05cdc4ec95bc54e434e307986a5de5960166b8161b7c1373ee/filelock-3.12.0-py3-none-any.whl (10 kB)
2026-05-01 00:32:06.318806 : DEBUG_ARR: Collecting frozenlist==1.3.3
2026-05-01 00:32:06.318812 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ec/ab/a440db757401a1e8863c9abb374a77cb2884eda74ffbf555dedcf1fbe7f6/frozenlist-1.3.3-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (161 kB)
2026-05-01 00:32:06.318822 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 161.3/161.3 kB 8.8 MB/s eta 0:00:00
2026-05-01 00:32:06.318828 : DEBUG_ARR: Collecting future==0.18.3
2026-05-01 00:32:06.318834 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8f/2e/cf6accf7415237d6faeeebdc7832023c90e0282aa16fd3263db0eb4715ec/future-0.18.3.tar.gz (840 kB)
2026-05-01 00:32:06.318839 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 840.9/840.9 kB 6.0 MB/s eta 0:00:00
2026-05-01 00:32:06.318845 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.318851 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.318856 : DEBUG_ARR: Collecting gitdb==4.0.10
2026-05-01 00:32:06.318862 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/21/a6/35f83efec687615c711fe0a09b67e58f6d1254db27b1013119de46f450bd/gitdb-4.0.10-py3-none-any.whl (62 kB)
2026-05-01 00:32:06.318868 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.7/62.7 kB 1.2 MB/s eta 0:00:00
2026-05-01 00:32:06.318873 : DEBUG_ARR: Collecting GitPython==3.1.31
2026-05-01 00:32:06.318878 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9e/8a/d1e02cc111d65b0346f70abb83c51f8593e7134bf694a4a56d1a470caaf7/GitPython-3.1.31-py3-none-any.whl (184 kB)
2026-05-01 00:32:06.318884 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 184.3/184.3 kB 6.1 MB/s eta 0:00:00
2026-05-01 00:32:06.318914 : DEBUG_ARR: Collecting grpcio==1.44.0
2026-05-01 00:32:06.318921 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/5b/92/a00eed89bae16e48644f514c842b1cc6deaf0f79cb7dcfeda2dc514e11af/grpcio-1.44.0-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (4.3 MB)
2026-05-01 00:32:06.318927 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.3/4.3 MB 4.5 MB/s eta 0:00:00
2026-05-01 00:32:06.318933 : DEBUG_ARR: Collecting grpcio-tools==1.44.0
2026-05-01 00:32:06.318938 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/0c/ab/6bc77bb47dc8b950c4957553fbb3d040be0b3d16ff2fe44bef0a5cbac7a6/grpcio_tools-1.44.0-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (2.4 MB)
2026-05-01 00:32:06.318943 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 2.4/2.4 MB 5.7 MB/s eta 0:00:00
2026-05-01 00:32:06.318949 : DEBUG_ARR: Collecting idna==3.4
2026-05-01 00:32:06.318954 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/fc/34/3030de6f1370931b9dbb4dad48f6ab1015ab1d32447850b9fc94e60097be/idna-3.4-py3-none-any.whl (61 kB)
2026-05-01 00:32:06.318959 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.5/61.5 kB 1.5 MB/s eta 0:00:00
2026-05-01 00:32:06.318965 : DEBUG_ARR: Collecting ijson==3.2.0.post0
2026-05-01 00:32:06.318970 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/41/81/7dcbdc2ae5d29540f5f9fb4a528003675b0079ada3a9f38e9e79f35a5584/ijson-3.2.0.post0-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (114 kB)
2026-05-01 00:32:06.318976 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 114.8/114.8 kB 2.1 MB/s eta 0:00:00
2026-05-01 00:32:06.318982 : DEBUG_ARR: Collecting iniconfig==2.0.0
2026-05-01 00:32:06.318988 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ef/a6/62565a6e1cf69e10f5727360368e451d4b7f58beeac6173dc9db836a5b46/iniconfig-2.0.0-py3-none-any.whl (5.9 kB)
2026-05-01 00:32:06.318994 : DEBUG_ARR: Collecting ipaddr==2.2.0
2026-05-01 00:32:06.319000 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9d/a7/1b39a16cb90dfe491f57e1cab3103a15d4e8dd9a150872744f531b1106c1/ipaddr-2.2.0.tar.gz (26 kB)
2026-05-01 00:32:06.319006 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319012 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319018 : DEBUG_ARR: Collecting ipython==5.4.1
2026-05-01 00:32:06.319023 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3d/f0/3770e603de61f62bc9f1935305daf0a66ec2e699b8617d466cc47803f5ba/ipython-5.4.1-py3-none-any.whl (757 kB)
2026-05-01 00:32:06.319028 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 757.6/757.6 kB 4.4 MB/s eta 0:00:00
2026-05-01 00:32:06.319034 : DEBUG_ARR: Collecting isodate==0.6.1
2026-05-01 00:32:06.319038 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/b6/85/7882d311924cbcfc70b1890780763e36ff0b140c7e51c110fc59a532f087/isodate-0.6.1-py2.py3-none-any.whl (41 kB)
2026-05-01 00:32:06.319063 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 41.7/41.7 kB 508.7 kB/s eta 0:00:00
2026-05-01 00:32:06.319071 : DEBUG_ARR: Collecting isort==5.12.0
2026-05-01 00:32:06.319075 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/0a/63/4036ae70eea279c63e2304b91ee0ac182f467f24f86394ecfe726092340b/isort-5.12.0-py3-none-any.whl (91 kB)
2026-05-01 00:32:06.319080 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 91.2/91.2 kB 5.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319086 : DEBUG_ARR: Collecting ixnetwork-open-traffic-generator==0.0.79
2026-05-01 00:32:06.319092 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8f/aa/dc5a95a3544a60a089eb51a0f23f5fb1e29aaa936f72ba2876c7add3551d/ixnetwork_open_traffic_generator-0.0.79-py2.py3-none-any.whl (46 kB)
2026-05-01 00:32:06.319097 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 46.4/46.4 kB 554.6 kB/s eta 0:00:00
2026-05-01 00:32:06.319103 : DEBUG_ARR: Collecting ixnetwork-restpy==1.0.64
2026-05-01 00:32:06.319108 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/43/26/2c5a1215c79e7776d7db10dff687953127b21c2a28b56bacbbe822abcf60/ixnetwork_restpy-1.0.64-py2.py3-none-any.whl (8.4 MB)
2026-05-01 00:32:06.319113 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 8.4/8.4 MB 5.7 MB/s eta 0:00:00
2026-05-01 00:32:06.319119 : DEBUG_ARR: Collecting Jinja2==2.10.1
2026-05-01 00:32:06.319125 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/1d/e7/fd8b501e7a6dfe492a433deb7b9d833d39ca74916fa8bc63dd1a4947a671/Jinja2-2.10.1-py2.py3-none-any.whl (124 kB)
2026-05-01 00:32:06.319130 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 124.9/124.9 kB 862.3 kB/s eta 0:00:00
2026-05-01 00:32:06.319136 : DEBUG_ARR: Collecting jsonpatch==1.32
2026-05-01 00:32:06.319141 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/a3/55/f7c93bae36d869292aedfbcbae8b091386194874f16390d680136edd2b28/jsonpatch-1.32-py2.py3-none-any.whl (12 kB)
2026-05-01 00:32:06.319146 : DEBUG_ARR: Collecting jsonpath-ng==1.5.3
2026-05-01 00:32:06.319152 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/4c/b7/3627068d9aa6b2d49af117eb3897770a5dbc6bb3f4c09ed56a9eb749438e/jsonpath_ng-1.5.3-py3-none-any.whl (29 kB)
2026-05-01 00:32:06.319158 : DEBUG_ARR: Collecting jsonpointer==2.3
2026-05-01 00:32:06.319164 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/a3/be/8dc9d31b50e38172c8020c40f497ce8debdb721545ddb9fcb7cca89ea9e6/jsonpointer-2.3-py2.py3-none-any.whl (7.8 kB)
2026-05-01 00:32:06.319169 : DEBUG_ARR: Collecting kombu==4.6.11
2026-05-01 00:32:06.319174 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9e/34/3eea6a3a9ff81b0c7ddbdceb22a1ffc1b5907d863f27ca19a68777d2211d/kombu-4.6.11-py2.py3-none-any.whl (184 kB)
2026-05-01 00:32:06.319181 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 184.4/184.4 kB 1.5 MB/s eta 0:00:00
2026-05-01 00:32:06.319187 : DEBUG_ARR: Collecting lazy-object-proxy==1.9.0
2026-05-01 00:32:06.319192 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/4e/cb/aca3f4d89d3efbed724fd9504a96dafbe2d903ea908355a335acb110a5cd/lazy_object_proxy-1.9.0-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (61 kB)
2026-05-01 00:32:06.319198 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.4/61.4 kB 1.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319204 : DEBUG_ARR: Collecting lxml==4.9.2
2026-05-01 00:32:06.319210 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3f/2f/8379eb85d10f06c01cab2b8a93fe676b6d7234e43441b17d348fdc735420/lxml-4.9.2-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.manylinux_2_24_x86_64.whl (7.1 MB)
2026-05-01 00:32:06.319216 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 7.1/7.1 MB 5.4 MB/s eta 0:00:00
2026-05-01 00:32:06.319222 : DEBUG_ARR: Collecting MarkupSafe==2.0.1
2026-05-01 00:32:06.319255 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7a/e8/00c435416c9b0238dca6f883563b01c4cc532b2ba6aaf7268081f6238520/MarkupSafe-2.0.1-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl (30 kB)
2026-05-01 00:32:06.319264 : DEBUG_ARR: Collecting mccabe==0.7.0
2026-05-01 00:32:06.319270 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/27/1a/1f68f9ba0c207934b35b86a8ca3aad8395a3d6dd7921c0686e23853ff5a9/mccabe-0.7.0-py2.py3-none-any.whl (7.3 kB)
2026-05-01 00:32:06.319275 : DEBUG_ARR: Collecting mock==5.0.2
2026-05-01 00:32:06.319281 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/27/6f/fbb16f260a7107ee98871d83f6793d88c4311b7189b10ef239da0b2181db/mock-5.0.2-py3-none-any.whl (30 kB)
2026-05-01 00:32:06.319286 : DEBUG_ARR: Collecting msal==1.22.0
2026-05-01 00:32:06.319291 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/5a/0d/5e21072561e8cbf13f938da854804cde984475e9b3d125922962e46487b8/msal-1.22.0-py2.py3-none-any.whl (90 kB)
2026-05-01 00:32:06.319298 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 90.0/90.0 kB 3.5 MB/s eta 0:00:00
2026-05-01 00:32:06.319306 : DEBUG_ARR: Collecting msal-extensions==1.0.0
2026-05-01 00:32:06.319310 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/52/34/a8995d6f0fa626ff6b28dbd9c90f6c2a46bd484bc7ab343d078b0c6ff1a7/msal_extensions-1.0.0-py2.py3-none-any.whl (19 kB)
2026-05-01 00:32:06.319313 : DEBUG_ARR: Collecting msrest==0.6.21
2026-05-01 00:32:06.319316 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/e8/cc/6c96bfb3d3cf4c3bdedfa6b46503223f4c2a4fa388377697e0f8082a4fed/msrest-0.6.21-py2.py3-none-any.whl (85 kB)
2026-05-01 00:32:06.319319 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 85.2/85.2 kB 2.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319322 : DEBUG_ARR: Collecting multidict==6.0.4
2026-05-01 00:32:06.319325 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/fe/0c/8469202f8f4b0e65816f91c3febc4bda7316c995b59ecdf3b15c574f7a24/multidict-6.0.4-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (121 kB)
2026-05-01 00:32:06.319328 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 121.3/121.3 kB 1.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319332 : DEBUG_ARR: Collecting natsort==8.3.1
2026-05-01 00:32:06.319334 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/5f/e1/70d203ba3ae5476f25fb8a2015d6a7ff156a4ce4795e36955c144ea5a826/natsort-8.3.1-py3-none-any.whl (38 kB)
2026-05-01 00:32:06.319337 : DEBUG_ARR: Collecting ncclient==0.6.13
2026-05-01 00:32:06.319340 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ee/6f/ef2796c82d097dbead1b804db8457fc8fdc244e3d6860eb0a702315dbf67/ncclient-0.6.13.tar.gz (105 kB)
2026-05-01 00:32:06.319343 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 105.7/105.7 kB 2.9 MB/s eta 0:00:00
2026-05-01 00:32:06.319346 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319349 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319352 : DEBUG_ARR: Collecting netaddr==0.8.0
2026-05-01 00:32:06.319355 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ff/cd/9cdfea8fc45c56680b798db6a55fa60a22e2d3d3ccf54fc729d083b50ce4/netaddr-0.8.0-py2.py3-none-any.whl (1.9 MB)
2026-05-01 00:32:06.319358 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.9/1.9 MB 3.7 MB/s eta 0:00:00
2026-05-01 00:32:06.319361 : DEBUG_ARR: Collecting netmiko==2.4.2
2026-05-01 00:32:06.319364 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/26/05/dbe9c97c39f126e7b8dc70cf897dcad557dbd579703f2e3acfd3606d0cee/netmiko-2.4.2-py2.py3-none-any.whl (144 kB)
2026-05-01 00:32:06.319367 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 144.8/144.8 kB 3.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319370 : DEBUG_ARR: Collecting nnpy==1.4.2
2026-05-01 00:32:06.319374 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/23/20/490a767ad65f43e42d67766462336b8fee73fc34456ae1d15551f466332c/nnpy-1.4.2.tar.gz (6.4 kB)
2026-05-01 00:32:06.319377 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319380 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319382 : DEBUG_ARR: Collecting oauthlib==3.2.2
2026-05-01 00:32:06.319385 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7e/80/cab10959dc1faead58dc8384a781dfbf93cb4d33d50988f7a69f1b7c9bbe/oauthlib-3.2.2-py3-none-any.whl (151 kB)
2026-05-01 00:32:06.319388 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 151.7/151.7 kB 3.8 MB/s eta 0:00:00
2026-05-01 00:32:06.319392 : DEBUG_ARR: Collecting packaging==23.1
2026-05-01 00:32:06.319395 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ab/c3/57f0601a2d4fe15de7a553c00adbc901425661bf048f2a22dfc500caf121/packaging-23.1-py3-none-any.whl (48 kB)
2026-05-01 00:32:06.319398 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.9/48.9 kB 350.0 kB/s eta 0:00:00
2026-05-01 00:32:06.319401 : DEBUG_ARR: Collecting paramiko==2.7.1
2026-05-01 00:32:06.319404 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/06/1e/1e08baaaf6c3d3df1459fd85f0e7d2d6aa916f33958f151ee1ecc9800971/paramiko-2.7.1-py2.py3-none-any.whl (206 kB)
2026-05-01 00:32:06.319407 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 206.8/206.8 kB 4.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319410 : DEBUG_ARR: Collecting passlib==1.7.4
2026-05-01 00:32:06.319413 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3b/a4/ab6b7589382ca3df236e03faa71deac88cae040af60c071a78d254a62172/passlib-1.7.4-py2.py3-none-any.whl (525 kB)
2026-05-01 00:32:06.319415 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 525.6/525.6 kB 7.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319419 : DEBUG_ARR: Collecting pexpect==4.8.0
2026-05-01 00:32:06.319422 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/39/7b/88dbb785881c28a102619d46423cb853b46dbccc70d3ac362d99773a78ce/pexpect-4.8.0-py2.py3-none-any.whl (59 kB)
2026-05-01 00:32:06.319424 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 59.0/59.0 kB 672.5 kB/s eta 0:00:00
2026-05-01 00:32:06.319428 : DEBUG_ARR: Collecting pickleshare==0.7.5
2026-05-01 00:32:06.319431 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9a/41/220f49aaea88bc6fa6cba8d05ecf24676326156c23b991e80b3f2fc24c77/pickleshare-0.7.5-py2.py3-none-any.whl (6.9 kB)
2026-05-01 00:32:06.319433 : DEBUG_ARR: Requirement already satisfied: pkg_resources==0.0.0 in ./env-python3/lib/python3.8/site-packages (0.0.0)
2026-05-01 00:32:06.319436 : DEBUG_ARR: Collecting platformdirs==3.5.0
2026-05-01 00:32:06.319439 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ce/cf/279b73aae00f7ba9d5d7664156ef323ebbf16fb556285bb223ecc45031aa/platformdirs-3.5.0-py3-none-any.whl (15 kB)
2026-05-01 00:32:06.319442 : DEBUG_ARR: Collecting pluggy==1.0.0
2026-05-01 00:32:06.319445 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9e/01/f38e2ff29715251cf25532b9082a1589ab7e4f571ced434f98d0139336dc/pluggy-1.0.0-py2.py3-none-any.whl (13 kB)
2026-05-01 00:32:06.319467 : DEBUG_ARR: Collecting plumbum==1.8.1
2026-05-01 00:32:06.319470 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/38/b2/1886b35657304d26ad948845a6aee173a5655bdc4804fb15f033ac70f083/plumbum-1.8.1-py3-none-any.whl (126 kB)
2026-05-01 00:32:06.319474 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 126.7/126.7 kB 999.0 kB/s eta 0:00:00
2026-05-01 00:32:06.319477 : DEBUG_ARR: Collecting ply==3.11
2026-05-01 00:32:06.319480 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/a3/58/35da89ee790598a0700ea49b2a66594140f44dec458c07e8e3d4979137fc/ply-3.11-py2.py3-none-any.whl (49 kB)
2026-05-01 00:32:06.319483 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 49.6/49.6 kB 278.4 kB/s eta 0:00:00
2026-05-01 00:32:06.319486 : DEBUG_ARR: Collecting portalocker==2.7.0
2026-05-01 00:32:06.319489 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8c/df/d4f711d168524f5aebd7fb30969eaa31e3048cf8979688cde3b08f6e5eb8/portalocker-2.7.0-py2.py3-none-any.whl (15 kB)
2026-05-01 00:32:06.319492 : DEBUG_ARR: Collecting prettytable==3.7.0
2026-05-01 00:32:06.319495 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7a/cd/bec5850e23eb005c6fe30fe4c26bafd9a07b3d2524771f22a0fa01270078/prettytable-3.7.0-py3-none-any.whl (27 kB)
2026-05-01 00:32:06.319498 : DEBUG_ARR: Collecting prompt-toolkit==1.0.18
2026-05-01 00:32:06.319501 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/64/27/5fd61a451d086ad4aa806dc72fe1383d2bc0e74323668672287f616d5d51/prompt_toolkit-1.0.18-py3-none-any.whl (245 kB)
2026-05-01 00:32:06.319504 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 245.4/245.4 kB 6.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319507 : DEBUG_ARR: Collecting protobuf==3.20.1
2026-05-01 00:32:06.319510 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c1/4d/1d46234fbdff4ee05cb7ec6cb6ea9282769fa9fefd72d93de4b85fd3d8c4/protobuf-3.20.1-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.whl (1.0 MB)
2026-05-01 00:32:06.319513 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.0/1.0 MB 4.8 MB/s eta 0:00:00
2026-05-01 00:32:06.319516 : DEBUG_ARR: Collecting psutil==5.9.5
2026-05-01 00:32:06.319519 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/af/4d/389441079ecef400e2551a3933224885a7bde6b8a4810091d628cdd75afe/psutil-5.9.5-cp36-abi3-manylinux_2_12_x86_64.manylinux2010_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (282 kB)
2026-05-01 00:32:06.319522 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 282.1/282.1 kB 4.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319525 : DEBUG_ARR: Collecting ptf==0.9.3
2026-05-01 00:32:06.319528 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/e1/c5/3ebf8ae63763e9ba1841ffb9e143b2c1316e9e259df23b93a169e774891e/ptf-0.9.3-0-py3-none-any.whl (60 kB)
2026-05-01 00:32:06.319531 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 60.7/60.7 kB 1.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319534 : DEBUG_ARR: Collecting ptyprocess==0.7.0
2026-05-01 00:32:06.319537 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/22/a6/858897256d0deac81a172289110f31629fc4cee19b6f01283303e18c8db3/ptyprocess-0.7.0-py2.py3-none-any.whl (13 kB)
2026-05-01 00:32:06.319540 : DEBUG_ARR: Collecting py==1.11.0
2026-05-01 00:32:06.319543 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/f6/f0/10642828a8dfb741e5f3fbaac830550a518a775c7fff6f04a007259b0548/py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-05-01 00:32:06.319546 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 1.4 MB/s eta 0:00:00
2026-05-01 00:32:06.319549 : DEBUG_ARR: Collecting pyaml==21.10.1
2026-05-01 00:32:06.319552 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/35/fd/78a3a11c7b9b11878ebbf4461a09cbc758bdfc1b45168972727f7334b09a/pyaml-21.10.1-py2.py3-none-any.whl (24 kB)
2026-05-01 00:32:06.319555 : DEBUG_ARR: Collecting pyasn1==0.4.8
2026-05-01 00:32:06.319558 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/62/1e/a94a8d635fa3ce4cfc7f506003548d0a2447ae76fd5ca53932970fe3053f/pyasn1-0.4.8-py2.py3-none-any.whl (77 kB)
2026-05-01 00:32:06.319561 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 77.1/77.1 kB 2.0 MB/s eta 0:00:00
2026-05-01 00:32:06.319564 : DEBUG_ARR: Collecting pycparser==2.21
2026-05-01 00:32:06.319567 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/62/d5/5f610ebe421e85889f2e55e33b7f9a6795bd982198517d912eb1c76e1a53/pycparser-2.21-py2.py3-none-any.whl (118 kB)
2026-05-01 00:32:06.319570 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 118.7/118.7 kB 1.2 MB/s eta 0:00:00
2026-05-01 00:32:06.319573 : DEBUG_ARR: Collecting pycryptodome==3.9.8
2026-05-01 00:32:06.319576 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/26/29/73158aec5b839234920c934ca6b81af260eaedd1f93ce341e05fa32c89b4/pycryptodome-3.9.8-cp38-cp38-manylinux1_x86_64.whl (13.7 MB)
2026-05-01 00:32:06.319579 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 13.7/13.7 MB 5.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319582 : DEBUG_ARR: Collecting pycryptodomex==3.17
2026-05-01 00:32:06.319585 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/08/7c/4b55006bc7615db176a52feb7ec49201048045dd08ec38bbeae2d59e2456/pycryptodomex-3.17-cp35-abi3-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (2.1 MB)
2026-05-01 00:32:06.319588 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 2.1/2.1 MB 5.7 MB/s eta 0:00:00
2026-05-01 00:32:06.319591 : DEBUG_ARR: Collecting pyfiglet==0.8.post1
2026-05-01 00:32:06.319594 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/33/07/fcfdd7a2872f5b348953de35acce1544dab0c1e8368dca54279b1cde5c15/pyfiglet-0.8.post1-py2.py3-none-any.whl (865 kB)
2026-05-01 00:32:06.319597 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 865.8/865.8 kB 5.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319600 : DEBUG_ARR: Collecting Pygments==2.15.1
2026-05-01 00:32:06.319603 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/34/a7/37c8d68532ba71549db4212cb036dbd6161b40e463aba336770e80c72f84/Pygments-2.15.1-py3-none-any.whl (1.1 MB)
2026-05-01 00:32:06.319606 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.1/1.1 MB 6.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319609 : DEBUG_ARR: Collecting PyJWT==2.5.0
2026-05-01 00:32:06.319612 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/37/82/43382713811f0ddd9fff1ed778af6818cc2080ccd425e3eba540be690fb6/PyJWT-2.5.0-py3-none-any.whl (20 kB)
2026-05-01 00:32:06.319615 : DEBUG_ARR: Collecting pylint==1.8.1
2026-05-01 00:32:06.319618 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/2b/d0/f8503a66d0f133b05689297a210f9f6925fc1f56070fe954ef4e72f02b0b/pylint-1.8.1-py2.py3-none-any.whl (683 kB)
2026-05-01 00:32:06.319621 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 683.5/683.5 kB 4.5 MB/s eta 0:00:00
2026-05-01 00:32:06.319641 : DEBUG_ARR: Collecting PyNaCl==1.5.0
2026-05-01 00:32:06.319645 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ee/87/f1bb6a595f14a327e8285b9eb54d41fef76c585a0edef0a45f6fc95de125/PyNaCl-1.5.0-cp36-abi3-manylinux_2_17_x86_64.manylinux2014_x86_64.manylinux_2_24_x86_64.whl (856 kB)
2026-05-01 00:32:06.319648 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 856.7/856.7 kB 6.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319651 : DEBUG_ARR: Collecting Pyro4==4.82
2026-05-01 00:32:06.319654 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/70/e3/8c4e0d24b46fbf02e6b2dc2da5d18f0c73cfd343a1fb01ae64c788c20e56/Pyro4-4.82-py2.py3-none-any.whl (89 kB)
2026-05-01 00:32:06.319657 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 90.0/90.0 kB 1.2 MB/s eta 0:00:00
2026-05-01 00:32:06.319660 : DEBUG_ARR: Collecting pyserial==3.5
2026-05-01 00:32:06.319663 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/07/bc/587a445451b253b285629263eb51c2d8e9bcea4fc97826266d186f96f558/pyserial-3.5-py2.py3-none-any.whl (90 kB)
2026-05-01 00:32:06.319666 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 90.6/90.6 kB 1.9 MB/s eta 0:00:00
2026-05-01 00:32:06.319669 : DEBUG_ARR: Collecting pysmi==0.3.4
2026-05-01 00:32:06.319672 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/1f/fc/02361d1c2b247de73070c457c4da98c448693154894c14f2d7b48dfabf7e/pysmi-0.3.4-py2.py3-none-any.whl (80 kB)
2026-05-01 00:32:06.319675 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 80.0/80.0 kB 2.9 MB/s eta 0:00:00
2026-05-01 00:32:06.319678 : DEBUG_ARR: Collecting pysnmp==4.4.12
2026-05-01 00:32:06.319681 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/25/7e/1e17facea54dd21c6a72db6ae57a5bfdd56edd54b8c4850668b554bdddba/pysnmp-4.4.12-py2.py3-none-any.whl (296 kB)
2026-05-01 00:32:06.319684 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 296.5/296.5 kB 5.8 MB/s eta 0:00:00
2026-05-01 00:32:06.319687 : DEBUG_ARR: Collecting pysubnettree==0.35
2026-05-01 00:32:06.319690 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3d/32/ffa0e8150c2a455bb202e1a1ca384ff3e6ea746968d92f5a53bfd6e4b368/pysubnettree-0.35.tar.gz (51 kB)
2026-05-01 00:32:06.319693 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 51.2/51.2 kB 767.0 kB/s eta 0:00:00
2026-05-01 00:32:06.319697 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319699 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319702 : DEBUG_ARR: Collecting pytest==7.1.3
2026-05-01 00:32:06.319705 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/e3/b9/3541bbcb412a9fd56593005ff32183825634ef795a1c01ceb6dee86e7259/pytest-7.1.3-py3-none-any.whl (298 kB)
2026-05-01 00:32:06.319708 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 298.2/298.2 kB 5.9 MB/s eta 0:00:00
2026-05-01 00:32:06.319711 : DEBUG_ARR: Collecting pytest-ansible==2.2.4
2026-05-01 00:32:06.319714 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/92/16/b5527f0470ba9a30e29084bbfb387c12f06f7cd949f98590e2bbbd7ef815/pytest-ansible-2.2.4.tar.gz (17 kB)
2026-05-01 00:32:06.319717 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319720 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319723 : DEBUG_ARR: Collecting pytest-forked==1.6.0
2026-05-01 00:32:06.319726 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/f4/af/9c0bda43e486a3c9bf1e0f876d0f241bc3f229d7d65d09331a0868db9629/pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-05-01 00:32:06.319729 : DEBUG_ARR: Collecting pytest-html==3.2.0
2026-05-01 00:32:06.319732 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/81/e1/35ae038e10ba11758e7d572f656ea7b99795f3d37d20aa40a5d7e8050091/pytest_html-3.2.0-py3-none-any.whl (16 kB)
2026-05-01 00:32:06.319735 : DEBUG_ARR: Collecting pytest-metadata==2.0.4
2026-05-01 00:32:06.319737 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/e1/00/c8175f054e801b5d8135ef2d0d7e4ad508c0af94d81e521431c23cf56e8f/pytest_metadata-2.0.4-py3-none-any.whl (9.9 kB)
2026-05-01 00:32:06.319740 : DEBUG_ARR: Collecting pytest-repeat==0.9.1
2026-05-01 00:32:06.319743 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ef/c8/5e5178f5704247d3f076a44409b9720eb7a25b64f26cb3ec727c9ede2d3a/pytest_repeat-0.9.1-py2.py3-none-any.whl (4.3 kB)
2026-05-01 00:32:06.319746 : DEBUG_ARR: Collecting pytest-xdist==1.28.0
2026-05-01 00:32:06.319749 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/9f/ea/227e5ec64bd5deb31011fb2a2557d62d5c06c4793a8bfc4f47d398714e1c/pytest_xdist-1.28.0-py2.py3-none-any.whl (34 kB)
2026-05-01 00:32:06.319752 : DEBUG_ARR: Collecting python-dateutil==2.8.2
2026-05-01 00:32:06.319755 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/36/7a/87837f39d0296e723bb9b62bbb257d0355c7f6128853c78955f57342a56d/python_dateutil-2.8.2-py2.py3-none-any.whl (247 kB)
2026-05-01 00:32:06.319758 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 247.7/247.7 kB 4.1 MB/s eta 0:00:00
2026-05-01 00:32:06.319761 : DEBUG_ARR: Collecting pytz==2023.3
2026-05-01 00:32:06.319764 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7f/99/ad6bd37e748257dd70d6f85d916cafe79c0b0f5e2e95b11f7fbc82bf3110/pytz-2023.3-py2.py3-none-any.whl (502 kB)
2026-05-01 00:32:06.319766 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 502.3/502.3 kB 11.2 MB/s eta 0:00:00
2026-05-01 00:32:06.319770 : DEBUG_ARR: Collecting PyYAML==6.0
2026-05-01 00:32:06.319773 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d7/42/7ad4b6d67a16229496d4f6e74201bdbebcf4bc1e87d5a70c9297d4961bd2/PyYAML-6.0-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl (701 kB)
2026-05-01 00:32:06.319776 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 701.2/701.2 kB 5.9 MB/s eta 0:00:00
2026-05-01 00:32:06.319779 : DEBUG_ARR: Collecting redis==4.5.4
2026-05-01 00:32:06.319782 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/b5/d4/ef474a49ec5821f3155c5de2d37ddcc4a497e2500cd16d4a9e51ce02030d/redis-4.5.4-py3-none-any.whl (238 kB)
2026-05-01 00:32:06.319785 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 238.9/238.9 kB 5.0 MB/s eta 0:00:00
2026-05-01 00:32:06.319788 : DEBUG_ARR: Collecting requests==2.29.0
2026-05-01 00:32:06.319790 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/cf/e1/2aa539876d9ed0ddc95882451deb57cfd7aa8dbf0b8dbce68e045549ba56/requests-2.29.0-py3-none-any.whl (62 kB)
2026-05-01 00:32:06.319793 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.5/62.5 kB 1.0 MB/s eta 0:00:00
2026-05-01 00:32:06.319797 : DEBUG_ARR: Collecting requests-oauthlib==1.3.1
2026-05-01 00:32:06.319799 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/6f/bb/5deac77a9af870143c684ab46a7934038a53eb4aa975bc0687ed6ca2c610/requests_oauthlib-1.3.1-py2.py3-none-any.whl (23 kB)
2026-05-01 00:32:06.319815 : DEBUG_ARR: Collecting retry==0.9.2
2026-05-01 00:32:06.319818 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/4b/0d/53aea75710af4528a25ed6837d71d117602b01946b307a3912cb3cfcbcba/retry-0.9.2-py2.py3-none-any.whl (8.0 kB)
2026-05-01 00:32:06.319821 : DEBUG_ARR: Collecting rpyc==5.3.1
2026-05-01 00:32:06.319824 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/a4/d8/715206e54dfc54177d126f05b6ecc9526891b11ac7a4bafdb1ae4df55eab/rpyc-5.3.1-py3-none-any.whl (74 kB)
2026-05-01 00:32:06.319827 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.0/74.0 kB 871.1 kB/s eta 0:00:00
2026-05-01 00:32:06.319831 : DEBUG_ARR: Collecting scandir==1.10.0
2026-05-01 00:32:06.319833 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/df/f5/9c052db7bd54d0cbf1bc0bb6554362bba1012d03e5888950a4f5c5dadc4e/scandir-1.10.0.tar.gz (33 kB)
2026-05-01 00:32:06.319836 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319839 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319842 : DEBUG_ARR: Collecting scapy==2.4.5
2026-05-01 00:32:06.319845 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/85/47/c919432ca258f354bb2c1e645623f891603f185bfc7563d4a21f6432e7ed/scapy-2.4.5.tar.gz (1.1 MB)
2026-05-01 00:32:06.319848 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.1/1.1 MB 5.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319851 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319854 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319857 : DEBUG_ARR: Collecting scp==0.14.5
2026-05-01 00:32:06.319860 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7f/04/4bcc504e6c2fdcfee7d74a6d14a49db0f129baf2cfa19f61148f333e96b9/scp-0.14.5-py2.py3-none-any.whl (8.7 kB)
2026-05-01 00:32:06.319863 : DEBUG_ARR: Collecting semantic-version==2.10.0
2026-05-01 00:32:06.319866 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/6a/23/8146aad7d88f4fcb3a6218f41a60f6c2d4e3a72de72da1825dc7c8f7877c/semantic_version-2.10.0-py2.py3-none-any.whl (15 kB)
2026-05-01 00:32:06.319869 : DEBUG_ARR: Collecting serpent==1.41
2026-05-01 00:32:06.319872 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/ad/86/e029bd8a451f145e28530128239be057ca6e701aac46ad0d0000f852d551/serpent-1.41-py3-none-any.whl (9.6 kB)
2026-05-01 00:32:06.319874 : DEBUG_ARR: Collecting setuptools-rust==1.6.0
2026-05-01 00:32:06.319877 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/57/db/7cc20ad859bc2a6a0c60e497c4be19784a8d14ff8e53a6da6ee4a6edd500/setuptools_rust-1.6.0-py3-none-any.whl (23 kB)
2026-05-01 00:32:06.319880 : DEBUG_ARR: Collecting simplegeneric==0.8.1
2026-05-01 00:32:06.319883 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/3d/57/4d9c9e3ae9a255cd4e1106bb57e24056d3d0709fc01b2e3e345898e49d5b/simplegeneric-0.8.1.zip (12 kB)
2026-05-01 00:32:06.319886 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319889 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319892 : DEBUG_ARR: Collecting six==1.16.0
2026-05-01 00:32:06.319894 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d9/5a/e7c31adbe875f2abbb91bd84cf2dc52d792b5a01506781dbcf25c91daf11/six-1.16.0-py2.py3-none-any.whl (11 kB)
2026-05-01 00:32:06.319897 : DEBUG_ARR: Collecting smmap==5.0.0
2026-05-01 00:32:06.319900 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/6d/01/7caa71608bc29952ae09b0be63a539e50d2484bc37747797a66a60679856/smmap-5.0.0-py3-none-any.whl (24 kB)
2026-05-01 00:32:06.319903 : DEBUG_ARR: Collecting snappi==0.7.44
2026-05-01 00:32:06.319906 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/d6/11/f1e2e0d8f3b9ba427c245d47763c66c15af611d189a4db9293d179b89d5b/snappi-0.7.44-py2.py3-none-any.whl (195 kB)
2026-05-01 00:32:06.319909 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 195.6/195.6 kB 3.3 MB/s eta 0:00:00
2026-05-01 00:32:06.319912 : DEBUG_ARR: Collecting snappi-convergence==0.2.2
2026-05-01 00:32:06.319915 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/30/26/4e1e6b88a8d8742c94a574d613f374b345379c0d1a3f93f38baf2d7449b0/snappi_convergence-0.2.2-py2.py3-none-any.whl (102 kB)
2026-05-01 00:32:06.319918 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 102.3/102.3 kB 2.2 MB/s eta 0:00:00
2026-05-01 00:32:06.319921 : DEBUG_ARR: Collecting snappi-ixnetwork==0.7.12
2026-05-01 00:32:06.319924 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/09/ee/5d374a80bd9f4357f961135799cc67181b2b0e0001a1304458dca472cd82/snappi_ixnetwork-0.7.12-py2.py3-none-any.whl (82 kB)
2026-05-01 00:32:06.319927 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 82.0/82.0 kB 1.6 MB/s eta 0:00:00
2026-05-01 00:32:06.319930 : DEBUG_ARR: Collecting tabulate==0.9.0
2026-05-01 00:32:06.319933 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/40/44/4a5f08c96eb108af5cb50b41f76142f0afa346dfa99d5296fe7202a11854/tabulate-0.9.0-py3-none-any.whl (35 kB)
2026-05-01 00:32:06.319936 : DEBUG_ARR: Collecting tenacity==8.2.2
2026-05-01 00:32:06.319939 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/e7/b0/c23bd61e1b32c9b96fbca996c87784e196a812da8d621d8d04851f6c8181/tenacity-8.2.2-py3-none-any.whl (24 kB)
2026-05-01 00:32:06.319942 : DEBUG_ARR: Collecting textfsm==1.1.2
2026-05-01 00:32:06.319944 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/8e/74/e4f66bf3b3829e063b30501b586b1a489bd664b9066bf74650845e4c6352/textfsm-1.1.2-py2.py3-none-any.whl (44 kB)
2026-05-01 00:32:06.319948 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 44.7/44.7 kB 571.1 kB/s eta 0:00:00
2026-05-01 00:32:06.319951 : DEBUG_ARR: Collecting thrift==0.11.0
2026-05-01 00:32:06.319954 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c6/b4/510617906f8e0c5660e7d96fbc5585113f83ad547a3989b80297ac72a74c/thrift-0.11.0.tar.gz (52 kB)
2026-05-01 00:32:06.319957 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 52.5/52.5 kB 554.5 kB/s eta 0:00:00
2026-05-01 00:32:06.319960 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.319963 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.319965 : DEBUG_ARR: Collecting tomli==2.0.1
2026-05-01 00:32:06.319968 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/97/75/10a9ebee3fd790d20926a90a2547f0bf78f371b2f13aa822c759680ca7b9/tomli-2.0.1-py3-none-any.whl (12 kB)
2026-05-01 00:32:06.319971 : DEBUG_ARR: Collecting traitlets==5.9.0
2026-05-01 00:32:06.319974 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/77/75/c28e9ef7abec2b7e9ff35aea3e0be6c1aceaf7873c26c95ae1f0d594de71/traitlets-5.9.0-py3-none-any.whl (117 kB)
2026-05-01 00:32:06.319977 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 117.4/117.4 kB 3.4 MB/s eta 0:00:00
2026-05-01 00:32:06.319980 : DEBUG_ARR: Collecting types-cryptography==3.3.23.2
2026-05-01 00:32:06.319983 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/b6/36/92dfe7e5056694e78caefd05b383140c74c7fcbfc63d26ee514c77f2d8a2/types_cryptography-3.3.23.2-py3-none-any.whl (30 kB)
2026-05-01 00:32:06.319998 : DEBUG_ARR: Collecting typing==3.7.4.3
2026-05-01 00:32:06.320001 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/05/d9/6eebe19d46bd05360c9a9aae822e67a80f9242aabbfc58b641b957546607/typing-3.7.4.3.tar.gz (78 kB)
2026-05-01 00:32:06.320005 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 78.6/78.6 kB 2.2 MB/s eta 0:00:00
2026-05-01 00:32:06.320008 : DEBUG_ARR:   Preparing metadata (setup.py): started
2026-05-01 00:32:06.320011 : DEBUG_ARR:   Preparing metadata (setup.py): finished with status 'done'
2026-05-01 00:32:06.320014 : DEBUG_ARR: Collecting typing_extensions==4.5.0
2026-05-01 00:32:06.320017 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/31/25/5abcd82372d3d4a3932e1fa8c3dbf9efac10cc7c0d16e78467460571b404/typing_extensions-4.5.0-py3-none-any.whl (27 kB)
2026-05-01 00:32:06.320020 : DEBUG_ARR: Collecting urllib3==1.26.15
2026-05-01 00:32:06.320022 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7b/f5/890a0baca17a61c1f92f72b81d3c31523c99bec609e60c292ea55b387ae8/urllib3-1.26.15-py2.py3-none-any.whl (140 kB)
2026-05-01 00:32:06.320025 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 140.9/140.9 kB 1.9 MB/s eta 0:00:00
2026-05-01 00:32:06.320029 : DEBUG_ARR: Collecting vine==1.3.0
2026-05-01 00:32:06.320032 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/7f/60/82c03047396126c8331ceb64da1dc52d4f1317209f32e8fe286d0c07365a/vine-1.3.0-py2.py3-none-any.whl (14 kB)
2026-05-01 00:32:06.320034 : DEBUG_ARR: Collecting virtualenv==20.23.0
2026-05-01 00:32:06.320037 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/f1/0a/18755fa6aec794fd539b050beeaa905fa5c77c64356aa8bdecb62c01581a/virtualenv-20.23.0-py3-none-any.whl (3.3 MB)
2026-05-01 00:32:06.320040 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3.3/3.3 MB 4.6 MB/s eta 0:00:00
2026-05-01 00:32:06.320044 : DEBUG_ARR: Collecting wcwidth==0.2.6
2026-05-01 00:32:06.320046 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/20/f4/c0584a25144ce20bfcf1aecd041768b8c762c1eb0aa77502a3f0baa83f11/wcwidth-0.2.6-py2.py3-none-any.whl (29 kB)
2026-05-01 00:32:06.320049 : DEBUG_ARR: Collecting websocket-client==1.5.1
2026-05-01 00:32:06.320052 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/6d/9a/6c793729c9d48fcca155ce55e4dfafacffb7fb52a62e3ae2198846c31af6/websocket_client-1.5.1-py3-none-any.whl (55 kB)
2026-05-01 00:32:06.320055 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 55.9/55.9 kB 755.7 kB/s eta 0:00:00
2026-05-01 00:32:06.320059 : DEBUG_ARR: Collecting wrapt==1.15.0
2026-05-01 00:32:06.320061 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/af/7f/25913aacbe0c2c68e7354222bdefe4e840489725eb835e311c581396f91f/wrapt-1.15.0-cp38-cp38-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_17_x86_64.manylinux2014_x86_64.whl (81 kB)
2026-05-01 00:32:06.320065 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 81.5/81.5 kB 1.5 MB/s eta 0:00:00
2026-05-01 00:32:06.320068 : DEBUG_ARR: Collecting yarl==1.9.2
2026-05-01 00:32:06.320071 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/c4/0c/7898c35ca4945fdd416e1dadeda985cc391e4f9298ae5e71c3a5cd88e82d/yarl-1.9.2-cp38-cp38-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (266 kB)
2026-05-01 00:32:06.320074 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 266.9/266.9 kB 3.5 MB/s eta 0:00:00
2026-05-01 00:32:06.320077 : DEBUG_ARR: Requirement already satisfied: setuptools in ./env-python3/lib/python3.8/site-packages (from grpcio-tools==1.44.0) (44.0.0)
2026-05-01 00:32:06.320080 : DEBUG_ARR: Collecting setuptools (from grpcio-tools==1.44.0)
2026-05-01 00:32:06.320083 : DEBUG_ARR:   Downloading https://mirrors.aliyun.com/pypi/packages/cd/b1/961ba076c7d3732e3a97e6681c55ef647afb795fe8bfcd27becec8a762ce/setuptools-75.3.4-py3-none-any.whl (1.3 MB)
2026-05-01 00:32:06.320086 : DEBUG_ARR:      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.3/1.3 MB 6.4 MB/s eta 0:00:00
2026-05-01 00:32:06.320089 : DEBUG_ARR: Building wheels for collected packages: ansible, future, ipaddr, ncclient, nnpy, pysubnettree, pytest-ansible, scandir, scapy, simplegeneric, thrift, typing
2026-05-01 00:32:06.320092 : DEBUG_ARR:   Building wheel for ansible (setup.py): started
2026-05-01 00:32:06.320095 : DEBUG_ARR:   Building wheel for ansible (setup.py): finished with status 'done'
2026-05-01 00:32:06.320098 : DEBUG_ARR:   Created wheel for ansible: filename=ansible-2.9.27-py3-none-any.whl size=16206250 sha256=7a7535c521dc24aeba1f1e6229a70eeedf1c361cc174bbb5079c1b62a1cd85f5
2026-05-01 00:32:06.320101 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/f2/8f/5a/028c939f6500a161b5ac5d2d72fd54c640cf6bfb2808d7b6df
2026-05-01 00:32:06.320104 : DEBUG_ARR:   Building wheel for future (setup.py): started
2026-05-01 00:32:06.320107 : DEBUG_ARR:   Building wheel for future (setup.py): finished with status 'done'
2026-05-01 00:32:06.320110 : DEBUG_ARR:   Created wheel for future: filename=future-0.18.3-py3-none-any.whl size=492025 sha256=c9976dbf21009f4aa0ffa984bcff875ceb4b9a69a116589f01355961e3c4ef15
2026-05-01 00:32:06.320112 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/07/14/8c/1cb73be9422f7e071f24ed77cb8e51eb87ac17e6fc06640715
2026-05-01 00:32:06.320115 : DEBUG_ARR:   Building wheel for ipaddr (setup.py): started
2026-05-01 00:32:06.320118 : DEBUG_ARR:   Building wheel for ipaddr (setup.py): finished with status 'done'
2026-05-01 00:32:06.320121 : DEBUG_ARR:   Created wheel for ipaddr: filename=ipaddr-2.2.0-py3-none-any.whl size=18280 sha256=d26bf58f914d57ffa7d002a7db1ce0c6daa53ee4f59cb32318e097494fc12024
2026-05-01 00:32:06.320124 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/93/8d/e3/125c89ca11bdb4ea3705a34e2d7b97949d7628f487eb7776b3
2026-05-01 00:32:06.320127 : DEBUG_ARR:   Building wheel for ncclient (setup.py): started
2026-05-01 00:32:06.320129 : DEBUG_ARR:   Building wheel for ncclient (setup.py): finished with status 'done'
2026-05-01 00:32:06.320132 : DEBUG_ARR:   Created wheel for ncclient: filename=ncclient-0.6.13-py2.py3-none-any.whl size=84621 sha256=3be13c9736e23dc98b83adfe661038be5fc6768c36008c0857b18b4c64edc751
2026-05-01 00:32:06.320135 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/d0/61/c6/5b64a30b880af597cd74f056229dcab83010ddfb7331ae139e
2026-05-01 00:32:06.320138 : DEBUG_ARR:   Building wheel for nnpy (setup.py): started
2026-05-01 00:32:06.320141 : DEBUG_ARR:   Building wheel for nnpy (setup.py): finished with status 'done'
2026-05-01 00:32:06.320144 : DEBUG_ARR:   Created wheel for nnpy: filename=nnpy-1.4.2-cp38-cp38-linux_x86_64.whl size=33900 sha256=96928c579b68e9b00cf74b064c3c004b53d0744da17481b6b3eaed5cd95de868
2026-05-01 00:32:06.320147 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/e6/f8/08/0200bcced808663d7839e97b5ea0b8efbdf327c9b5faa7658e
2026-05-01 00:32:06.320149 : DEBUG_ARR:   Building wheel for pysubnettree (setup.py): started
2026-05-01 00:32:06.320152 : DEBUG_ARR:   Building wheel for pysubnettree (setup.py): finished with status 'done'
2026-05-01 00:32:06.320155 : DEBUG_ARR:   Created wheel for pysubnettree: filename=pysubnettree-0.35-cp38-cp38-linux_x86_64.whl size=134478 sha256=d9a58a877a5559011709661b9a658309c0f2144813e44e328c7cbe187b65d917
2026-05-01 00:32:06.320158 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/80/af/55/008a607286c888b79e9ae1298f6de85a39a733c35a43735bdc
2026-05-01 00:32:06.320176 : DEBUG_ARR:   Building wheel for pytest-ansible (setup.py): started
2026-05-01 00:32:06.320180 : DEBUG_ARR:   Building wheel for pytest-ansible (setup.py): finished with status 'done'
2026-05-01 00:32:06.320183 : DEBUG_ARR:   Created wheel for pytest-ansible: filename=pytest_ansible-2.2.4-py3-none-any.whl size=20019 sha256=2860b9e97ea319436c39d28a895063900bc61b8ce4b41414e35194ed315fdc2d
2026-05-01 00:32:06.320185 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/f7/37/f5/25ea9e2dfd50072512fe8942e207c1cf926beb7131ece7ec43
2026-05-01 00:32:06.320188 : DEBUG_ARR:   Building wheel for scandir (setup.py): started
2026-05-01 00:32:06.320191 : DEBUG_ARR:   Building wheel for scandir (setup.py): finished with status 'done'
2026-05-01 00:32:06.320194 : DEBUG_ARR:   Created wheel for scandir: filename=scandir-1.10.0-cp38-cp38-linux_x86_64.whl size=44354 sha256=681accd58a1cf7cae461e7e6c3469ccaec56497c2a4c4f8d171b5e13f0dd1e0e
2026-05-01 00:32:06.320197 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/23/22/b9/e11b11d980fe2fb77930e35ed8b8f7c1f2e3c58e6cd9ad9303
2026-05-01 00:32:06.320200 : DEBUG_ARR:   Building wheel for scapy (setup.py): started
2026-05-01 00:32:06.320203 : DEBUG_ARR:   Building wheel for scapy (setup.py): finished with status 'done'
2026-05-01 00:32:06.320206 : DEBUG_ARR:   Created wheel for scapy: filename=scapy-2.4.5-py2.py3-none-any.whl size=1261540 sha256=5649fd73e4c23a71e4cff4dbcd324e4a6a96adcd2726cb8a4d013de0a6395eea
2026-05-01 00:32:06.320208 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/67/51/b3/b3c36b52116e1ae296b5e85f5b70b49ab11b71d5233c4d02d3
2026-05-01 00:32:06.320211 : DEBUG_ARR:   Building wheel for simplegeneric (setup.py): started
2026-05-01 00:32:06.320214 : DEBUG_ARR:   Building wheel for simplegeneric (setup.py): finished with status 'done'
2026-05-01 00:32:06.320217 : DEBUG_ARR:   Created wheel for simplegeneric: filename=simplegeneric-0.8.1-py3-none-any.whl size=5075 sha256=73cdb86aa59d556fddf5b60219cb96a1084d589ca42da23ae4c5cb00e860e042
2026-05-01 00:32:06.320220 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/ef/1b/c2/777f8338800d6c547dc2faae760b6bdcd2373ed9383cb5e121
2026-05-01 00:32:06.320223 : DEBUG_ARR:   Building wheel for thrift (setup.py): started
2026-05-01 00:32:06.320225 : DEBUG_ARR:   Building wheel for thrift (setup.py): finished with status 'done'
2026-05-01 00:32:06.320228 : DEBUG_ARR:   Created wheel for thrift: filename=thrift-0.11.0-cp38-cp38-linux_x86_64.whl size=381264 sha256=e0266f795b1f243c4198f9decb2d9deb8bb73e10f378dc94da9542b57cfa969e
2026-05-01 00:32:06.320231 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/02/54/75/9a485e071392184643495590bf5e9347cb370ba5a6c59285ab
2026-05-01 00:32:06.320234 : DEBUG_ARR:   Building wheel for typing (setup.py): started
2026-05-01 00:32:06.320237 : DEBUG_ARR:   Building wheel for typing (setup.py): finished with status 'done'
2026-05-01 00:32:06.320240 : DEBUG_ARR:   Created wheel for typing: filename=typing-3.7.4.3-py3-none-any.whl size=26308 sha256=4e4429a6d253f44059eca2213d642338d9afb2f13253587c4a1b68fae56298a7
2026-05-01 00:32:06.320242 : DEBUG_ARR:   Stored in directory: /home/ubuntu/.cache/pip/wheels/8a/98/fa/67a8eed0e06c38c41b3bce441050970436189df672fd1403fe
2026-05-01 00:32:06.320245 : DEBUG_ARR: Successfully built ansible future ipaddr ncclient nnpy pysubnettree pytest-ansible scandir scapy simplegeneric thrift typing
2026-05-01 00:32:06.320251 : DEBUG_ARR: [91mDEPRECATION: celery 4.4.7 has a non-standard dependency specifier pytz>dev. pip 24.1 will enforce this behaviour change. A possible replacement is to upgrade to a newer version of celery or contact the author to suggest that they release a version with a conforming dependency specifiers. Discussion can be found at https://github.com/pypa/pip/issues/12063
2026-05-01 00:32:06.320255 : DEBUG_ARR: [0mInstalling collected packages: wcwidth, types-cryptography, simplegeneric, scandir, pytz, pysubnettree, pyserial, pyfiglet, pyasn1, ptyprocess, ply, pickleshare, passlib, netaddr, ipaddr, ijson, dpkt, distlib, billiard, wrapt, websocket-client, vine, urllib3, typing_extensions, typing, traitlets, tomli, tenacity, tabulate, smmap, six, setuptools, serpent, semantic-version, scapy, PyYAML, pysmi, PyJWT, Pygments, pycryptodomex, pycryptodome, pycparser, py, psutil, protobuf, prettytable, portalocker, plumbum, pluggy, platformdirs, pexpect, packaging, oauthlib, natsort, multidict, mock, mccabe, MarkupSafe, lxml, lazy-object-proxy, jsonpointer, isort, iniconfig, idna, future, frozenlist, filelock, execnet, defusedxml, decorator, contextlib2, charset-normalizer, certifi, bcrypt, attrs, async-timeout, abstract-open-traffic-generator, yarl, virtualenv, thrift, textfsm, setuptools-rust, rpyc, retry, requests, redis, python-dateutil, pytest, pysnmp, Pyro4, pyaml, ptf, prompt-toolkit, jsonpath-ng, jsonpatch, Jinja2, isodate, grpcio, gitdb, cffi, astroid, amqp, allure-python-commons, aiosignal, snappi-convergence, requests-oauthlib, pytest-repeat, pytest-metadata, pytest-forked, PyNaCl, pylint, nnpy, kombu, ixnetwork-restpy, ipython, grpcio-tools, GitPython, cryptography, azure-core, allure-pytest, aiohttp, snappi-ixnetwork, snappi, pytest-xdist, pytest-html, paramiko, msrest, ixnetwork-open-traffic-generator, celery, azure-storage-queue, ansible, scp, pytest-ansible, ncclient, msal, azure-storage-blob, netmiko, msal-extensions, azure-identity, azure-kusto-data, azure-kusto-ingest
2026-05-01 00:32:06.320258 : DEBUG_ARR:   Attempting uninstall: typing_extensions
2026-05-01 00:32:06.320261 : DEBUG_ARR:     Found existing installation: typing_extensions 4.13.2
2026-05-01 00:32:06.320263 : DEBUG_ARR:     Uninstalling typing_extensions-4.13.2:
2026-05-01 00:32:06.320267 : DEBUG_ARR:       Successfully uninstalled typing_extensions-4.13.2
2026-05-01 00:32:06.320270 : DEBUG_ARR:   Attempting uninstall: setuptools
2026-05-01 00:32:06.320272 : DEBUG_ARR:     Found existing installation: setuptools 44.0.0
2026-05-01 00:32:06.320275 : DEBUG_ARR:     Uninstalling setuptools-44.0.0:
2026-05-01 00:32:06.320278 : DEBUG_ARR:       Successfully uninstalled setuptools-44.0.0
2026-05-01 00:32:06.320281 : DEBUG_ARR:   Attempting uninstall: pycparser
2026-05-01 00:32:06.320283 : DEBUG_ARR:     Found existing installation: pycparser 2.23
2026-05-01 00:32:06.320286 : DEBUG_ARR:     Uninstalling pycparser-2.23:
2026-05-01 00:32:06.320289 : DEBUG_ARR:       Successfully uninstalled pycparser-2.23
2026-05-01 00:32:06.320292 : DEBUG_ARR:   Attempting uninstall: bcrypt
2026-05-01 00:32:06.320295 : DEBUG_ARR:     Found existing installation: bcrypt 5.0.0
2026-05-01 00:32:06.320298 : DEBUG_ARR:     Uninstalling bcrypt-5.0.0:
2026-05-01 00:32:06.320300 : DEBUG_ARR:       Successfully uninstalled bcrypt-5.0.0
2026-05-01 00:32:06.320303 : DEBUG_ARR:   Attempting uninstall: cffi
2026-05-01 00:32:06.320306 : DEBUG_ARR:     Found existing installation: cffi 1.17.1
2026-05-01 00:32:06.320309 : DEBUG_ARR:     Uninstalling cffi-1.17.1:
2026-05-01 00:32:06.320312 : DEBUG_ARR:       Successfully uninstalled cffi-1.17.1
2026-05-01 00:32:06.320315 : DEBUG_ARR:   Attempting uninstall: PyNaCl
2026-05-01 00:32:06.320318 : DEBUG_ARR:     Found existing installation: PyNaCl 1.6.2
2026-05-01 00:32:06.320321 : DEBUG_ARR:     Uninstalling PyNaCl-1.6.2:
2026-05-01 00:32:06.320323 : DEBUG_ARR:       Successfully uninstalled PyNaCl-1.6.2
2026-05-01 00:32:06.320326 : DEBUG_ARR:   Attempting uninstall: cryptography
2026-05-01 00:32:06.320329 : DEBUG_ARR:     Found existing installation: cryptography 47.0.0
2026-05-01 00:32:06.320332 : DEBUG_ARR:     Uninstalling cryptography-47.0.0:
2026-05-01 00:32:06.320335 : DEBUG_ARR:       Successfully uninstalled cryptography-47.0.0
2026-05-01 00:32:06.320337 : DEBUG_ARR:   Attempting uninstall: paramiko
2026-05-01 00:32:06.320340 : DEBUG_ARR:     Found existing installation: paramiko 3.5.1
2026-05-01 00:32:06.320343 : DEBUG_ARR:     Uninstalling paramiko-3.5.1:
2026-05-01 00:32:06.320361 : DEBUG_ARR:       Successfully uninstalled paramiko-3.5.1
2026-05-01 00:32:06.320365 : DEBUG_ARR: Successfully installed GitPython-3.1.31 Jinja2-2.10.1 MarkupSafe-2.0.1 PyJWT-2.5.0 PyNaCl-1.5.0 PyYAML-6.0 Pygments-2.15.1 Pyro4-4.82 abstract-open-traffic-generator-0.0.68 aiohttp-3.8.4 aiosignal-1.3.1 allure-pytest-2.8.22 allure-python-commons-2.8.22 amqp-2.6.1 ansible-2.9.27 astroid-1.6.6 async-timeout-4.0.2 attrs-23.1.0 azure-core-1.26.4 azure-identity-1.12.0 azure-kusto-data-4.1.4 azure-kusto-ingest-4.1.4 azure-storage-blob-12.9.0 azure-storage-queue-12.6.0 bcrypt-4.0.1 billiard-3.6.4.0 celery-4.4.7 certifi-2022.12.7 cffi-1.15.1 charset-normalizer-3.1.0 contextlib2-0.6.0.post1 cryptography-3.3.2 decorator-5.1.1 defusedxml-0.7.1 distlib-0.3.6 dpkt-1.9.8 execnet-1.9.0 filelock-3.12.0 frozenlist-1.3.3 future-0.18.3 gitdb-4.0.10 grpcio-1.44.0 grpcio-tools-1.44.0 idna-3.4 ijson-3.2.0.post0 iniconfig-2.0.0 ipaddr-2.2.0 ipython-5.4.1 isodate-0.6.1 isort-5.12.0 ixnetwork-open-traffic-generator-0.0.79 ixnetwork-restpy-1.0.64 jsonpatch-1.32 jsonpath-ng-1.5.3 jsonpointer-2.3 kombu-4.6.11 lazy-object-proxy-1.9.0 lxml-4.9.2 mccabe-0.7.0 mock-5.0.2 msal-1.22.0 msal-extensions-1.0.0 msrest-0.6.21 multidict-6.0.4 natsort-8.3.1 ncclient-0.6.13 netaddr-0.8.0 netmiko-2.4.2 nnpy-1.4.2 oauthlib-3.2.2 packaging-23.1 paramiko-2.7.1 passlib-1.7.4 pexpect-4.8.0 pickleshare-0.7.5 platformdirs-3.5.0 pluggy-1.0.0 plumbum-1.8.1 ply-3.11 portalocker-2.7.0 prettytable-3.7.0 prompt-toolkit-1.0.18 protobuf-3.20.1 psutil-5.9.5 ptf-0.9.3 ptyprocess-0.7.0 py-1.11.0 pyaml-21.10.1 pyasn1-0.4.8 pycparser-2.21 pycryptodome-3.9.8 pycryptodomex-3.17 pyfiglet-0.8.post1 pylint-1.8.1 pyserial-3.5 pysmi-0.3.4 pysnmp-4.4.12 pysubnettree-0.35 pytest-7.1.3 pytest-ansible-2.2.4 pytest-forked-1.6.0 pytest-html-3.2.0 pytest-metadata-2.0.4 pytest-repeat-0.9.1 pytest-xdist-1.28.0 python-dateutil-2.8.2 pytz-2023.3 redis-4.5.4 requests-2.29.0 requests-oauthlib-1.3.1 retry-0.9.2 rpyc-5.3.1 scandir-1.10.0 scapy-2.4.5 scp-0.14.5 semantic-version-2.10.0 serpent-1.41 setuptools-75.3.4 setuptools-rust-1.6.0 simplegeneric-0.8.1 six-1.16.0 smmap-5.0.0 snappi-0.7.44 snappi-convergence-0.2.2 snappi-ixnetwork-0.7.12 tabulate-0.9.0 tenacity-8.2.2 textfsm-1.1.2 thrift-0.11.0 tomli-2.0.1 traitlets-5.9.0 types-cryptography-3.3.23.2 typing-3.7.4.3 typing_extensions-4.5.0 urllib3-1.26.15 vine-1.3.0 virtualenv-20.23.0 wcwidth-0.2.6 websocket-client-1.5.1 wrapt-1.15.0 yarl-1.9.2
2026-05-01 00:32:06.320368 : DEBUG_ARR: [91m
2026-05-01 00:32:06.320371 : DEBUG_ARR: [notice] A new release of pip is available: 24.0 -> 25.0.1
2026-05-01 00:32:06.320374 : DEBUG_ARR: [notice] To update, run: python3 -m pip install --upgrade pip
2026-05-01 00:32:06.320377 : DEBUG_ARR: [0mRemoving intermediate container 4e193a47eb51
2026-05-01 00:32:06.320380 : DEBUG_ARR:  ---> e153fecf6bfe
2026-05-01 00:32:06.320383 : DEBUG_ARR: Successfully built e153fecf6bfe
2026-05-01 00:32:06.320386 : DEBUG_ARR: Successfully tagged docker-sonic-mgmt-ubuntu:master
2026-05-01 00:32:06.320388 : DEBUG_ARR: INFO: cleanup a temporary dir: /tmp/tmp.jjr3pEX5LP
2026-05-01 00:32:06.320391 : DEBUG_ARR: INFO: creating a container: sonic-mgmt-test ...
2026-05-01 00:32:06.320394 : DEBUG_ARR: 41c4230d5d56635b223dae2545e003e50b73c9e81218942a6b473a0239f1d1d1
2026-05-01 00:32:06.320397 : DEBUG_ARR:  * Restarting OpenBSD Secure Shell server sshd
2026-05-01 00:32:06.320400 : DEBUG_ARR:    ...done.
2026-05-01 00:32:06.320403 : DEBUG_ARR: INFO: verifying UID and GID in container matches host
2026-05-01 00:32:06.320405 : DEBUG_ARR: ******************************************************************************
2026-05-01 00:32:06.320408 : DEBUG_ARR: EXEC: docker exec --user ubuntu -ti sonic-mgmt-test bash
2026-05-01 00:32:06.320411 : DEBUG_ARR: SSH:  ssh -i ~/.ssh/id_rsa_docker_sonic_mgmt ubuntu@172.17.0.2
2026-05-01 00:32:06.320414 : DEBUG_ARR: ******************************************************************************
2026-05-01 00:32:06.320417 : DEBUG_ARR: 
2026-05-01 00:32:06.320420 : DEBUG_ARR: INFO: sonic-mgmt configuration is done!
2026-05-01 00:32:06.320428 : DEBUG_ARR: 
2026-05-01 00:32:06.320471 : Sleep 10 second
2026-05-01 00:32:16.330783 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp /data/g200dev.tar .; sudo tar xvf g200dev.tar'; ls -l *g200*"
2026-05-01 00:32:17.047185 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/
2026-05-01 00:32:17.047227 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/minigraph.xml
2026-05-01 00:32:17.047232 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/platform_asic
2026-05-01 00:32:17.047235 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/
2026-05-01 00:32:17.047238 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/acl_key_profile.json
2026-05-01 00:32:17.047241 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/sai_init_config.json
2026-05-01 00:32:17.047245 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/sai_sdk_log_config.json
2026-05-01 00:32:17.047248 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/port_config.ini
2026-05-01 00:32:17.047251 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/sai.profile
2026-05-01 00:32:17.047254 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/g200/nsim_config.json
2026-05-01 00:32:17.047256 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/plugins/
2026-05-01 00:32:17.047259 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/plugins/eeprom.py
2026-05-01 00:32:17.047262 : DEBUG_ARR: x86_64-kvm-g200_x86_64-r0/default_sku
2026-05-01 00:32:17.047265 : DEBUG_ARR: -rw-r--r-- 1 root root 30720 May  1 07:21 g200dev.tar
2026-05-01 00:32:17.047308 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp -r x86_64-kvm-g200_x86_64-r0/g200 x86_64-kvm_x86_64-r0;ls -l x86_64-kvm_x86_64-r0/g200'"
2026-05-01 00:32:17.748971 : DEBUG_ARR: total 32
2026-05-01 00:32:17.749013 : DEBUG_ARR: -rw-r--r-- 1 root root 8704 May  1 07:32 acl_key_profile.json
2026-05-01 00:32:17.749017 : DEBUG_ARR: -rw-r--r-- 1 root root  924 May  1 07:32 nsim_config.json
2026-05-01 00:32:17.749020 : DEBUG_ARR: -rw-r--r-- 1 root root 2111 May  1 07:32 port_config.ini
2026-05-01 00:32:17.749024 : DEBUG_ARR: -rw-r--r-- 1 root root  201 May  1 07:32 sai.profile
2026-05-01 00:32:17.749027 : DEBUG_ARR: -rw-r--r-- 1 root root  780 May  1 07:32 sai_init_config.json
2026-05-01 00:32:17.749030 : DEBUG_ARR: -rw-r--r-- 1 root root 3482 May  1 07:32 sai_sdk_log_config.json
2026-05-01 00:32:17.749076 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp /data/q200dev.tar .; sudo tar xvf q200dev.tar'; ls -l *q200*"
2026-05-01 00:32:18.449487 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/
2026-05-01 00:32:18.449528 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/default_sku
2026-05-01 00:32:18.449533 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/
2026-05-01 00:32:18.449536 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/q200-128x100G-vs.json
2026-05-01 00:32:18.449539 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/port_config.ini
2026-05-01 00:32:18.449542 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/sai.profile
2026-05-01 00:32:18.449545 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/buffer_ports_t0.j2
2026-05-01 00:32:18.449552 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/buffers_defaults_t0.j2
2026-05-01 00:32:18.449555 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/q200/buffers.json.j2
2026-05-01 00:32:18.449557 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/minigraph.xml
2026-05-01 00:32:18.449560 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/plugins/
2026-05-01 00:32:18.449563 : DEBUG_ARR: x86_64-kvm-q200_x86_64-r0/plugins/eeprom.py
2026-05-01 00:32:18.449566 : DEBUG_ARR: -rw-r--r-- 1 root root 40960 May  1 07:21 q200dev.tar
2026-05-01 00:32:18.449606 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp -r x86_64-kvm-q200_x86_64-r0/q200 x86_64-kvm_x86_64-r0;ls -l x86_64-kvm_x86_64-r0/q200'"
2026-05-01 00:32:19.155842 : DEBUG_ARR: total 44
2026-05-01 00:32:19.155883 : DEBUG_ARR: -rw-r--r-- 1 root root   223 May  1 07:32 buffer_ports_t0.j2
2026-05-01 00:32:19.155888 : DEBUG_ARR: -rw-r--r-- 1 root root    67 May  1 07:32 buffers.json.j2
2026-05-01 00:32:19.155891 : DEBUG_ARR: -rw-r--r-- 1 root root  1034 May  1 07:32 buffers_defaults_t0.j2
2026-05-01 00:32:19.155894 : DEBUG_ARR: -rw-r--r-- 1 root root  9695 May  1 07:32 port_config.ini
2026-05-01 00:32:19.155899 : DEBUG_ARR: -rw-r--r-- 1 root root 13694 May  1 07:32 q200-128x100G-vs.json
2026-05-01 00:32:19.155902 : DEBUG_ARR: -rw-r--r-- 1 root root   141 May  1 07:32 sai.profile
2026-05-01 00:32:19.155950 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp /data/p200dev.tar .; sudo tar xvf p200dev.tar'; ls -l *p200*"
2026-05-01 00:32:19.866256 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/
2026-05-01 00:32:19.866298 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/minigraph.xml
2026-05-01 00:32:19.866302 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/default_sku
2026-05-01 00:32:19.866306 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/cisco_asic
2026-05-01 00:32:19.866309 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/plugins/
2026-05-01 00:32:19.866315 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/plugins/eeprom.py
2026-05-01 00:32:19.866318 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/
2026-05-01 00:32:19.866323 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/sai_sdk_log_config.json
2026-05-01 00:32:19.866326 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/buffers_defaults_t0.j2
2026-05-01 00:32:19.866329 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/sai.profile
2026-05-01 00:32:19.866332 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/traps.json
2026-05-01 00:32:19.866335 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/sai_init_config.json
2026-05-01 00:32:19.866338 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/buffers.json.j2
2026-05-01 00:32:19.866341 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/port_config.ini
2026-05-01 00:32:19.866344 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/p200/buffer_ports_t0.j2
2026-05-01 00:32:19.866347 : DEBUG_ARR: x86_64-kvm-p200_x86_64-r0/platform_asic
2026-05-01 00:32:19.866350 : DEBUG_ARR: -rw-r--r-- 1 root root 40960 May  1 07:21 p200dev.tar
2026-05-01 00:32:19.866391 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device; sudo cp -r x86_64-kvm-p200_x86_64-r0/p200 x86_64-kvm_x86_64-r0;ls -l x86_64-kvm_x86_64-r0/p200'"
2026-05-01 00:32:20.555416 : DEBUG_ARR: total 44
2026-05-01 00:32:20.555457 : DEBUG_ARR: -rw-r--r-- 1 root root  223 May  1 07:32 buffer_ports_t0.j2
2026-05-01 00:32:20.555462 : DEBUG_ARR: -rw-r--r-- 1 root root   67 May  1 07:32 buffers.json.j2
2026-05-01 00:32:20.555465 : DEBUG_ARR: -rw-r--r-- 1 root root 1034 May  1 07:32 buffers_defaults_t0.j2
2026-05-01 00:32:20.555469 : DEBUG_ARR: -rw-r--r-- 1 root root 8350 May  1 07:32 port_config.ini
2026-05-01 00:32:20.555472 : DEBUG_ARR: -rw-r--r-- 1 root root  212 May  1 07:32 sai.profile
2026-05-01 00:32:20.555475 : DEBUG_ARR: -rw-r--r-- 1 root root 2071 May  1 07:32 sai_init_config.json
2026-05-01 00:32:20.555478 : DEBUG_ARR: -rw-r--r-- 1 root root 3501 May  1 07:32 sai_sdk_log_config.json
2026-05-01 00:32:20.555481 : DEBUG_ARR: -rw-r--r-- 1 root root 4419 May  1 07:32 traps.json
2026-05-01 00:32:20.555521 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /usr/share/sonic/device/x86_64-kvm_x86_64-r0/; sudo cp /data/cisco-8101-p4-32x100-vs.tar .; sudo tar xvf cisco-8101-p4-32x100-vs.tar'"
2026-05-01 00:32:21.265452 : DEBUG_ARR: cisco-8101-p4-32x100-vs/
2026-05-01 00:32:21.265501 : DEBUG_ARR: cisco-8101-p4-32x100-vs/acl_key_profile.json
2026-05-01 00:32:21.265506 : DEBUG_ARR: cisco-8101-p4-32x100-vs/pg_profile_lookup.ini
2026-05-01 00:32:21.265509 : DEBUG_ARR: cisco-8101-p4-32x100-vs/ciscovs_sai.profile
2026-05-01 00:32:21.265512 : DEBUG_ARR: cisco-8101-p4-32x100-vs/buffers.json.j2
2026-05-01 00:32:21.265516 : DEBUG_ARR: cisco-8101-p4-32x100-vs/sai_init_config.json
2026-05-01 00:32:21.265519 : DEBUG_ARR: cisco-8101-p4-32x100-vs/lanemap.ini
2026-05-01 00:32:21.265521 : DEBUG_ARR: cisco-8101-p4-32x100-vs/sai.profile
2026-05-01 00:32:21.265524 : DEBUG_ARR: cisco-8101-p4-32x100-vs/buffers_defaults_t1.j2
2026-05-01 00:32:21.265528 : DEBUG_ARR: cisco-8101-p4-32x100-vs/buffers_defaults_t0.j2
2026-05-01 00:32:21.265530 : DEBUG_ARR: cisco-8101-p4-32x100-vs/qos.json.j2
2026-05-01 00:32:21.265533 : DEBUG_ARR: cisco-8101-p4-32x100-vs/sai_sdk_log_config.json
2026-05-01 00:32:21.265536 : DEBUG_ARR: cisco-8101-p4-32x100-vs/port_config.ini
2026-05-01 00:32:21.265539 : DEBUG_ARR: cisco-8101-p4-32x100-vs/pai.profile
2026-05-01 00:32:21.265541 : DEBUG_ARR: cisco-8101-p4-32x100-vs/nsim_config.json
2026-05-01 00:32:21.265544 : DEBUG_ARR: cisco-8101-p4-32x100-vs/sai_mlnx.profile
2026-05-01 00:32:21.265861 : Current directory /home/super/workspace/PhoenixWingDailySRv6Test/na_lab/pytest_env
{'conf-name': 'vms-kvm-t0', 'group-name': 'vms6-1', 'topo': 't0', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-t0-64', 'group-name': 'vms6-1', 'topo': 't0-64', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-02'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-t0-64-32', 'group-name': 'vms6-1', 'topo': 't0-64-32', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-02'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-t1-lag', 'group-name': 'vms6-2', 'topo': 't1-lag', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-02', 'ptf_ip': '10.250.0.106/24', 'ptf_ipv6': 'fec0::ffff:afa:6/64', 'server': 'server_1', 'vm_base': 'VM0104', 'dut': ['vlab-03'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-t0-2', 'group-name': 'vms6-3', 'topo': 't0', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-03', 'ptf_ip': '10.250.0.108/24', 'ptf_ipv6': 'fec0::ffff:afa:8/64', 'server': 'server_1', 'vm_base': 'VM0104', 'dut': ['vlab-04'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-dual-t0', 'group-name': 'vms6-4', 'topo': 'dualtor', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-04', 'ptf_ip': '10.250.0.109/24', 'ptf_ipv6': 'fec0::ffff:afa:9/64', 'server': 'server_1', 'vm_base': 'VM0108', 'dut': ['vlab-05', 'vlab-06'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Dual-TOR testbed'}
{'conf-name': 'vms-kvm-multi-asic-t1-lag', 'group-name': 'vms6-4', 'topo': 't1-64-lag', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-05', 'ptf_ip': '10.250.0.110/24', 'ptf_ipv6': 'fec0::ffff:afa:a/64', 'server': 'server_1', 'vm_base': 'VM0104', 'dut': ['vlab-07'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests multi-asic virtual switch vm'}
reading
found testbed vms-kvm-ciscovs-7nodes
Starting VMs for testbed 'vms-kvm-ciscovs-7nodes' on server 'server_1'

PLAY [servers:&vm_host] ********************************************************

TASK [vm_set : Pick package_installation from env] *****************************
Friday 01 May 2026  07:32:23 +0000 (0:00:00.156)       0:00:00.156 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Set the default variable package_installation] ******************
Friday 01 May 2026  07:32:23 +0000 (0:00:00.031)       0:00:00.187 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : get host distribution] ******************************************
Friday 01 May 2026  07:32:23 +0000 (0:00:00.027)       0:00:00.215 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : get host distribution version] **********************************
Friday 01 May 2026  07:32:24 +0000 (0:00:01.044)       0:00:01.259 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : get host kernel version] ****************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.202)       0:00:01.462 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Check if kernel upgrade needed] *********************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.202)       0:00:01.664 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : debug] **********************************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.031)       0:00:01.695 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Upgrade kernel package] *****************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.026)       0:00:01.721 ************ 
skipping: [STR-ACS-VSERV-01] => (item=[]) 

TASK [vm_set : Prompt for rebooting] *******************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.040)       0:00:01.762 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Install necessary packages] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.025)       0:00:01.788 ************ 
skipping: [STR-ACS-VSERV-01] => (item=[]) 

TASK [vm_set : Install necessary packages] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.049)       0:00:01.838 ************ 
skipping: [STR-ACS-VSERV-01] => (item=[]) 

TASK [vm_set : Install necessary packages] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.054)       0:00:01.892 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Install necessary packages] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.025)       0:00:01.918 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Get default pip_executable] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.027)       0:00:01.945 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Get default pip_executable] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.026)       0:00:01.972 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : remove old python packages] *************************************
Friday 01 May 2026  07:32:25 +0000 (0:00:00.031)       0:00:02.004 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : include_tasks] **************************************************
Friday 01 May 2026  07:32:27 +0000 (0:00:01.787)       0:00:03.792 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Ensure ubuntu in docker,sudo group] *****************************
Friday 01 May 2026  07:32:27 +0000 (0:00:00.029)       0:00:03.821 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Ensure ubuntu in libvirt group] *********************************
Friday 01 May 2026  07:32:28 +0000 (0:00:00.515)       0:00:04.337 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Install br_netfilter kernel module] *****************************
Friday 01 May 2026  07:32:28 +0000 (0:00:00.242)       0:00:04.580 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Set sysctl bridge parameters for testbed] ***********************
Friday 01 May 2026  07:32:28 +0000 (0:00:00.406)       0:00:04.987 ************ 
changed: [STR-ACS-VSERV-01] => (item=net.bridge.bridge-nf-call-arptables)
ok: [STR-ACS-VSERV-01] => (item=net.bridge.bridge-nf-call-ip6tables)
ok: [STR-ACS-VSERV-01] => (item=net.bridge.bridge-nf-call-iptables)

TASK [vm_set : Set sysctl RCVBUF max parameter for testbed] ********************
Friday 01 May 2026  07:32:29 +0000 (0:00:00.799)       0:00:05.786 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Set sysctl RCVBUF default parameter for testbed] ****************
Friday 01 May 2026  07:32:29 +0000 (0:00:00.207)       0:00:05.994 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Increase IPv6 route cache size] *********************************
Friday 01 May 2026  07:32:29 +0000 (0:00:00.206)       0:00:06.200 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Setup external front port] **************************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.211)       0:00:06.412 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Setup internal management network] ******************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.028)       0:00:06.441 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : getent] *********************************************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.029)       0:00:06.470 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.405)       0:00:06.876 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.034)       0:00:06.911 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : debug] **********************************************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.038)       0:00:06.949 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "home_path = /home/ubuntu root_path = /home/ubuntu/veos-vm"
}

TASK [vm_set : Require veos or SONiC or cisco VMs by default] ******************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.029)       0:00:06.979 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : veos or SONiC or cisco VMs not needed when setting up Kubernetes master] ***
Friday 01 May 2026  07:32:30 +0000 (0:00:00.027)       0:00:07.007 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : VMs not needed in case of Keysight API Server] ******************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.027)       0:00:07.034 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : VMs not needed in case of Keysight IxANVL] **********************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.027)       0:00:07.062 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Retrieve a list of the defined VMs] *****************************
Friday 01 May 2026  07:32:30 +0000 (0:00:00.027)       0:00:07.090 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Retrieve a list of the running VMs] *****************************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.452)       0:00:07.542 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Set vm_state_string according to ansible version] ***************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.233)       0:00:07.776 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Print ansible version and vm_state_string] **********************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.030)       0:00:07.806 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "ansible version is 2.8.12 and vm_state_string is pause"
}

TASK [vm_set : Retrieve a list of the paused VMs with status=pause] ************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.031)       0:00:07.838 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Require VMs as CEOS by default] *********************************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.235)       0:00:08.074 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check VM type] **************************************************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.028)       0:00:08.102 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Ensure /home/ubuntu/veos-vm exists] *****************************
Friday 01 May 2026  07:32:31 +0000 (0:00:00.030)       0:00:08.133 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Install cleanup script] *****************************************
Friday 01 May 2026  07:32:32 +0000 (0:00:00.431)       0:00:08.564 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vm_resumer.py to the /home/ubuntu/veos-vm] *****************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.853)       0:00:09.418 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.644)       0:00:10.062 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.034)       0:00:10.097 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Limit VM] *******************************************************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.037)       0:00:10.134 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Generate vm list of target VMs] *********************************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.031)       0:00:10.166 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set fallback default value for VM_targets] **********************
Friday 01 May 2026  07:32:33 +0000 (0:00:00.030)       0:00:10.197 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Set vm configuration properties when configuration is defined] ***
Friday 01 May 2026  07:32:33 +0000 (0:00:00.036)       0:00:10.233 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set vm configuration properties when configuration is not defined] ***
Friday 01 May 2026  07:32:33 +0000 (0:00:00.030)       0:00:10.263 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Stop VMs] *******************************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.035)       0:00:10.298 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start VMs] ******************************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.031)       0:00:10.330 ************ 
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start.yml for STR-ACS-VSERV-01

TASK [vm_set : Require VMs as CEOS by default] *********************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.118)       0:00:10.448 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Load topo variables] ********************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.032)       0:00:10.481 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pick provided max num of fp] ************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.047)       0:00:10.528 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : debug] **********************************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.035)       0:00:10.564 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "max_fp_num 6"
}

TASK [vm_set : Filter VMs for specified topology] ******************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.033)       0:00:10.597 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Create directory for vm images and vm disks] ********************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.040)       0:00:10.638 ************ 
ok: [STR-ACS-VSERV-01] => (item=/home/ubuntu/veos-vm/images)
ok: [STR-ACS-VSERV-01] => (item=/home/ubuntu/veos-vm/disks)

TASK [vm_set : Check hdd image] ************************************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.390)       0:00:11.028 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if skip_veos_image_downloading is true] ********************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.033)       0:00:11.061 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init veos_hdd_image_urls when veos_hdd_image_url value type is string] ***
Friday 01 May 2026  07:32:34 +0000 (0:00:00.032)       0:00:11.093 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init veos_hdd_image_urls when veos_hdd_image_url value type is list] ***
Friday 01 May 2026  07:32:34 +0000 (0:00:00.031)       0:00:11.125 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init working_image_urls list] ***********************************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.032)       0:00:11.158 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Loop veos_hdd_image_urls to find out working URLs] **************
Friday 01 May 2026  07:32:34 +0000 (0:00:00.033)       0:00:11.191 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if no working veos hdd image download url is found] ********
Friday 01 May 2026  07:32:34 +0000 (0:00:00.033)       0:00:11.224 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Download veos hdd image from the first URL in working_image_urls] ***
Friday 01 May 2026  07:32:34 +0000 (0:00:00.032)       0:00:11.257 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cd image] *************************************************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.289 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if skip_veos_image_downloading is true] ********************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.321 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init veos_cd_image_urls when veos_cd_image_url value type is string] ***
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.354 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init veos_cd_image_urls when veos_cd_image_url value type is list] ***
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.386 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init working_image_urls list] ***********************************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.418 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Loop veos_cd_image_urls to find out working URLs] ***************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.031)       0:00:11.450 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if no working veos cd image download url is found] *********
Friday 01 May 2026  07:32:35 +0000 (0:00:00.034)       0:00:11.484 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Download veos cd image from the first URL in working_image_urls] ***
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.516 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.032)       0:00:11.549 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check SONiC image] **********************************************
Friday 01 May 2026  07:32:35 +0000 (0:00:00.034)       0:00:11.584 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if skip_vsonic_image_downloading is true] ******************
Friday 01 May 2026  07:32:41 +0000 (0:00:06.203)       0:00:17.788 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init vsonic_image_urls when vsonic_image_url value type is string] ***
Friday 01 May 2026  07:32:41 +0000 (0:00:00.037)       0:00:17.825 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init vsonic_image_urls when vsonic_image_url value type is list] ***
Friday 01 May 2026  07:32:41 +0000 (0:00:00.035)       0:00:17.861 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init working_image_urls list] ***********************************
Friday 01 May 2026  07:32:41 +0000 (0:00:00.035)       0:00:17.897 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Loop vsonic_image_urls to find out working URLs] ****************
Friday 01 May 2026  07:32:41 +0000 (0:00:00.036)       0:00:17.933 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if no working SONiC image download url is found] ***********
Friday 01 May 2026  07:32:41 +0000 (0:00:00.038)       0:00:17.971 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Download SONiC image from the first URL in working_image_urls] ***
Friday 01 May 2026  07:32:41 +0000 (0:00:00.036)       0:00:18.007 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Get downloaded SONiC image info] ********************************
Friday 01 May 2026  07:32:41 +0000 (0:00:00.035)       0:00:18.043 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Get downloaded SONiC image info] ********************************
Friday 01 May 2026  07:32:41 +0000 (0:00:00.034)       0:00:18.078 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Rename file to have a .gz suffix] *******************************
Friday 01 May 2026  07:32:48 +0000 (0:00:06.313)       0:00:24.391 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Decompress file] ************************************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.037)       0:00:24.428 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.036)       0:00:24.465 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco image] **********************************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.037)       0:00:24.503 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if skip_vcisco_image_downloading is true] ******************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.535 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init vcisco_image_urls when vcisco_image_url value type is string] ***
Friday 01 May 2026  07:32:48 +0000 (0:00:00.031)       0:00:24.566 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init vcisco_image_urls when vcisco_image_url value type is list] ***
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.598 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Init working_image_urls list] ***********************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.631 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Loop vcisco_image_urls to find out working URLs] ****************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.664 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if no working cisco image download url is found] ***********
Friday 01 May 2026  07:32:48 +0000 (0:00:00.034)       0:00:24.698 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Download cisco image from the first URL in working_image_urls] ***
Friday 01 May 2026  07:32:48 +0000 (0:00:00.034)       0:00:24.732 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.765 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Create VMs network] *********************************************
Friday 01 May 2026  07:32:48 +0000 (0:00:00.032)       0:00:24.798 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Default autostart to no when it is not defined] *****************
Friday 01 May 2026  07:32:57 +0000 (0:00:08.990)       0:00:33.788 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Default batch_size to 1 when it is not defined] *****************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.037)       0:00:33.826 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Default wait interval to 0 if it is not defined] ****************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.035)       0:00:33.862 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Start VMs] ******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.037)       0:00:33.899 ************ 
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/start_vm.yml for STR-ACS-VSERV-01

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.188)       0:00:34.088 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.034)       0:00:34.122 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.038)       0:00:34.161 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.032)       0:00:34.194 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:57 +0000 (0:00:00.034)       0:00:34.228 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.037)       0:00:34.265 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.035)       0:00:34.301 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.035)       0:00:34.336 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.039)       0:00:34.376 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.041)       0:00:34.417 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.039)       0:00:34.457 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0100 host internal name = PE1 sonic_password = password vm_type = vsonic serial port = 7000 ip = 10.250.0.51 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.046)       0:00:34.504 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0100] ******************************
Friday 01 May 2026  07:32:58 +0000 (0:00:00.207)       0:00:34.711 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0100, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:33:17 +0000 (0:00:19.146)       0:00:53.858 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0100 if it requires fix] ***************************
Friday 01 May 2026  07:33:57 +0000 (0:00:39.463)       0:01:33.322 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0100] ************************************************
Friday 01 May 2026  07:33:57 +0000 (0:00:00.038)       0:01:33.361 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:05.488)       0:01:38.849 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.045)       0:01:38.895 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.035)       0:01:38.930 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.031)       0:01:38.962 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.041)       0:01:39.003 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.037)       0:01:39.040 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.037)       0:01:39.078 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.035)       0:01:39.113 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.035)       0:01:39.148 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.036)       0:01:39.185 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:34:02 +0000 (0:00:00.039)       0:01:39.224 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:03 +0000 (0:00:00.045)       0:01:39.269 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:34:03 +0000 (0:00:00.043)       0:01:39.313 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0101 host internal name = PE2 sonic_password = password vm_type = vsonic serial port = 7001 ip = 10.250.0.52 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:34:03 +0000 (0:00:00.047)       0:01:39.361 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0101] ******************************
Friday 01 May 2026  07:34:03 +0000 (0:00:00.206)       0:01:39.568 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0101, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:34:43 +0000 (0:00:40.224)       0:02:19.793 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0101 if it requires fix] ***************************
Friday 01 May 2026  07:34:47 +0000 (0:00:03.882)       0:02:23.675 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0101] ************************************************
Friday 01 May 2026  07:34:47 +0000 (0:00:00.046)       0:02:23.721 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:34:50 +0000 (0:00:03.485)       0:02:27.207 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:34:50 +0000 (0:00:00.042)       0:02:27.250 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.037)       0:02:27.287 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.036)       0:02:27.324 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.043)       0:02:27.367 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.035)       0:02:27.403 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.042)       0:02:27.445 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.035)       0:02:27.480 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.037)       0:02:27.517 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.037)       0:02:27.555 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.049)       0:02:27.605 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.047)       0:02:27.653 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.045)       0:02:27.698 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0102 host internal name = PE3 sonic_password = password vm_type = vsonic serial port = 7002 ip = 10.250.0.53 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.049)       0:02:27.747 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0102] ******************************
Friday 01 May 2026  07:34:51 +0000 (0:00:00.214)       0:02:27.962 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0102, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:35:47 +0000 (0:00:55.786)       0:03:23.748 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0102 if it requires fix] ***************************
Friday 01 May 2026  07:35:49 +0000 (0:00:02.205)       0:03:25.954 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0102] ************************************************
Friday 01 May 2026  07:35:49 +0000 (0:00:00.041)       0:03:25.995 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:03.655)       0:03:29.651 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.071)       0:03:29.722 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.040)       0:03:29.762 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.039)       0:03:29.802 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.047)       0:03:29.849 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.038)       0:03:29.887 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.043)       0:03:29.930 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.037)       0:03:29.967 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.039)       0:03:30.006 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.047)       0:03:30.054 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.045)       0:03:30.100 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.052)       0:03:30.153 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.046)       0:03:30.200 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0103 host internal name = P3 sonic_password = password vm_type = vsonic serial port = 7003 ip = 10.250.0.54 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:35:53 +0000 (0:00:00.052)       0:03:30.252 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0103] ******************************
Friday 01 May 2026  07:35:54 +0000 (0:00:00.221)       0:03:30.473 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0103, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:36:45 +0000 (0:00:51.771)       0:04:22.244 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0103 if it requires fix] ***************************
Friday 01 May 2026  07:36:49 +0000 (0:00:03.078)       0:04:25.323 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0103] ************************************************
Friday 01 May 2026  07:36:49 +0000 (0:00:00.041)       0:04:25.364 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:36:52 +0000 (0:00:03.762)       0:04:29.126 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:36:52 +0000 (0:00:00.042)       0:04:29.169 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:52 +0000 (0:00:00.039)       0:04:29.209 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:52 +0000 (0:00:00.034)       0:04:29.244 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.042)       0:04:29.287 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.035)       0:04:29.322 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.040)       0:04:29.362 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.035)       0:04:29.398 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.052)       0:04:29.450 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.042)       0:04:29.492 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.050)       0:04:29.543 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.052)       0:04:29.595 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.048)       0:04:29.644 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0104 host internal name = P2 sonic_password = password vm_type = vsonic serial port = 7004 ip = 10.250.0.55 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.058)       0:04:29.702 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0104] ******************************
Friday 01 May 2026  07:36:53 +0000 (0:00:00.229)       0:04:29.932 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0104, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:37:40 +0000 (0:00:46.668)       0:05:16.601 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0104 if it requires fix] ***************************
Friday 01 May 2026  07:37:47 +0000 (0:00:07.231)       0:05:23.832 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0104] ************************************************
Friday 01 May 2026  07:37:47 +0000 (0:00:00.039)       0:05:23.871 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:05.507)       0:05:29.379 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.058)       0:05:29.438 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.055)       0:05:29.493 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.047)       0:05:29.540 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.054)       0:05:29.595 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.039)       0:05:29.634 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.042)       0:05:29.677 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.033)       0:05:29.710 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Find current server group] **************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.036)       0:05:29.747 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Extract VM names from the inventory] ****************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.040)       0:05:29.787 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Generate hostname for target VM] ********************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.059)       0:05:29.846 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.046)       0:05:29.892 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Device debug output] ********************************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.044)       0:05:29.937 ************ 
ok: [STR-ACS-VSERV-01] => {
    "msg": "hostname = VM0105 host internal name = P4 sonic_password = password vm_type = vsonic serial port = 7005 ip = 10.250.0.56 hwsku = cisco-8101-p4-32x100-vs"
}

TASK [vm_set : Check destination file existance] *******************************
Friday 01 May 2026  07:37:53 +0000 (0:00:00.052)       0:05:29.989 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Copy vsonic disk image for VM0105] ******************************
Friday 01 May 2026  07:37:54 +0000 (0:00:00.309)       0:05:30.299 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Define vm VM0105, hwsku cisco-8101-p4-32x100-vs] ****************
Friday 01 May 2026  07:38:46 +0000 (0:00:52.502)       0:06:22.802 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0105 if it requires fix] ***************************
Friday 01 May 2026  07:38:56 +0000 (0:00:09.634)       0:06:32.436 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm VM0105] ************************************************
Friday 01 May 2026  07:38:56 +0000 (0:00:00.039)       0:06:32.476 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Find out VM index] **********************************************
Friday 01 May 2026  07:39:01 +0000 (0:00:05.700)       0:06:38.176 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Pause after started every 6 VMs] ********************************
Friday 01 May 2026  07:39:01 +0000 (0:00:00.044)       0:06:38.221 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.071)       0:06:38.293 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart VMs] **************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.047)       0:06:38.340 ************ 
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01
included: /data/sonic-mgmt/ansible/roles/vm_set/tasks/kickstart_vm.yml for STR-ACS-VSERV-01

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.430)       0:06:38.771 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.038)       0:06:38.810 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.056)       0:06:38.866 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0100 is loaded] *********************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.043)       0:06:38.909 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.041)       0:06:38.951 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0100] *******************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.038)       0:06:38.989 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.043)       0:06:39.033 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.036)       0:06:39.070 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0100 is loaded] *********************************
Friday 01 May 2026  07:39:02 +0000 (0:00:00.073)       0:06:39.143 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0100 if it hangs] **********************************
Friday 01 May 2026  07:39:08 +0000 (0:00:05.797)       0:06:44.941 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0100] ******************************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.060)       0:06:45.001 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0100 is loaded] *********************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.044)       0:06:45.046 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0100] **************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.055)       0:06:45.102 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.047)       0:06:45.150 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0100 is loaded] *********************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.050)       0:06:45.200 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0100] ***********************************************
Friday 01 May 2026  07:39:08 +0000 (0:00:00.040)       0:06:45.241 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.039)       0:06:45.281 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.138)       0:06:45.420 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0100 reachablity] *********************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.066)       0:06:45.487 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0100] ****************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.048)       0:06:45.536 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0100 reachablity] **************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.049)       0:06:45.585 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0100] *******************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.039)       0:06:45.625 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.036)       0:06:45.661 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.039)       0:06:45.701 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.034)       0:06:45.735 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.065)       0:06:45.801 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0101 is loaded] *********************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.047)       0:06:45.849 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.049)       0:06:45.898 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0101] *******************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.047)       0:06:45.945 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.038)       0:06:45.984 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.042)       0:06:46.027 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0101 is loaded] *********************************
Friday 01 May 2026  07:39:09 +0000 (0:00:00.056)       0:06:46.083 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0101 if it hangs] **********************************
Friday 01 May 2026  07:39:15 +0000 (0:00:05.896)       0:06:51.979 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0101] ******************************************
Friday 01 May 2026  07:39:15 +0000 (0:00:00.078)       0:06:52.057 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0101 is loaded] *********************************
Friday 01 May 2026  07:39:15 +0000 (0:00:00.057)       0:06:52.114 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0101] **************************
Friday 01 May 2026  07:39:15 +0000 (0:00:00.091)       0:06:52.206 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.095)       0:06:52.301 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0101 is loaded] *********************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.103)       0:06:52.405 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0101] ***********************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.074)       0:06:52.479 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.088)       0:06:52.567 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.067)       0:06:52.635 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0101 reachablity] *********************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.086)       0:06:52.721 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0101] ****************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.068)       0:06:52.790 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0101 reachablity] **************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.094)       0:06:52.885 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0101] *******************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.072)       0:06:52.957 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.060)       0:06:53.018 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.053)       0:06:53.072 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.062)       0:06:53.135 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.049)       0:06:53.184 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0102 is loaded] *********************************
Friday 01 May 2026  07:39:16 +0000 (0:00:00.076)       0:06:53.261 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:17 +0000 (0:00:00.036)       0:06:53.298 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0102] *******************
Friday 01 May 2026  07:39:17 +0000 (0:00:00.057)       0:06:53.355 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:17 +0000 (0:00:00.051)       0:06:53.407 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:17 +0000 (0:00:00.035)       0:06:53.442 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0102 is loaded] *********************************
Friday 01 May 2026  07:39:17 +0000 (0:00:00.071)       0:06:53.514 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0102 if it hangs] **********************************
Friday 01 May 2026  07:39:22 +0000 (0:00:05.032)       0:06:58.547 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0102] ******************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.072)       0:06:58.620 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0102 is loaded] *********************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.067)       0:06:58.687 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0102] **************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.063)       0:06:58.751 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.072)       0:06:58.824 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0102 is loaded] *********************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.071)       0:06:58.895 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0102] ***********************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.066)       0:06:58.961 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.054)       0:06:59.016 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.063)       0:06:59.079 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0102 reachablity] *********************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.066)       0:06:59.146 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0102] ****************************************
Friday 01 May 2026  07:39:22 +0000 (0:00:00.069)       0:06:59.215 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0102 reachablity] **************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.090)       0:06:59.306 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0102] *******************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.074)       0:06:59.381 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.064)       0:06:59.446 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.068)       0:06:59.514 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.059)       0:06:59.573 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.062)       0:06:59.636 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0103 is loaded] *********************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.079)       0:06:59.716 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.067)       0:06:59.783 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0103] *******************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.080)       0:06:59.864 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.069)       0:06:59.933 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.070)       0:07:00.004 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0103 is loaded] *********************************
Friday 01 May 2026  07:39:23 +0000 (0:00:00.100)       0:07:00.105 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0103 if it hangs] **********************************
Friday 01 May 2026  07:39:31 +0000 (0:00:07.793)       0:07:07.898 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0103] ******************************************
Friday 01 May 2026  07:39:31 +0000 (0:00:00.089)       0:07:07.988 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0103 is loaded] *********************************
Friday 01 May 2026  07:39:31 +0000 (0:00:00.088)       0:07:08.076 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0103] **************************
Friday 01 May 2026  07:39:31 +0000 (0:00:00.086)       0:07:08.163 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:31 +0000 (0:00:00.080)       0:07:08.244 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0103 is loaded] *********************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.084)       0:07:08.329 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0103] ***********************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.082)       0:07:08.411 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.075)       0:07:08.487 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.072)       0:07:08.559 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0103 reachablity] *********************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.095)       0:07:08.655 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0103] ****************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.097)       0:07:08.753 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0103 reachablity] **************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.072)       0:07:08.825 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0103] *******************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.073)       0:07:08.899 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.052)       0:07:08.952 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.072)       0:07:09.024 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.066)       0:07:09.090 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.051)       0:07:09.142 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0104 is loaded] *********************************
Friday 01 May 2026  07:39:32 +0000 (0:00:00.087)       0:07:09.230 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:33 +0000 (0:00:00.069)       0:07:09.300 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0104] *******************
Friday 01 May 2026  07:39:33 +0000 (0:00:00.072)       0:07:09.373 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:33 +0000 (0:00:00.068)       0:07:09.441 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:33 +0000 (0:00:00.066)       0:07:09.508 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0104 is loaded] *********************************
Friday 01 May 2026  07:39:33 +0000 (0:00:00.098)       0:07:09.606 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0104 if it hangs] **********************************
Friday 01 May 2026  07:39:42 +0000 (0:00:09.341)       0:07:18.948 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0104] ******************************************
Friday 01 May 2026  07:39:42 +0000 (0:00:00.058)       0:07:19.007 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0104 is loaded] *********************************
Friday 01 May 2026  07:39:42 +0000 (0:00:00.079)       0:07:19.086 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0104] **************************
Friday 01 May 2026  07:39:42 +0000 (0:00:00.066)       0:07:19.153 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:42 +0000 (0:00:00.066)       0:07:19.219 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0104 is loaded] *********************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.077)       0:07:19.297 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0104] ***********************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.072)       0:07:19.369 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.068)       0:07:19.438 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.067)       0:07:19.505 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0104 reachablity] *********************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.085)       0:07:19.590 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0104] ****************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.066)       0:07:19.657 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0104 reachablity] **************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.079)       0:07:19.737 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0104] *******************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.062)       0:07:19.800 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.060)       0:07:19.861 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.069)       0:07:19.931 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.057)       0:07:19.988 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.064)       0:07:20.052 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0105 is loaded] *********************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.086)       0:07:20.138 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm] ***********************************************
Friday 01 May 2026  07:39:43 +0000 (0:00:00.063)       0:07:20.202 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0105] *******************
Friday 01 May 2026  07:39:44 +0000 (0:00:00.065)       0:07:20.268 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:39:44 +0000 (0:00:00.064)       0:07:20.332 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : set_fact] *******************************************************
Friday 01 May 2026  07:39:44 +0000 (0:00:00.058)       0:07:20.391 ************ 
ok: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0105 is loaded] *********************************
Friday 01 May 2026  07:39:44 +0000 (0:00:00.090)       0:07:20.481 ************ 
changed: [STR-ACS-VSERV-01]

TASK [vm_set : Destroy vm VM0105 if it hangs] **********************************
Friday 01 May 2026  07:40:05 +0000 (0:00:21.279)       0:07:41.761 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start vm again VM0105] ******************************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.086)       0:07:41.848 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0105 is loaded] *********************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.056)       0:07:41.904 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error again vm VM0105] **************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.075)       0:07:41.980 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.071)       0:07:42.051 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Wait until vm VM0105 is loaded] *********************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.076)       0:07:42.128 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin vm VM0105] ***********************************************
Friday 01 May 2026  07:40:05 +0000 (0:00:00.073)       0:07:42.201 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set cisco vm host] **********************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.064)       0:07:42.266 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add cisco vm host] **********************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.062)       0:07:42.329 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check cisco VM0105 reachablity] *********************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.083)       0:07:42.413 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Respin failed vm VM0105] ****************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.065)       0:07:42.479 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Check failed cisco VM0105 reachablity] **************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.080)       0:07:42.559 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Kickstart gives error after respin vm VM0105] *******************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.065)       0:07:42.624 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Set VM to autostart] ********************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.068)       0:07:42.693 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Log all kickstart failed VMs] ***********************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.065)       0:07:42.758 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Fail if kickstart any VM failed] ********************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.062)       0:07:42.820 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Connect VMs] ****************************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.063)       0:07:42.883 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Disconnect VMs] *************************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.065)       0:07:42.949 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Renumber topology] **********************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.064)       0:07:43.014 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Add topology] ***************************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.062)       0:07:43.077 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Remove topology] ************************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.059)       0:07:43.136 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Stop Kubernetes VMs] ********************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.057)       0:07:43.194 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Start Kubernetes VMs] *******************************************
Friday 01 May 2026  07:40:06 +0000 (0:00:00.064)       0:07:43.259 ************ 
skipping: [STR-ACS-VSERV-01]

TASK [vm_set : Manage the dut state] *******************************************
Friday 01 May 2026  07:40:07 +0000 (0:00:00.061)       0:07:43.320 ************ 
skipping: [STR-ACS-VSERV-01]

PLAY RECAP *********************************************************************
STR-ACS-VSERV-01           : ok=159  changed=29   unreachable=0    failed=0    skipped=212  rescued=0    ignored=0   

Friday 01 May 2026  07:40:07 +0000 (0:00:00.055)       0:07:43.375 ************ 
=============================================================================== 
vm_set : Copy vsonic disk image for VM0102 ----------------------------- 55.79s
vm_set : Copy vsonic disk image for VM0105 ----------------------------- 52.50s
vm_set : Copy vsonic disk image for VM0103 ----------------------------- 51.77s
vm_set : Copy vsonic disk image for VM0104 ----------------------------- 46.67s
vm_set : Copy vsonic disk image for VM0101 ----------------------------- 40.22s
vm_set : Define vm VM0100, hwsku cisco-8101-p4-32x100-vs --------------- 39.46s
vm_set : Wait until vm VM0105 is loaded -------------------------------- 21.28s
vm_set : Copy vsonic disk image for VM0100 ----------------------------- 19.15s
vm_set : Define vm VM0105, hwsku cisco-8101-p4-32x100-vs ---------------- 9.63s
vm_set : Wait until vm VM0104 is loaded --------------------------------- 9.34s
vm_set : Create VMs network --------------------------------------------- 8.99s
vm_set : Wait until vm VM0103 is loaded --------------------------------- 7.79s
vm_set : Define vm VM0104, hwsku cisco-8101-p4-32x100-vs ---------------- 7.23s
vm_set : Get downloaded SONiC image info -------------------------------- 6.31s
vm_set : Check SONiC image ---------------------------------------------- 6.20s
vm_set : Wait until vm VM0101 is loaded --------------------------------- 5.90s
vm_set : Wait until vm VM0100 is loaded --------------------------------- 5.80s
vm_set : Start vm VM0105 ------------------------------------------------ 5.70s
vm_set : Start vm VM0104 ------------------------------------------------ 5.51s
vm_set : Start vm VM0100 ------------------------------------------------ 5.49s
{'conf-name': 'vms-kvm-four-asic-t1-lag', 'group-name': 'vms6-4', 'topo': 't1-8-lag', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-05', 'ptf_ip': '10.250.0.110/24', 'ptf_ipv6': 'fec0::ffff:afa:a/64', 'server': 'server_1', 'vm_base': 'VM0128', 'dut': ['vlab-08'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests multi-asic virtual switch vm'}
{'conf-name': 'vms-kvm-t2', 'group-name': 'vms6-4', 'topo': 't2-vs', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-04', 'ptf_ip': '10.250.0.109/24', 'ptf_ipv6': 'fec0::ffff:afa:9/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-t2-01', 'vlab-t2-02', 'vlab-t2-sup'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'T2 Virtual chassis'}
{'conf-name': 'vms-kvm-t0-3', 'group-name': 'vms6-6', 'topo': 't0', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-06', 'ptf_ip': '10.250.0.116/24', 'ptf_ipv6': 'fec0::ffff:afb:2/64', 'server': 'server_1', 'vm_base': 'VM0132', 'dut': ['vlab-09'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-t0-4', 'group-name': 'vms6-7', 'topo': 't0', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-07', 'ptf_ip': '10.250.0.118/24', 'ptf_ipv6': 'fec0::ffff:afb:4/64', 'server': 'server_1', 'vm_base': 'VM0136', 'dut': ['vlab-10'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-dual-mixed', 'group-name': 'vms6-8', 'topo': 'dualtor-mixed', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-08', 'ptf_ip': '10.250.0.119/24', 'ptf_ipv6': 'fec0::ffff:afa:9/64', 'netns_mgmt_ip': '10.250.0.126/24', 'server': 'server_1', 'vm_base': 'VM0140', 'dut': ['vlab-11', 'vlab-12'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Dual-TOR-Mixed testbed'}
{'conf-name': '8000e-t0', 'group-name': 'vms8-1', 'topo': 't0', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-8k-01', 'ptf_ip': '10.250.0.202/24', 'ptf_ipv6': 'fec0::ffff:afc:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-8k-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests 8000e sonic device'}
{'conf-name': '8000e-t1', 'group-name': 'vms8-1', 'topo': 't1', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-8k-01', 'ptf_ip': '10.250.0.202/24', 'ptf_ipv6': 'fec0::ffff:afc:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-8k-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests 8000e sonic device'}
{'conf-name': 'vms-kvm-wan-pub', 'group-name': 'vms6-1', 'topo': 'wan-pub', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-4link', 'group-name': 'vms6-1', 'topo': 'wan-4link', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-pub-cisco', 'group-name': 'vms6-1', 'topo': 'wan-pub-cisco', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-2dut', 'group-name': 'vms6-1', 'topo': 'wan-2dut', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01', 'vlab-03'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-3link-tg', 'group-name': 'vms6-1', 'topo': 'wan-3link-tg', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-ecmp', 'group-name': 'vms6-1', 'topo': 'wan-ecmp', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01', 'vlab-02'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-wan-pub-isis', 'group-name': 'vms6-1', 'topo': 'wan-pub-isis', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual switch vm'}
{'conf-name': 'vms-kvm-dpu', 'group-name': 'vms6-1', 'topo': 'dpu', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-01'], 'inv_name': 'veos_vtb', 'auto_recover': False, 'comment': 'Tests virtual switch vm as DPU'}
{'conf-name': 'vms-kvm-ciscovs-7nodes', 'group-name': 'vms9-1', 'topo': 'ciscovs-7nodes', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-c-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual cisco vs vm with 7 nodes'}
{'conf-name': 'vms-kvm-ciscovs-5nodes', 'group-name': 'vms9-1', 'topo': 'ciscovs-5nodes', 'ptf_image_name': 'docker-ptf', 'ptf': 'ptf-01', 'ptf_ip': '10.250.0.102/24', 'ptf_ipv6': 'fec0::ffff:afa:2/64', 'server': 'server_1', 'vm_base': 'VM0100', 'dut': ['vlab-c-01'], 'inv_name': 'veos_vtb', 'auto_recover': 'False', 'comment': 'Tests virtual cisco vs vm with 5 nodes'}
2026-05-01 00:32:21.330118 : /home/super/workspace/PhoenixWingDailySRv6Test/na_lab/pytest_env/../..//sonic-mgmt/ansible/vars/topo_ciscovs-7nodes.yml : vms_yml {'PE1': {'vlans': [28], 'vm_offset': 0}, 'PE2': {'vlans': [29], 'vm_offset': 1}, 'PE3': {'vlans': [30], 'vm_offset': 2}, 'P3': {'vlans': [31], 'vm_offset': 3}, 'P2': {'vlans': [16], 'vm_offset': 4}, 'P4': {'vlans': [17], 'vm_offset': 5}}, len 6
2026-05-01 00:32:21.330258 : Get input topo vms-kvm-ciscovs-7nodes
2026-05-01 00:32:21.330278 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "docker exec --user ubuntu  sonic-mgmt-test bash -c 'cd /data/sonic-mgmt/ansible;  export PACKAGE_INSTALLATION=false; ./testbed-cli.sh -t vtestbed.yaml -m veos_vtb  -k vsonic  start-topo-vms vms-kvm-ciscovs-7nodes password.txt'"
2026-05-01 00:40:07.289634 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl stop apt-daily.timer"
2026-05-01 00:40:08.514811 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl stop apt-daily-upgrade.timer"
2026-05-01 00:40:10.001872 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl stop apt-daily.service"
2026-05-01 00:40:11.441807 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl stop apt-daily-upgrade.service"
2026-05-01 00:40:12.941999 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl disable apt-daily.timer"
2026-05-01 00:40:15.300923 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl disable apt-daily-upgrade.timer"
2026-05-01 00:40:17.542624 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl disable apt-daily.service"
 Id   Name     State
------------------------
 1    VM0100   running
 2    VM0101   running
 3    VM0102   running
 4    VM0103   running
 5    VM0104   running
 6    VM0105   running

CONTAINER ID   IMAGE                             COMMAND       CREATED         STATUS         PORTS     NAMES
41c4230d5d56   docker-sonic-mgmt-ubuntu:master   "/bin/bash"   8 minutes ago   Up 8 minutes   22/tcp    sonic-mgmt-test
2026-05-01 00:40:19.517948 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl mask apt-daily.service"
2026-05-01 00:40:21.691217 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl mask apt-daily-upgrade.service"
2026-05-01 00:40:23.840308 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo systemctl mask openvswitch-switch.service"
2026-05-01 00:40:25.979473 : Sleep 10 second
2026-05-01 00:40:35.987126 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo virsh list; docker ps -a"
2026-05-01 00:40:37.590254 : sshpass -p "123" ssh   -q -o "UserKnownHostsFile=/dev/null" -o "StrictHostKeyChecking=no" ubuntu@192.168.0.2 "sudo virsh list | grep VM"
2026-05-01 00:40:39.313564 : DEBUG_ARR:  1    VM0100   running
2026-05-01 00:40:39.313628 : DEBUG_ARR:  2    VM0101   running
2026-05-01 00:40:39.313643 : DEBUG_ARR:  3    VM0102   running
2026-05-01 00:40:39.313650 : DEBUG_ARR:  4    VM0103   running
2026-05-01 00:40:39.313661 : DEBUG_ARR:  5    VM0104   running
2026-05-01 00:40:39.313672 : DEBUG_ARR:  6    VM0105   running
{"Set up Test nodes' VMs in pytest VM": 917.880229473114}
2026-05-01 00:40:49.323107 : Brought up needed test nodess
2026-05-01 00:40:49.323184 : rm -rf /tmp/local_cache//1777620320.4260683/
--- 928.9017233848572 seconds ---
