2026-05-07 04:05:06,500 - INFO - Domain Default found not creating 2026-05-07 04:05:06,790 - INFO - Project ctest-TestSubInterfaces-10659180 not found, creating it 2026-05-07 04:05:07,444 - INFO - Created Project:ctest-TestSubInterfaces-10659180, ID : efe00fe4-c42d-4aed-94a1-2ad973b6eafc 2026-05-07 04:05:10,190 - DEBUG - Response for create_network : {'network': {'id': 'b873bf8c-7afa-4c5d-9184-f457ce2e4720', 'name': 'ctest-vn-63045930', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vn-63045930'], 'port_security_enabled': True, 'description': ''}} 2026-05-07 04:05:10,640 - DEBUG - Response for create_subnet : {'subnet': {'id': '96a3adba-cf3a-46ff-9978-c51b727fc499', 'name': '', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': 'b873bf8c-7afa-4c5d-9184-f457ce2e4720', 'ip_version': 4, 'cidr': '9.116.10.0/26', 'allocation_pools': [{'start': '9.116.10.2', 'end': '9.116.10.62'}], 'gateway_ip': '9.116.10.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '9.116.10.2', 'tags': [], 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:10,678 - INFO - Created VN ctest-vn-63045930 2026-05-07 04:05:10,698 - DEBUG - VN ctest-vn-63045930 UUID is b873bf8c-7afa-4c5d-9184-f457ce2e4720 2026-05-07 04:05:11,237 - DEBUG - Response for create_network : {'network': {'id': '95e0dbe0-74c8-4d90-bbc3-b09444a2cfec', 'name': 'ctest-vn-05958078', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vn-05958078'], 'port_security_enabled': True, 'description': ''}} 2026-05-07 04:05:11,591 - DEBUG - Response for create_subnet : {'subnet': {'id': 'cc3d9efc-f48c-4b56-a825-d31707a5fb63', 'name': '', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': '95e0dbe0-74c8-4d90-bbc3-b09444a2cfec', 'ip_version': 4, 'cidr': '112.130.39.128/26', 'allocation_pools': [{'start': '112.130.39.130', 'end': '112.130.39.190'}], 'gateway_ip': '112.130.39.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '112.130.39.130', 'tags': [], 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:11,627 - INFO - Created VN ctest-vn-05958078 2026-05-07 04:05:11,646 - DEBUG - VN ctest-vn-05958078 UUID is 95e0dbe0-74c8-4d90-bbc3-b09444a2cfec 2026-05-07 04:05:12,166 - DEBUG - Response for create_network : {'network': {'id': '276965db-827d-4254-a7bd-439686b205db', 'name': 'ctest-vn-76822610', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vn-76822610'], 'port_security_enabled': True, 'description': ''}} 2026-05-07 04:05:12,453 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a08fe888-e9f2-44bb-98f5-0371fc487d18', 'name': '', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': '276965db-827d-4254-a7bd-439686b205db', 'ip_version': 4, 'cidr': '39.250.188.192/26', 'allocation_pools': [{'start': '39.250.188.194', 'end': '39.250.188.254'}], 'gateway_ip': '39.250.188.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '39.250.188.194', 'tags': [], 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:12,501 - INFO - Created VN ctest-vn-76822610 2026-05-07 04:05:12,518 - DEBUG - VN ctest-vn-76822610 UUID is 276965db-827d-4254-a7bd-439686b205db 2026-05-07 04:05:12,635 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-25979133']} 2026-05-07 04:05:13,069 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-25979133', 'id': '296813b7-da61-4885-8429-11a7161e1758', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': '95e0dbe0-74c8-4d90-bbc3-b09444a2cfec', 'mac_address': '02:29:68:13:b7:da', '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': '112.130.39.131', 'subnet_id': 'cc3d9efc-f48c-4b56-a825-d31707a5fb63'}], 'security_groups': ['deed7a7d-513c-43f6-b6ce-2d11c3782eb2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:13,070 - DEBUG - Created port 296813b7-da61-4885-8429-11a7161e1758 2026-05-07 04:05:13,162 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-56476249']} 2026-05-07 04:05:13,714 - DEBUG - Created port e00cc3a1-2a1c-4459-969e-d5da06d18df3 2026-05-07 04:05:13,847 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-06427598']} 2026-05-07 04:05:14,355 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-06427598', 'id': '00294cf3-0d66-4ce6-84f9-f9fc4175cf61', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': '95e0dbe0-74c8-4d90-bbc3-b09444a2cfec', 'mac_address': '02:00:29:4c:f3:0d', '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': '112.130.39.132', 'subnet_id': 'cc3d9efc-f48c-4b56-a825-d31707a5fb63'}], 'security_groups': ['deed7a7d-513c-43f6-b6ce-2d11c3782eb2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:14,355 - DEBUG - Created port 00294cf3-0d66-4ce6-84f9-f9fc4175cf61 2026-05-07 04:05:14,438 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-17824314']} 2026-05-07 04:05:14,986 - DEBUG - Created port 0f57e3b4-4386-49dd-b2fb-83000f6dfd58 2026-05-07 04:05:15,107 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-16864884']} 2026-05-07 04:05:15,500 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-16864884', 'id': '8ac90ded-ceb9-4bde-aa72-b37caf0f8b69', 'tenant_id': 'efe00fe4c42d4aed94a12ad973b6eafc', 'network_id': '95e0dbe0-74c8-4d90-bbc3-b09444a2cfec', 'mac_address': '02:8a:c9:0d:ed:ce', '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': '112.130.39.133', 'subnet_id': 'cc3d9efc-f48c-4b56-a825-d31707a5fb63'}], 'security_groups': ['deed7a7d-513c-43f6-b6ce-2d11c3782eb2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'efe00fe4c42d4aed94a12ad973b6eafc'}} 2026-05-07 04:05:15,500 - DEBUG - Created port 8ac90ded-ceb9-4bde-aa72-b37caf0f8b69 2026-05-07 04:05:15,585 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-10659180', 'ctest-vmi-79123387']} 2026-05-07 04:05:16,162 - DEBUG - Created port 89f3a5c6-fb76-4726-9d2f-1214cfccfb09 2026-05-07 04:05:16,285 - INFO - ================================================================================ 2026-05-07 04:05:16,285 - INFO - STARTING TEST : test_vlan_interface_2 2026-05-07 04:05:16,285 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2026-05-07 04:05:17,650 - DEBUG - Nothing to compare xmpp stats {'10.0.0.23': {'10.20.0.129': '0', '10.20.0.193': '0'}, '10.0.0.240': {'10.20.0.129': '0', '10.20.0.193': '0'}} with 2026-05-07 04:05:17,650 - INFO - Initial checks done. Running the testcase now 2026-05-07 04:05:17,650 - INFO - 2026-05-07 04:05:17,885 - DEBUG - Services list from nova: [, , , ] 2026-05-07 04:05:18,687 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5754-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5754-2) 2026-05-07 04:05:20,264 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5754-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5754-1) 2026-05-07 04:05:21,578 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5754-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5754-2) 2026-05-07 04:05:21,733 - INFO - Adding interface with subnet_id 96a3adba-cf3a-46ff-9978-c51b727fc499, port_id None to router 21fe2388-cdba-4894-968a-428c1438dd57 2026-05-07 04:05:22,227 - INFO - Adding interface with subnet_id a08fe888-e9f2-44bb-98f5-0371fc487d18, port_id None to router 21fe2388-cdba-4894-968a-428c1438dd57 2026-05-07 04:05:22,880 - INFO - Waiting for VM ctest-TestSubInterfaces-10659180-84870638 to be up.. 2026-05-07 04:05:23,159 - DEBUG - VM is in ACTIVE state now 2026-05-07 04:05:23,159 - INFO - VM name : ctest-TestSubInterfaces-10659180-84870638 2026-05-07 04:05:23,287 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 ID is 1c80eafc-8048-4996-9467-4aff9318de95 2026-05-07 04:05:23,332 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 launched on Node an-jenkins-deploy-platform-ansible-os-5754-2 2026-05-07 04:05:23,459 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1c80eafc-8048-4996-9467-4aff9318de95 2026-05-07 04:05:23,762 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1c80eafc-8048-4996-9467-4aff9318de95 2026-05-07 04:05:23,811 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/296813b7-da61-4885-8429-11a7161e1758 2026-05-07 04:05:27,108 - 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 1018ms') 2026-05-07 04:05:27,108 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:27,128 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:31,207 - 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') 2026-05-07 04:05:31,207 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:31,229 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:35,308 - 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 1006ms') 2026-05-07 04:05:35,308 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:35,329 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:39,434 - 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 1031ms') 2026-05-07 04:05:39,434 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:39,452 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:43,523 - 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-05-07 04:05:43,524 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:43,546 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:47,624 - 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-05-07 04:05:47,625 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:47,644 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:51,714 - 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') 2026-05-07 04:05:51,714 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:51,740 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:55,812 - 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') 2026-05-07 04:05:55,812 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:55,831 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:05:59,915 - 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 1012ms') 2026-05-07 04:05:59,915 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:05:59,935 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:04,019 - 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 1004ms') 2026-05-07 04:06:04,019 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:04,040 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:08,132 - 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 1024ms') 2026-05-07 04:06:08,132 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:08,152 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:12,234 - 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') 2026-05-07 04:06:12,234 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:12,255 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:16,328 - 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') 2026-05-07 04:06:16,328 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:16,347 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:20,428 - 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-05-07 04:06:20,429 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:20,455 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:24,556 - 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 1029ms') 2026-05-07 04:06:24,556 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:24,575 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:28,674 - 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-05-07 04:06:28,674 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 failed! 2026-05-07 04:06:28,692 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-10659180:ctest-vn-05958078 is 112.130.39.129 and allocation pool is NOT set 2026-05-07 04:06:30,760 - 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=9.39 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.864 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 = 0.864/5.125/9.386/4.261 ms') 2026-05-07 04:06:30,760 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-84870638 passed 2026-05-07 04:06:30,844 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:30,844 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:30,915 - 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-05-07 04:06:31,049 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:06:36,050 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:36,050 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:36,124 - 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-05-07 04:06:36,287 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:06:41,288 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:41,288 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:41,359 - 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-05-07 04:06:41,472 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:06:46,473 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:46,473 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:46,545 - 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-05-07 04:06:46,655 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:06:51,655 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:51,656 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:51,727 - 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-05-07 04:06:51,908 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:06:56,909 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:06:56,909 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:06:56,978 - 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-05-07 04:06:57,087 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-07 04:07:02,088 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:07:02,088 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-84870638, IP 112.130.39.131, Port 22 2026-05-07 04:07:02,271 - DEBUG - VM ctest-TestSubInterfaces-10659180-84870638 is ready for SSH connections 2026-05-07 04:07:02,271 - INFO - Waiting for VM ctest-TestSubInterfaces-10659180-52438890 to be up.. 2026-05-07 04:07:02,398 - DEBUG - VM is in ACTIVE state now 2026-05-07 04:07:02,398 - INFO - VM name : ctest-TestSubInterfaces-10659180-52438890 2026-05-07 04:07:02,521 - DEBUG - VM ctest-TestSubInterfaces-10659180-52438890 ID is 494786b1-ea66-4499-8c88-f2213a82bb04 2026-05-07 04:07:02,521 - DEBUG - VM ctest-TestSubInterfaces-10659180-52438890 launched on Node an-jenkins-deploy-platform-ansible-os-5754-1 2026-05-07 04:07:02,647 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/494786b1-ea66-4499-8c88-f2213a82bb04 2026-05-07 04:07:02,668 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/d99a6386-94ca-41f6-93a9-f55f956634ac 2026-05-07 04:07:03,853 - 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=4.88 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.547 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.547/2.711/4.876/2.164 ms') 2026-05-07 04:07:03,853 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-10659180-52438890 passed 2026-05-07 04:07:03,942 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:07:03,942 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-52438890, IP 39.250.188.196, Port 22 2026-05-07 04:07:04,126 - DEBUG - VM ctest-TestSubInterfaces-10659180-52438890 is ready for SSH connections 2026-05-07 04:07:04,126 - INFO - Waiting for VM ctest-TestSubInterfaces-10659180-30441909 to be up.. 2026-05-07 04:07:04,243 - DEBUG - VM is in ACTIVE state now 2026-05-07 04:07:04,243 - INFO - VM name : ctest-TestSubInterfaces-10659180-30441909 2026-05-07 04:07:04,375 - DEBUG - VM ctest-TestSubInterfaces-10659180-30441909 ID is 9891af2b-af35-47e4-841b-fb3ad0555890 2026-05-07 04:07:04,376 - DEBUG - VM ctest-TestSubInterfaces-10659180-30441909 launched on Node an-jenkins-deploy-platform-ansible-os-5754-2 2026-05-07 04:07:04,498 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/9891af2b-af35-47e4-841b-fb3ad0555890 2026-05-07 04:07:04,514 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/8ac90ded-ceb9-4bde-aa72-b37caf0f8b69 2026-05-07 04:07:05,717 - 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=2.49 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=2.09 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.092/2.290/2.489/0.198 ms') 2026-05-07 04:07:05,717 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestSubInterfaces-10659180-30441909 passed 2026-05-07 04:07:05,804 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:07:05,804 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-10659180-30441909, IP 112.130.39.133, Port 22 2026-05-07 04:07:05,979 - DEBUG - VM ctest-TestSubInterfaces-10659180-30441909 is ready for SSH connections 2026-05-07 04:07:05,979 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 9.116.10.3 -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-05-07 04:07:05,979 - DEBUG - ifconfig -a| grep 9.116.10.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-07 04:07:28,450 - DEBUG - None 2026-05-07 04:07:33,451 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 9.116.10.3 -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-05-07 04:07:33,452 - DEBUG - ifconfig -a| grep 9.116.10.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-07 04:07:36,205 - DEBUG - None 2026-05-07 04:07:41,206 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 9.116.10.3 -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-05-07 04:07:41,207 - DEBUG - ifconfig -a| grep 9.116.10.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-07 04:07:43,159 - DEBUG - None 2026-05-07 04:07:48,159 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 9.116.10.3 -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-05-07 04:07:48,160 - DEBUG - ifconfig -a| grep 9.116.10.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-07 04:07:49,354 - DEBUG - eth0.100 2026-05-07 04:07:49,354 - INFO - Interface eth0.100 is found on VM 1c80eafc-8048-4996-9467-4aff9318de95 2026-05-07 04:07:49,355 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 39.250.188.195 -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-05-07 04:07:49,355 - DEBUG - ifconfig -a| grep 39.250.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-07 04:08:34,484 - DEBUG - eth0.100 2026-05-07 04:08:34,484 - INFO - Interface eth0.100 is found on VM 9891af2b-af35-47e4-841b-fb3ad0555890 2026-05-07 04:08:34,484 - DEBUG - Running remote_cmd, Cmd : route add -net 39.250.188.192/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2026-05-07 04:08:34,484 - DEBUG - route add -net 39.250.188.192/26 dev eth0.100 2026-05-07 04:08:35,057 - DEBUG - None 2026-05-07 04:08:35,057 - DEBUG - Running remote_cmd, Cmd : route add -net 9.116.10.0/26 dev eth0.100, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2026-05-07 04:08:35,057 - DEBUG - route add -net 9.116.10.0/26 dev eth0.100 2026-05-07 04:08:35,652 - DEBUG - None 2026-05-07 04:08:35,653 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-07 04:08:35,653 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 39.250.188.196, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2026-05-07 04:08:35,653 - DEBUG - ping -s 56 -c 3 -W 1 39.250.188.196 2026-05-07 04:08:38,220 - DEBUG - PING 39.250.188.196 (39.250.188.196) 56(84) bytes of data. 64 bytes from 39.250.188.196: icmp_req=1 ttl=63 time=12.9 ms 64 bytes from 39.250.188.196: icmp_req=2 ttl=63 time=1.85 ms 64 bytes from 39.250.188.196: icmp_req=3 ttl=63 time=2.57 ms --- 39.250.188.196 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.856/5.785/12.929/5.060 ms 2026-05-07 04:08:38,221 - INFO - Ping to IP 39.250.188.196 from VM ctest-TestSubInterfaces-10659180-84870638 passed 2026-05-07 04:08:38,221 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 39.250.188.195, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2026-05-07 04:08:38,221 - DEBUG - ping -s 56 -c 3 -W 1 39.250.188.195 2026-05-07 04:08:40,902 - DEBUG - PING 39.250.188.195 (39.250.188.195) 56(84) bytes of data. 64 bytes from 39.250.188.195: icmp_req=1 ttl=63 time=8.81 ms 64 bytes from 39.250.188.195: icmp_req=2 ttl=63 time=1.35 ms 64 bytes from 39.250.188.195: icmp_req=3 ttl=63 time=0.886 ms --- 39.250.188.195 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2005ms rtt min/avg/max/mdev = 0.886/3.685/8.817/3.633 ms 2026-05-07 04:08:40,902 - INFO - Ping to IP 39.250.188.195 from VM ctest-TestSubInterfaces-10659180-84870638 passed 2026-05-07 04:08:40,902 - INFO - Deleting interface with subnet_id a08fe888-e9f2-44bb-98f5-0371fc487d18, port_id None from router 21fe2388-cdba-4894-968a-428c1438dd57 2026-05-07 04:08:41,254 - INFO - Deleting interface with subnet_id 96a3adba-cf3a-46ff-9978-c51b727fc499, port_id None from router 21fe2388-cdba-4894-968a-428c1438dd57 2026-05-07 04:08:41,678 - INFO - Detaching port 8ac90ded-ceb9-4bde-aa72-b37caf0f8b69 from VM ctest-TestSubInterfaces-10659180-30441909 2026-05-07 04:08:41,777 - INFO - Deleting VM ctest-TestSubInterfaces-10659180-30441909 2026-05-07 04:08:41,903 - INFO - Deleting VM ctest-TestSubInterfaces-10659180-52438890 2026-05-07 04:08:42,055 - INFO - Detaching port 296813b7-da61-4885-8429-11a7161e1758 from VM ctest-TestSubInterfaces-10659180-84870638 2026-05-07 04:08:42,118 - INFO - Deleting VM ctest-TestSubInterfaces-10659180-84870638 2026-05-07 04:08:43,602 - DEBUG - No XMPP flaps were noticed during the test
2026-05-07 04:08:43,602 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:03:27]
2026-05-07 04:08:43,602 - INFO - -------------------------------------------------------------------------------- 2026-05-07 04:08:43,763 - INFO - Deleted port 89f3a5c6-fb76-4726-9d2f-1214cfccfb09 2026-05-07 04:08:44,131 - DEBUG - Response for delete_port : () 2026-05-07 04:08:44,132 - INFO - Deleted port 8ac90ded-ceb9-4bde-aa72-b37caf0f8b69 2026-05-07 04:08:44,294 - INFO - Deleted port 0f57e3b4-4386-49dd-b2fb-83000f6dfd58 2026-05-07 04:08:44,536 - DEBUG - Response for delete_port : () 2026-05-07 04:08:44,536 - INFO - Deleted port 00294cf3-0d66-4ce6-84f9-f9fc4175cf61 2026-05-07 04:08:44,707 - INFO - Deleted port e00cc3a1-2a1c-4459-969e-d5da06d18df3 2026-05-07 04:08:45,041 - DEBUG - Response for delete_port : () 2026-05-07 04:08:45,041 - INFO - Deleted port 296813b7-da61-4885-8429-11a7161e1758 2026-05-07 04:08:45,041 - INFO - Deleting VN ctest-vn-76822610 2026-05-07 04:08:45,295 - DEBUG - Response for deleting network () 2026-05-07 04:08:45,295 - INFO - Deleting VN ctest-vn-05958078 2026-05-07 04:08:45,539 - DEBUG - Response for deleting network () 2026-05-07 04:08:45,539 - INFO - Deleting VN ctest-vn-63045930 2026-05-07 04:08:45,780 - DEBUG - Response for deleting network () 2026-05-07 04:08:46,653 - INFO - Deleted project: ctest-TestSubInterfaces-10659180, ID : efe00fe4-c42d-4aed-94a1-2ad973b6eafc