2026-06-08 03:55:15,579 - INFO - Domain Default found not creating
2026-06-08 03:55:15,779 - INFO - Project ctest-TestSubInterfaces-26176602 not found, creating it
2026-06-08 03:55:16,411 - INFO - Created Project:ctest-TestSubInterfaces-26176602, ID : 19a8c36c-0ada-4c62-9f8e-9f10fe7e0cef
2026-06-08 03:55:18,807 - DEBUG - Response for create_network : {'network': {'id': '64b7b9b3-0e28-4413-ad79-8efca636cf4a', 'name': 'ctest-vn-59214061', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vn-59214061'], 'port_security_enabled': True, 'description': ''}}
2026-06-08 03:55:19,084 - DEBUG - Response for create_subnet : {'subnet': {'id': '5a285dbb-cf36-46c8-933f-54b795ac713f', 'name': '', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '64b7b9b3-0e28-4413-ad79-8efca636cf4a', 'ip_version': 4, 'cidr': '11.110.67.128/26', 'allocation_pools': [{'start': '11.110.67.130', 'end': '11.110.67.190'}], 'gateway_ip': '11.110.67.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '11.110.67.130', 'tags': [], 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:19,112 - INFO - Created VN ctest-vn-59214061
2026-06-08 03:55:19,127 - DEBUG - VN ctest-vn-59214061 UUID is 64b7b9b3-0e28-4413-ad79-8efca636cf4a
2026-06-08 03:55:19,554 - DEBUG - Response for create_network : {'network': {'id': '1c78361f-1066-4360-9e1e-1b1fed93b25e', 'name': 'ctest-vn-73605685', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vn-73605685'], 'port_security_enabled': True, 'description': ''}}
2026-06-08 03:55:19,804 - DEBUG - Response for create_subnet : {'subnet': {'id': '59956ce5-cee9-4243-a531-56dbcbf77645', 'name': '', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '1c78361f-1066-4360-9e1e-1b1fed93b25e', 'ip_version': 4, 'cidr': '167.246.249.64/26', 'allocation_pools': [{'start': '167.246.249.66', 'end': '167.246.249.126'}], 'gateway_ip': '167.246.249.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '167.246.249.66', 'tags': [], 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:19,832 - INFO - Created VN ctest-vn-73605685
2026-06-08 03:55:19,847 - DEBUG - VN ctest-vn-73605685 UUID is 1c78361f-1066-4360-9e1e-1b1fed93b25e
2026-06-08 03:55:20,241 - DEBUG - Response for create_network : {'network': {'id': '2e1b093d-5616-4298-9956-e23b185ae4eb', 'name': 'ctest-vn-88241847', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vn-88241847'], 'port_security_enabled': True, 'description': ''}}
2026-06-08 03:55:20,482 - DEBUG - Response for create_subnet : {'subnet': {'id': '109814f1-e360-4899-8dbc-5eedf0f009b2', 'name': '', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '2e1b093d-5616-4298-9956-e23b185ae4eb', 'ip_version': 4, 'cidr': '158.192.229.64/26', 'allocation_pools': [{'start': '158.192.229.66', 'end': '158.192.229.126'}], 'gateway_ip': '158.192.229.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '158.192.229.66', 'tags': [], 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:20,508 - INFO - Created VN ctest-vn-88241847
2026-06-08 03:55:20,523 - DEBUG - VN ctest-vn-88241847 UUID is 2e1b093d-5616-4298-9956-e23b185ae4eb
2026-06-08 03:55:20,601 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-66413289']}
2026-06-08 03:55:20,893 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-66413289', 'id': 'dd678b73-94ab-4d18-99d4-c984765c3d99', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '1c78361f-1066-4360-9e1e-1b1fed93b25e', 'mac_address': '02:dd:67:8b:73:94', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '167.246.249.67', 'subnet_id': '59956ce5-cee9-4243-a531-56dbcbf77645'}], 'security_groups': ['100d70b5-a559-4da5-ac80-956f7c8db36f'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:20,893 - DEBUG - Created port dd678b73-94ab-4d18-99d4-c984765c3d99
2026-06-08 03:55:20,975 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-96542904']}
2026-06-08 03:55:21,491 - DEBUG - Created port 880d631d-568e-47ae-ab38-c946e72dd011
2026-06-08 03:55:21,623 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-59847419']}
2026-06-08 03:55:22,002 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-59847419', 'id': '7e15758f-098f-4668-ad6c-1d25005d0d33', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '1c78361f-1066-4360-9e1e-1b1fed93b25e', 'mac_address': '02:7e:15:75:8f:09', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '167.246.249.68', 'subnet_id': '59956ce5-cee9-4243-a531-56dbcbf77645'}], 'security_groups': ['100d70b5-a559-4da5-ac80-956f7c8db36f'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:22,002 - DEBUG - Created port 7e15758f-098f-4668-ad6c-1d25005d0d33
2026-06-08 03:55:22,076 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-38093769']}
2026-06-08 03:55:22,559 - DEBUG - Created port f2213544-975d-4a4c-bdd6-5100bc919b6b
2026-06-08 03:55:22,675 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-56737992']}
2026-06-08 03:55:23,021 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-56737992', 'id': 'e8a3e80a-30a4-4955-a527-7fc929d2e337', 'tenant_id': '19a8c36c0ada4c629f8e9f10fe7e0cef', 'network_id': '1c78361f-1066-4360-9e1e-1b1fed93b25e', 'mac_address': '02:e8:a3:e8:0a:30', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '167.246.249.69', 'subnet_id': '59956ce5-cee9-4243-a531-56dbcbf77645'}], 'security_groups': ['100d70b5-a559-4da5-ac80-956f7c8db36f'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '19a8c36c0ada4c629f8e9f10fe7e0cef'}}
2026-06-08 03:55:23,021 - DEBUG - Created port e8a3e80a-30a4-4955-a527-7fc929d2e337
2026-06-08 03:55:23,109 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-26176602', 'ctest-vmi-63965365']}
2026-06-08 03:55:23,615 - DEBUG - Created port e275b700-07da-4953-8157-bb6c3eaf2234
2026-06-08 03:55:23,741 - INFO - ================================================================================
2026-06-08 03:55:23,741 - INFO - STARTING TEST : test_vlan_interface_2
2026-06-08 03:55:23,741 - INFO - TEST DESCRIPTION :
Test ping/hping between tagged-untagged vmis across VNs
2026-06-08 03:55:25,021 - DEBUG - Nothing to compare xmpp stats {'10.0.0.23': {'10.20.0.193': '3', '10.20.0.25': '1'}, '10.0.0.240': {'10.20.0.129': '3', '10.20.0.25': '2'}} with
2026-06-08 03:55:25,021 - INFO - Initial checks done. Running the testcase now
2026-06-08 03:55:25,022 - INFO -
2026-06-08 03:55:25,169 - DEBUG - Services list from nova: [, , , ]
2026-06-08 03:55:25,768 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5901-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5901-2)
2026-06-08 03:55:27,188 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5901-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5901-1)
2026-06-08 03:55:28,156 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5901-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5901-2)
2026-06-08 03:55:28,303 - INFO - Adding interface with subnet_id 5a285dbb-cf36-46c8-933f-54b795ac713f, port_id None to router ee268273-72d7-41bb-90c0-7ee63ab1effc
2026-06-08 03:55:28,774 - INFO - Adding interface with subnet_id 109814f1-e360-4899-8dbc-5eedf0f009b2, port_id None to router ee268273-72d7-41bb-90c0-7ee63ab1effc
2026-06-08 03:55:29,300 - INFO - Waiting for VM ctest-TestSubInterfaces-26176602-27934544 to be up..
2026-06-08 03:55:29,455 - DEBUG - VM is in ACTIVE state now
2026-06-08 03:55:29,455 - INFO - VM name : ctest-TestSubInterfaces-26176602-27934544
2026-06-08 03:55:29,549 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 ID is 0e87e58b-97dc-4aa7-a83b-bd78eac8b753
2026-06-08 03:55:29,578 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 launched on Node an-jenkins-deploy-platform-ansible-os-5901-2
2026-06-08 03:55:29,662 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/0e87e58b-97dc-4aa7-a83b-bd78eac8b753
2026-06-08 03:55:29,967 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/0e87e58b-97dc-4aa7-a83b-bd78eac8b753
2026-06-08 03:55:30,006 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/dd678b73-94ab-4d18-99d4-c984765c3d99
2026-06-08 03:55:33,199 - 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 1001ms')
2026-06-08 03:55:33,199 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:33,217 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:37,329 - 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 1039ms')
2026-06-08 03:55:37,329 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:37,348 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:41,423 - 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 1007ms')
2026-06-08 03:55:41,423 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:41,443 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:45,518 - 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 1011ms')
2026-06-08 03:55:45,518 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:45,532 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:49,611 - 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 1021ms')
2026-06-08 03:55:49,611 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:49,631 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:53,713 - 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 1017ms')
2026-06-08 03:55:53,713 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:53,729 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:55:57,804 - 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 1011ms')
2026-06-08 03:55:57,804 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:55:57,823 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:01,911 - 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 1023ms')
2026-06-08 03:56:01,911 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:56:01,928 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:06,035 - 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 1032ms')
2026-06-08 03:56:06,035 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:56:06,050 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:10,127 - 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 1011ms')
2026-06-08 03:56:10,127 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:56:10,147 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:14,230 - 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 1014ms')
2026-06-08 03:56:14,231 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:56:14,252 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:18,347 - 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 1028ms')
2026-06-08 03:56:18,347 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 failed!
2026-06-08 03:56:18,366 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-26176602:ctest-vn-73605685 is 167.246.249.65 and allocation pool is NOT set
2026-06-08 03:56:20,447 - 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=1 ttl=63 time=13.0 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=14.1 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 12.998/13.561/14.125/0.563 ms')
2026-06-08 03:56:20,447 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-27934544 passed
2026-06-08 03:56:20,521 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:20,521 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:20,590 - 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': ''}
2026-06-08 03:56:20,683 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:25,683 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:25,683 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:25,754 - 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': ''}
2026-06-08 03:56:25,841 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:30,841 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:30,841 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:30,911 - 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': ''}
2026-06-08 03:56:31,011 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:36,011 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:36,011 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:36,078 - 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': ''}
2026-06-08 03:56:36,174 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:41,175 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:41,175 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:41,242 - 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': ''}
2026-06-08 03:56:41,339 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:46,340 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:46,341 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-27934544, IP 167.246.249.67, Port 22
2026-06-08 03:56:46,515 - DEBUG - VM ctest-TestSubInterfaces-26176602-27934544 is ready for SSH connections
2026-06-08 03:56:46,515 - INFO - Waiting for VM ctest-TestSubInterfaces-26176602-79045781 to be up..
2026-06-08 03:56:46,612 - DEBUG - VM is in ACTIVE state now
2026-06-08 03:56:46,613 - INFO - VM name : ctest-TestSubInterfaces-26176602-79045781
2026-06-08 03:56:46,714 - DEBUG - VM ctest-TestSubInterfaces-26176602-79045781 ID is 40850390-9d30-45ed-8da1-9b0ed6988317
2026-06-08 03:56:46,714 - DEBUG - VM ctest-TestSubInterfaces-26176602-79045781 launched on Node an-jenkins-deploy-platform-ansible-os-5901-1
2026-06-08 03:56:46,796 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/40850390-9d30-45ed-8da1-9b0ed6988317
2026-06-08 03:56:46,811 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/4b65fe36-fea3-4b59-bc12-35f076b81d31
2026-06-08 03:56:47,992 - 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=1 ttl=63 time=3.93 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=2.67 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.667/3.300/3.933/0.633 ms')
2026-06-08 03:56:47,992 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-26176602-79045781 passed
2026-06-08 03:56:48,065 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:48,065 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-79045781, IP 158.192.229.68, Port 22
2026-06-08 03:56:48,236 - DEBUG - VM ctest-TestSubInterfaces-26176602-79045781 is ready for SSH connections
2026-06-08 03:56:48,237 - INFO - Waiting for VM ctest-TestSubInterfaces-26176602-00069454 to be up..
2026-06-08 03:56:48,324 - DEBUG - VM is in ACTIVE state now
2026-06-08 03:56:48,324 - INFO - VM name : ctest-TestSubInterfaces-26176602-00069454
2026-06-08 03:56:48,407 - DEBUG - VM ctest-TestSubInterfaces-26176602-00069454 ID is 53a0621d-f727-460c-b7d2-3456b81f84ae
2026-06-08 03:56:48,407 - DEBUG - VM ctest-TestSubInterfaces-26176602-00069454 launched on Node an-jenkins-deploy-platform-ansible-os-5901-2
2026-06-08 03:56:48,490 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/53a0621d-f727-460c-b7d2-3456b81f84ae
2026-06-08 03:56:48,501 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/e8a3e80a-30a4-4955-a527-7fc929d2e337
2026-06-08 03:56:49,681 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n64 bytes from 169.254.0.7: icmp_seq=1 ttl=63 time=4.34 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=5.77 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 4.340/5.055/5.770/0.715 ms')
2026-06-08 03:56:49,681 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestSubInterfaces-26176602-00069454 passed
2026-06-08 03:56:49,764 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:49,764 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-00069454, IP 167.246.249.69, Port 22
2026-06-08 03:56:49,832 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-06-08 03:56:49,953 - DEBUG - VM ctest-TestSubInterfaces-26176602-00069454 is NOT ready for SSH connections, VM status: ACTIVE
2026-06-08 03:56:54,954 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:56:54,954 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-26176602-00069454, IP 167.246.249.69, Port 22
2026-06-08 03:56:55,131 - DEBUG - VM ctest-TestSubInterfaces-26176602-00069454 is ready for SSH connections
2026-06-08 03:56:55,131 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 11.110.67.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.240, gateway password: c0ntrail123
2026-06-08 03:56:55,131 - DEBUG - ifconfig -a| grep 11.110.67.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2026-06-08 03:57:17,465 - DEBUG - None
2026-06-08 03:57:22,466 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 11.110.67.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.240, gateway password: c0ntrail123
2026-06-08 03:57:22,466 - DEBUG - ifconfig -a| grep 11.110.67.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2026-06-08 03:57:23,721 - DEBUG - None
2026-06-08 03:57:28,722 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 11.110.67.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.240, gateway password: c0ntrail123
2026-06-08 03:57:28,722 - DEBUG - ifconfig -a| grep 11.110.67.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2026-06-08 03:57:31,357 - DEBUG - None
2026-06-08 03:57:36,358 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 11.110.67.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.240, gateway password: c0ntrail123
2026-06-08 03:57:36,359 - DEBUG - ifconfig -a| grep 11.110.67.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2026-06-08 03:57:37,642 - DEBUG - eth0.100
2026-06-08 03:57:37,643 - INFO - Interface eth0.100 is found on VM 0e87e58b-97dc-4aa7-a83b-bd78eac8b753
2026-06-08 03:57:37,643 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 158.192.229.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2026-06-08 03:57:37,643 - DEBUG - ifconfig -a| grep 158.192.229.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1
2026-06-08 03:58:22,427 - DEBUG - eth0.100
2026-06-08 03:58:22,428 - INFO - Interface eth0.100 is found on VM 53a0621d-f727-460c-b7d2-3456b81f84ae
2026-06-08 03:58:22,428 - DEBUG - Running remote_cmd, Cmd : route add -net 158.192.229.64/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2026-06-08 03:58:22,428 - DEBUG - route add -net 158.192.229.64/26 dev eth0.100
2026-06-08 03:58:23,138 - DEBUG - None
2026-06-08 03:58:23,138 - DEBUG - Running remote_cmd, Cmd : route add -net 11.110.67.128/26 dev eth0.100, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2026-06-08 03:58:23,139 - DEBUG - route add -net 11.110.67.128/26 dev eth0.100
2026-06-08 03:58:23,795 - DEBUG - None
2026-06-08 03:58:23,795 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-06-08 03:58:23,795 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 158.192.229.68, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2026-06-08 03:58:23,795 - DEBUG - ping -s 56 -c 3 -W 1 158.192.229.68
2026-06-08 03:58:26,327 - DEBUG - PING 158.192.229.68 (158.192.229.68) 56(84) bytes of data.
64 bytes from 158.192.229.68: icmp_req=1 ttl=63 time=10.0 ms
64 bytes from 158.192.229.68: icmp_req=2 ttl=63 time=1.30 ms
64 bytes from 158.192.229.68: icmp_req=3 ttl=63 time=1.36 ms
--- 158.192.229.68 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.306/4.245/10.069/4.118 ms
2026-06-08 03:58:26,328 - INFO - Ping to IP 158.192.229.68 from VM ctest-TestSubInterfaces-26176602-27934544 passed
2026-06-08 03:58:26,328 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 158.192.229.67, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2026-06-08 03:58:26,328 - DEBUG - ping -s 56 -c 3 -W 1 158.192.229.67
2026-06-08 03:58:28,929 - DEBUG - PING 158.192.229.67 (158.192.229.67) 56(84) bytes of data.
64 bytes from 158.192.229.67: icmp_req=1 ttl=63 time=9.39 ms
64 bytes from 158.192.229.67: icmp_req=2 ttl=63 time=1.04 ms
64 bytes from 158.192.229.67: icmp_req=3 ttl=63 time=1.02 ms
--- 158.192.229.67 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.027/3.819/9.390/3.939 ms
2026-06-08 03:58:28,929 - INFO - Ping to IP 158.192.229.67 from VM ctest-TestSubInterfaces-26176602-27934544 passed
2026-06-08 03:58:28,929 - INFO - Deleting interface with subnet_id 109814f1-e360-4899-8dbc-5eedf0f009b2, port_id None from router ee268273-72d7-41bb-90c0-7ee63ab1effc
2026-06-08 03:58:29,149 - INFO - Deleting interface with subnet_id 5a285dbb-cf36-46c8-933f-54b795ac713f, port_id None from router ee268273-72d7-41bb-90c0-7ee63ab1effc
2026-06-08 03:58:29,529 - INFO - Detaching port e8a3e80a-30a4-4955-a527-7fc929d2e337 from VM ctest-TestSubInterfaces-26176602-00069454
2026-06-08 03:58:29,657 - INFO - Deleting VM ctest-TestSubInterfaces-26176602-00069454
2026-06-08 03:58:29,732 - INFO - Deleting VM ctest-TestSubInterfaces-26176602-79045781
2026-06-08 03:58:29,804 - INFO - Detaching port dd678b73-94ab-4d18-99d4-c984765c3d99 from VM ctest-TestSubInterfaces-26176602-27934544
2026-06-08 03:58:29,845 - INFO - Deleting VM ctest-TestSubInterfaces-26176602-27934544
2026-06-08 03:58:31,255 - DEBUG - No XMPP flaps were noticed during the test
2026-06-08 03:58:31,255 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:03:08]
2026-06-08 03:58:31,255 - INFO - --------------------------------------------------------------------------------
2026-06-08 03:58:31,394 - INFO - Deleted port e275b700-07da-4953-8157-bb6c3eaf2234
2026-06-08 03:58:31,621 - DEBUG - Response for delete_port : ()
2026-06-08 03:58:31,621 - INFO - Deleted port e8a3e80a-30a4-4955-a527-7fc929d2e337
2026-06-08 03:58:31,747 - INFO - Deleted port f2213544-975d-4a4c-bdd6-5100bc919b6b
2026-06-08 03:58:31,938 - DEBUG - Response for delete_port : ()
2026-06-08 03:58:31,938 - INFO - Deleted port 7e15758f-098f-4668-ad6c-1d25005d0d33
2026-06-08 03:58:32,060 - INFO - Deleted port 880d631d-568e-47ae-ab38-c946e72dd011
2026-06-08 03:58:32,330 - DEBUG - Response for delete_port : ()
2026-06-08 03:58:32,331 - INFO - Deleted port dd678b73-94ab-4d18-99d4-c984765c3d99
2026-06-08 03:58:32,331 - INFO - Deleting VN ctest-vn-88241847
2026-06-08 03:58:32,496 - DEBUG - Response for deleting network ()
2026-06-08 03:58:32,496 - INFO - Deleting VN ctest-vn-73605685
2026-06-08 03:58:32,661 - DEBUG - Response for deleting network ()
2026-06-08 03:58:32,661 - INFO - Deleting VN ctest-vn-59214061
2026-06-08 03:58:32,847 - DEBUG - Response for deleting network ()
2026-06-08 03:58:33,644 - INFO - Deleted project: ctest-TestSubInterfaces-26176602, ID : 19a8c36c-0ada-4c62-9f8e-9f10fe7e0cef