is in ACTIVE state now
2025-12-25 03:57:08,459 - INFO - VM name : ctest-TestSubInterfaces-39274012-94865674
2025-12-25 03:57:08,556 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 ID is 4f3b66aa-4c10-4c43-ba91-36bb6e3c709a
2025-12-25 03:57:08,556 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 launched on Node an-jenkins-deploy-platform-ansible-os-4927-1
2025-12-25 03:57:08,656 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/4f3b66aa-4c10-4c43-ba91-36bb6e3c709a
2025-12-25 03:57:08,669 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/1441d1d4-ee48-4e9e-b79e-72b743b545f4
2025-12-25 03:57:11,859 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms')
2025-12-25 03:57:11,859 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 failed!
2025-12-25 03:57:11,873 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-39274012:ctest-vn-66599979 is 67.208.44.193 and allocation pool is NOT set
2025-12-25 03:57:15,953 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms')
2025-12-25 03:57:15,953 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 failed!
2025-12-25 03:57:15,970 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-39274012:ctest-vn-66599979 is 67.208.44.193 and allocation pool is NOT set
2025-12-25 03:57:20,048 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2025-12-25 03:57:20,048 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 failed!
2025-12-25 03:57:20,066 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-39274012:ctest-vn-66599979 is 67.208.44.193 and allocation pool is NOT set
2025-12-25 03:57:24,147 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2025-12-25 03:57:24,147 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 failed!
2025-12-25 03:57:24,166 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-39274012:ctest-vn-66599979 is 67.208.44.193 and allocation pool is NOT set
2025-12-25 03:57:28,241 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms')
2025-12-25 03:57:28,241 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 failed!
2025-12-25 03:57:28,269 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-39274012:ctest-vn-66599979 is 67.208.44.193 and allocation pool is NOT set
2025-12-25 03:57:32,373 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=31.9 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1032ms\r\nrtt min/avg/max/mdev = 31.902/31.902/31.902/0.000 ms')
2025-12-25 03:57:32,373 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-39274012-94865674 passed
2025-12-25 03:57:32,447 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:32,448 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:32,520 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:32,622 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:57:37,623 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:37,623 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:37,691 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:37,800 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:57:42,801 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:42,801 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:42,867 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:42,965 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:57:47,965 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:47,965 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:48,032 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:48,135 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:57:53,135 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:53,136 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:53,224 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:53,324 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:57:58,325 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:57:58,325 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:57:58,402 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:57:58,502 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:03,503 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:03,503 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:03,573 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:58:03,714 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:08,715 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:08,715 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:08,783 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:58:08,888 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:13,889 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:13,889 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:13,955 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:58:14,064 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:19,065 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:19,065 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:19,135 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:58:19,237 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:24,238 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:24,238 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:24,307 - DEBUG - Error on ssh to ubuntu@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-25 03:58:24,406 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-25 03:58:29,407 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:58:29,407 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-39274012-94865674, IP 67.208.44.197, Port 22
2025-12-25 03:58:29,579 - DEBUG - VM ctest-TestSubInterfaces-39274012-94865674 is ready for SSH connections
2025-12-25 03:58:29,579 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 9.54.106.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:58:29,580 - DEBUG - ifconfig -a| grep 9.54.106.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-12-25 03:59:16,044 - DEBUG - eth0.100
2025-12-25 03:59:16,044 - INFO - Interface eth0.100 is found on VM 4febaa2f-ecf2-4e7b-9162-5f586bbd9874
2025-12-25 03:59:16,044 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 126.254.45.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:59:16,044 - DEBUG - ifconfig -a| grep 126.254.45.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2025-12-25 03:59:55,986 - DEBUG - eth0.100
2025-12-25 03:59:55,986 - INFO - Interface eth0.100 is found on VM 4f3b66aa-4c10-4c43-ba91-36bb6e3c709a
2025-12-25 03:59:55,986 - DEBUG - Running remote_cmd, Cmd : route add -net 126.254.45.128/26 dev eth0.100, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:59:55,986 - DEBUG - route add -net 126.254.45.128/26 dev eth0.100
2025-12-25 03:59:56,637 - DEBUG - None
2025-12-25 03:59:56,637 - DEBUG - Running remote_cmd, Cmd : route add -net 9.54.106.64/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:59:56,637 - DEBUG - route add -net 9.54.106.64/26 dev eth0.100
2025-12-25 03:59:57,233 - DEBUG - None
2025-12-25 03:59:57,233 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-25 03:59:57,233 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.254.45.132, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:59:57,233 - DEBUG - ping -s 56 -c 3 -W 1 126.254.45.132
2025-12-25 03:59:59,794 - DEBUG - PING 126.254.45.132 (126.254.45.132) 56(84) bytes of data.
64 bytes from 126.254.45.132: icmp_req=1 ttl=63 time=27.3 ms
64 bytes from 126.254.45.132: icmp_req=2 ttl=63 time=1.41 ms
64 bytes from 126.254.45.132: icmp_req=3 ttl=63 time=1.19 ms
--- 126.254.45.132 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2005ms
rtt min/avg/max/mdev = 1.198/9.987/27.351/12.278 ms
2025-12-25 03:59:59,795 - INFO - Ping to IP 126.254.45.132 from VM ctest-TestSubInterfaces-39274012-71189195 passed
2025-12-25 03:59:59,795 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.254.45.131, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2025-12-25 03:59:59,795 - DEBUG - ping -s 56 -c 3 -W 1 126.254.45.131
2025-12-25 04:00:02,433 - DEBUG - PING 126.254.45.131 (126.254.45.131) 56(84) bytes of data.
64 bytes from 126.254.45.131: icmp_req=1 ttl=63 time=13.6 ms
64 bytes from 126.254.45.131: icmp_req=2 ttl=63 time=1.18 ms
64 bytes from 126.254.45.131: icmp_req=3 ttl=63 time=0.919 ms
--- 126.254.45.131 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 0.919/5.266/13.699/5.964 ms
2025-12-25 04:00:02,433 - INFO - Ping to IP 126.254.45.131 from VM ctest-TestSubInterfaces-39274012-71189195 passed
2025-12-25 04:00:02,433 - INFO - Deleting interface with subnet_id d6005049-d602-4cc7-9858-9e3c85a059c5, port_id None from router d7df37ef-dc63-43fc-9380-63b3cf768080
2025-12-25 04:00:02,771 - INFO - Deleting interface with subnet_id ad11affa-82a9-47fa-a6e0-c7bf2c5070df, port_id None from router d7df37ef-dc63-43fc-9380-63b3cf768080
2025-12-25 04:00:03,273 - INFO - Detaching port 1441d1d4-ee48-4e9e-b79e-72b743b545f4 from VM ctest-TestSubInterfaces-39274012-94865674
2025-12-25 04:00:03,408 - INFO - Deleting VM ctest-TestSubInterfaces-39274012-94865674
2025-12-25 04:00:03,579 - INFO - Deleting VM ctest-TestSubInterfaces-39274012-43028587
2025-12-25 04:00:03,688 - INFO - Detaching port c1027d33-5f0a-44e0-ba9f-edf3f83094fe from VM ctest-TestSubInterfaces-39274012-71189195
2025-12-25 04:00:03,741 - INFO - Deleting VM ctest-TestSubInterfaces-39274012-71189195
2025-12-25 04:00:05,210 - DEBUG - No XMPP flaps were noticed during the test
2025-12-25 04:00:05,210 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:04:18]
2025-12-25 04:00:05,210 - INFO - --------------------------------------------------------------------------------
2025-12-25 04:00:05,352 - INFO - Deleted port cc7167fc-2ea6-445f-971e-fda6af634fef
2025-12-25 04:00:05,612 - DEBUG - Response for delete_port : ()
2025-12-25 04:00:05,612 - INFO - Deleted port 1441d1d4-ee48-4e9e-b79e-72b743b545f4
2025-12-25 04:00:05,756 - INFO - Deleted port 4d112840-2f33-410d-977c-675a797f1862
2025-12-25 04:00:05,955 - DEBUG - Response for delete_port : ()
2025-12-25 04:00:05,955 - INFO - Deleted port 465d2de8-b98a-4732-8c42-ec0439525920
2025-12-25 04:00:06,100 - INFO - Deleted port 0f84521e-53e8-4a2c-81d4-5d785057b1e3
2025-12-25 04:00:06,372 - DEBUG - Response for delete_port : ()
2025-12-25 04:00:06,372 - INFO - Deleted port c1027d33-5f0a-44e0-ba9f-edf3f83094fe
2025-12-25 04:00:06,372 - INFO - Deleting VN ctest-vn-55540823
2025-12-25 04:00:06,677 - DEBUG - Response for deleting network ()
2025-12-25 04:00:06,677 - INFO - Deleting VN ctest-vn-66599979
2025-12-25 04:00:06,952 - DEBUG - Response for deleting network ()
2025-12-25 04:00:06,953 - INFO - Deleting VN ctest-vn-94203531
2025-12-25 04:00:07,227 - DEBUG - Response for deleting network ()
2025-12-25 04:00:08,162 - INFO - Deleted project: ctest-TestSubInterfaces-39274012, ID : 81a2da5a-4748-4a16-8cfc-343953e84a25