2026-05-18 03:48:59,285 - INFO - Domain Default found not creating 2026-05-18 03:48:59,501 - INFO - Project ctest-TestSubInterfaces-91966857 not found, creating it 2026-05-18 03:49:00,478 - INFO - Created Project:ctest-TestSubInterfaces-91966857, ID : 6e76b315-242c-4f82-b1d6-2f7021093cc0 2026-05-18 03:49:03,619 - DEBUG - Response for create_network : {'network': {'id': '83def181-eba5-42ee-b7e6-ea65370eff86', 'name': 'ctest-vn-36463906', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'project_id': '6e76b315242c4f82b1d62f7021093cc0', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vn-36463906'], 'port_security_enabled': True, 'description': ''}} 2026-05-18 03:49:03,949 - DEBUG - Response for create_subnet : {'subnet': {'id': '3cd68b78-5d31-4ac1-b9fd-56ee4b90cde6', 'name': '', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '83def181-eba5-42ee-b7e6-ea65370eff86', 'ip_version': 4, 'cidr': '143.178.22.64/26', 'allocation_pools': [{'start': '143.178.22.66', 'end': '143.178.22.126'}], 'gateway_ip': '143.178.22.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '143.178.22.66', 'tags': [], 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:03,975 - INFO - Created VN ctest-vn-36463906 2026-05-18 03:49:03,994 - DEBUG - VN ctest-vn-36463906 UUID is 83def181-eba5-42ee-b7e6-ea65370eff86 2026-05-18 03:49:04,396 - DEBUG - Response for create_network : {'network': {'id': '2b80e939-5cfc-4059-b4e1-1b5cad888120', 'name': 'ctest-vn-50955044', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'project_id': '6e76b315242c4f82b1d62f7021093cc0', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vn-50955044'], 'port_security_enabled': True, 'description': ''}} 2026-05-18 03:49:04,640 - DEBUG - Response for create_subnet : {'subnet': {'id': '145823fc-d986-4684-9a86-88dc2b0a40f6', 'name': '', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '2b80e939-5cfc-4059-b4e1-1b5cad888120', 'ip_version': 4, 'cidr': '152.227.107.0/26', 'allocation_pools': [{'start': '152.227.107.2', 'end': '152.227.107.62'}], 'gateway_ip': '152.227.107.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '152.227.107.2', 'tags': [], 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:04,678 - INFO - Created VN ctest-vn-50955044 2026-05-18 03:49:04,699 - DEBUG - VN ctest-vn-50955044 UUID is 2b80e939-5cfc-4059-b4e1-1b5cad888120 2026-05-18 03:49:05,073 - DEBUG - Response for create_network : {'network': {'id': '7d380deb-20df-481f-b870-3f58364da025', 'name': 'ctest-vn-50095523', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'project_id': '6e76b315242c4f82b1d62f7021093cc0', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vn-50095523'], 'port_security_enabled': True, 'description': ''}} 2026-05-18 03:49:05,328 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c5977d17-770b-4124-b552-e50e5107a208', 'name': '', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '7d380deb-20df-481f-b870-3f58364da025', 'ip_version': 4, 'cidr': '6.7.169.192/26', 'allocation_pools': [{'start': '6.7.169.194', 'end': '6.7.169.254'}], 'gateway_ip': '6.7.169.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '6.7.169.194', 'tags': [], 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:05,353 - INFO - Created VN ctest-vn-50095523 2026-05-18 03:49:05,371 - DEBUG - VN ctest-vn-50095523 UUID is 7d380deb-20df-481f-b870-3f58364da025 2026-05-18 03:49:05,458 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-11810546']} 2026-05-18 03:49:05,796 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-11810546', 'id': '4425e1a1-1bd6-483c-974e-9dc32ffc4bbf', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '2b80e939-5cfc-4059-b4e1-1b5cad888120', 'mac_address': '02:44:25:e1:a1:1b', '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': '152.227.107.3', 'subnet_id': '145823fc-d986-4684-9a86-88dc2b0a40f6'}], 'security_groups': ['1ff39a36-930c-4575-af26-3cba8f4a4b83'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:05,796 - DEBUG - Created port 4425e1a1-1bd6-483c-974e-9dc32ffc4bbf 2026-05-18 03:49:05,873 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-74341433']} 2026-05-18 03:49:06,348 - DEBUG - Created port 07742b29-0ceb-4fb1-9f40-ca557952320c 2026-05-18 03:49:06,472 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-86194228']} 2026-05-18 03:49:06,846 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-86194228', 'id': 'dbf8afcc-cc28-40fc-9899-cff198982311', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '2b80e939-5cfc-4059-b4e1-1b5cad888120', 'mac_address': '02:db:f8:af:cc:cc', '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': '152.227.107.4', 'subnet_id': '145823fc-d986-4684-9a86-88dc2b0a40f6'}], 'security_groups': ['1ff39a36-930c-4575-af26-3cba8f4a4b83'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:06,846 - DEBUG - Created port dbf8afcc-cc28-40fc-9899-cff198982311 2026-05-18 03:49:06,920 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-21749647']} 2026-05-18 03:49:07,400 - DEBUG - Created port bb3d1f3a-1a81-4309-8658-73f92c5f6ca6 2026-05-18 03:49:07,520 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-03760959']} 2026-05-18 03:49:07,849 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-03760959', 'id': '062300ee-5ece-4cc2-9960-c6080b9a7405', 'tenant_id': '6e76b315242c4f82b1d62f7021093cc0', 'network_id': '2b80e939-5cfc-4059-b4e1-1b5cad888120', 'mac_address': '02:06:23:00:ee:5e', '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': '152.227.107.5', 'subnet_id': '145823fc-d986-4684-9a86-88dc2b0a40f6'}], 'security_groups': ['1ff39a36-930c-4575-af26-3cba8f4a4b83'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '6e76b315242c4f82b1d62f7021093cc0'}} 2026-05-18 03:49:07,849 - DEBUG - Created port 062300ee-5ece-4cc2-9960-c6080b9a7405 2026-05-18 03:49:07,928 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91966857', 'ctest-vmi-25398820']} 2026-05-18 03:49:08,408 - DEBUG - Created port 760ba1eb-92e2-45b2-8657-9dea80e5c66f 2026-05-18 03:49:08,527 - INFO - ================================================================================ 2026-05-18 03:49:08,527 - INFO - STARTING TEST : test_vlan_interface_2 2026-05-18 03:49:08,527 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2026-05-18 03:49:09,829 - DEBUG - Nothing to compare xmpp stats {'10.0.0.65': {'10.20.0.129': '0', '10.20.0.25': '2'}, '10.0.0.130': {'10.20.0.25': '0', '10.20.0.129': '3'}} with 2026-05-18 03:49:09,829 - INFO - Initial checks done. Running the testcase now 2026-05-18 03:49:09,829 - INFO - 2026-05-18 03:49:10,032 - DEBUG - Services list from nova: [, , , ] 2026-05-18 03:49:10,714 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5792-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5792-2) 2026-05-18 03:49:12,180 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5792-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5792-1) 2026-05-18 03:49:13,350 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5792-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5792-2) 2026-05-18 03:49:13,511 - INFO - Adding interface with subnet_id 3cd68b78-5d31-4ac1-b9fd-56ee4b90cde6, port_id None to router 6332e1c9-b2b5-4cdc-a82a-5988438a1d74 2026-05-18 03:49:13,968 - INFO - Adding interface with subnet_id c5977d17-770b-4124-b552-e50e5107a208, port_id None to router 6332e1c9-b2b5-4cdc-a82a-5988438a1d74 2026-05-18 03:49:14,566 - INFO - Waiting for VM ctest-TestSubInterfaces-91966857-38686058 to be up.. 2026-05-18 03:49:14,730 - DEBUG - VM is in ACTIVE state now 2026-05-18 03:49:14,730 - INFO - VM name : ctest-TestSubInterfaces-91966857-38686058 2026-05-18 03:49:14,860 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 ID is 0e45214b-6c62-4fed-a06b-ff58942e1186 2026-05-18 03:49:14,899 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 launched on Node an-jenkins-deploy-platform-ansible-os-5792-2 2026-05-18 03:49:15,014 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/0e45214b-6c62-4fed-a06b-ff58942e1186 2026-05-18 03:49:15,344 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/0e45214b-6c62-4fed-a06b-ff58942e1186 2026-05-18 03:49:15,392 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/4425e1a1-1bd6-483c-974e-9dc32ffc4bbf 2026-05-18 03:49:18,586 - 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 1013ms') 2026-05-18 03:49:18,586 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:18,603 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:22,692 - 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 1020ms') 2026-05-18 03:49:22,692 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:22,714 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:26,814 - 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 1027ms') 2026-05-18 03:49:26,814 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:26,830 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:30,908 - 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-18 03:49:30,908 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:30,928 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:35,007 - 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-18 03:49:35,008 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:35,024 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:39,131 - 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 1034ms') 2026-05-18 03:49:39,131 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:39,146 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:43,227 - 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-18 03:49:43,228 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:43,244 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:47,326 - 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-05-18 03:49:47,326 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:47,342 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:51,421 - 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-18 03:49:51,421 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:51,436 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:55,519 - 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-18 03:49:55,519 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:55,538 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:49:59,615 - 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-18 03:49:59,615 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:49:59,637 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:50:03,710 - 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 1009ms') 2026-05-18 03:50:03,710 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 failed! 2026-05-18 03:50:03,726 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91966857:ctest-vn-50955044 is 152.227.107.1 and allocation pool is NOT set 2026-05-18 03:50:07,807 - 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=8.55 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1015ms\r\nrtt min/avg/max/mdev = 8.553/8.553/8.553/0.000 ms') 2026-05-18 03:50:07,807 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-38686058 passed 2026-05-18 03:50:07,880 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:07,880 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:07,953 - 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-18 03:50:08,048 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-18 03:50:13,049 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:13,049 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:13,115 - 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-18 03:50:13,214 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-18 03:50:18,215 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:18,215 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:18,284 - 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-18 03:50:18,388 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-18 03:50:23,389 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:23,389 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:23,469 - 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-18 03:50:23,562 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-18 03:50:28,562 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:28,562 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:28,642 - 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-18 03:50:28,758 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-18 03:50:33,760 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:33,760 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-38686058, IP 152.227.107.3, Port 22 2026-05-18 03:50:33,932 - DEBUG - VM ctest-TestSubInterfaces-91966857-38686058 is ready for SSH connections 2026-05-18 03:50:33,932 - INFO - Waiting for VM ctest-TestSubInterfaces-91966857-93997522 to be up.. 2026-05-18 03:50:34,038 - DEBUG - VM is in ACTIVE state now 2026-05-18 03:50:34,038 - INFO - VM name : ctest-TestSubInterfaces-91966857-93997522 2026-05-18 03:50:34,131 - DEBUG - VM ctest-TestSubInterfaces-91966857-93997522 ID is 07819d7d-bdcf-4a59-acd3-8fbc54bfe8b2 2026-05-18 03:50:34,131 - DEBUG - VM ctest-TestSubInterfaces-91966857-93997522 launched on Node an-jenkins-deploy-platform-ansible-os-5792-1 2026-05-18 03:50:34,232 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/07819d7d-bdcf-4a59-acd3-8fbc54bfe8b2 2026-05-18 03:50:34,243 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/cc454d8a-679a-409e-8f18-0cbd1f2f6b49 2026-05-18 03:50:35,418 - 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.26 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=1.51 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 = 1.509/2.386/3.263/0.877 ms') 2026-05-18 03:50:35,418 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91966857-93997522 passed 2026-05-18 03:50:35,490 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:35,490 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-93997522, IP 6.7.169.196, Port 22 2026-05-18 03:50:35,663 - DEBUG - VM ctest-TestSubInterfaces-91966857-93997522 is ready for SSH connections 2026-05-18 03:50:35,664 - INFO - Waiting for VM ctest-TestSubInterfaces-91966857-05374640 to be up.. 2026-05-18 03:50:35,755 - DEBUG - VM is in ACTIVE state now 2026-05-18 03:50:35,755 - INFO - VM name : ctest-TestSubInterfaces-91966857-05374640 2026-05-18 03:50:35,849 - DEBUG - VM ctest-TestSubInterfaces-91966857-05374640 ID is 2499861a-0894-4711-bde0-891db4cf6ba6 2026-05-18 03:50:35,849 - DEBUG - VM ctest-TestSubInterfaces-91966857-05374640 launched on Node an-jenkins-deploy-platform-ansible-os-5792-2 2026-05-18 03:50:35,943 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/2499861a-0894-4711-bde0-891db4cf6ba6 2026-05-18 03:50:35,954 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/062300ee-5ece-4cc2-9960-c6080b9a7405 2026-05-18 03:50:37,133 - 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=3.96 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=2.04 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.043/3.002/3.961/0.959 ms') 2026-05-18 03:50:37,134 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestSubInterfaces-91966857-05374640 passed 2026-05-18 03:50:37,206 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:50:37,206 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91966857-05374640, IP 152.227.107.5, Port 22 2026-05-18 03:50:37,376 - DEBUG - VM ctest-TestSubInterfaces-91966857-05374640 is ready for SSH connections 2026-05-18 03:50:37,376 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 143.178.22.67 -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.130, gateway password: c0ntrail123 2026-05-18 03:50:37,376 - DEBUG - ifconfig -a| grep 143.178.22.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-18 03:51:00,908 - DEBUG - None 2026-05-18 03:51:05,909 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 143.178.22.67 -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.130, gateway password: c0ntrail123 2026-05-18 03:51:05,910 - DEBUG - ifconfig -a| grep 143.178.22.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-18 03:51:08,789 - DEBUG - None 2026-05-18 03:51:13,790 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 143.178.22.67 -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.130, gateway password: c0ntrail123 2026-05-18 03:51:13,790 - DEBUG - ifconfig -a| grep 143.178.22.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-18 03:51:15,471 - DEBUG - None 2026-05-18 03:51:20,472 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 143.178.22.67 -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.130, gateway password: c0ntrail123 2026-05-18 03:51:20,473 - DEBUG - ifconfig -a| grep 143.178.22.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-18 03:51:21,638 - DEBUG - eth0.100 2026-05-18 03:51:21,639 - INFO - Interface eth0.100 is found on VM 0e45214b-6c62-4fed-a06b-ff58942e1186 2026-05-18 03:51:21,639 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 6.7.169.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.130, gateway password: c0ntrail123 2026-05-18 03:51:21,639 - DEBUG - ifconfig -a| grep 6.7.169.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-18 03:52:02,313 - DEBUG - eth0.100 2026-05-18 03:52:02,313 - INFO - Interface eth0.100 is found on VM 2499861a-0894-4711-bde0-891db4cf6ba6 2026-05-18 03:52:02,313 - DEBUG - Running remote_cmd, Cmd : route add -net 6.7.169.192/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-05-18 03:52:02,314 - DEBUG - route add -net 6.7.169.192/26 dev eth0.100 2026-05-18 03:52:02,993 - DEBUG - None 2026-05-18 03:52:02,993 - DEBUG - Running remote_cmd, Cmd : route add -net 143.178.22.64/26 dev eth0.100, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-05-18 03:52:02,993 - DEBUG - route add -net 143.178.22.64/26 dev eth0.100 2026-05-18 03:52:03,682 - DEBUG - None 2026-05-18 03:52:03,682 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-18 03:52:03,683 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 6.7.169.196, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-05-18 03:52:03,683 - DEBUG - ping -s 56 -c 3 -W 1 6.7.169.196 2026-05-18 03:52:06,274 - DEBUG - PING 6.7.169.196 (6.7.169.196) 56(84) bytes of data. 64 bytes from 6.7.169.196: icmp_req=1 ttl=63 time=13.5 ms 64 bytes from 6.7.169.196: icmp_req=2 ttl=63 time=1.76 ms 64 bytes from 6.7.169.196: icmp_req=3 ttl=63 time=1.44 ms --- 6.7.169.196 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.446/5.591/13.565/5.640 ms 2026-05-18 03:52:06,274 - INFO - Ping to IP 6.7.169.196 from VM ctest-TestSubInterfaces-91966857-38686058 passed 2026-05-18 03:52:06,274 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 6.7.169.195, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123 2026-05-18 03:52:06,275 - DEBUG - ping -s 56 -c 3 -W 1 6.7.169.195 2026-05-18 03:52:08,854 - DEBUG - PING 6.7.169.195 (6.7.169.195) 56(84) bytes of data. 64 bytes from 6.7.169.195: icmp_req=1 ttl=63 time=8.38 ms 64 bytes from 6.7.169.195: icmp_req=2 ttl=63 time=0.935 ms 64 bytes from 6.7.169.195: icmp_req=3 ttl=63 time=0.835 ms --- 6.7.169.195 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2003ms rtt min/avg/max/mdev = 0.835/3.385/8.386/3.536 ms 2026-05-18 03:52:08,854 - INFO - Ping to IP 6.7.169.195 from VM ctest-TestSubInterfaces-91966857-38686058 passed 2026-05-18 03:52:08,854 - INFO - Deleting interface with subnet_id c5977d17-770b-4124-b552-e50e5107a208, port_id None from router 6332e1c9-b2b5-4cdc-a82a-5988438a1d74 2026-05-18 03:52:09,108 - INFO - Deleting interface with subnet_id 3cd68b78-5d31-4ac1-b9fd-56ee4b90cde6, port_id None from router 6332e1c9-b2b5-4cdc-a82a-5988438a1d74 2026-05-18 03:52:09,429 - INFO - Detaching port 062300ee-5ece-4cc2-9960-c6080b9a7405 from VM ctest-TestSubInterfaces-91966857-05374640 2026-05-18 03:52:09,470 - INFO - Deleting VM ctest-TestSubInterfaces-91966857-05374640 2026-05-18 03:52:09,594 - INFO - Deleting VM ctest-TestSubInterfaces-91966857-93997522 2026-05-18 03:52:09,682 - INFO - Detaching port 4425e1a1-1bd6-483c-974e-9dc32ffc4bbf from VM ctest-TestSubInterfaces-91966857-38686058 2026-05-18 03:52:09,714 - INFO - Deleting VM ctest-TestSubInterfaces-91966857-38686058 2026-05-18 03:52:11,113 - DEBUG - No XMPP flaps were noticed during the test
2026-05-18 03:52:11,113 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:03:03]
2026-05-18 03:52:11,113 - INFO - -------------------------------------------------------------------------------- 2026-05-18 03:52:11,253 - INFO - Deleted port 760ba1eb-92e2-45b2-8657-9dea80e5c66f 2026-05-18 03:52:11,517 - DEBUG - Response for delete_port : () 2026-05-18 03:52:11,517 - INFO - Deleted port 062300ee-5ece-4cc2-9960-c6080b9a7405 2026-05-18 03:52:11,656 - INFO - Deleted port bb3d1f3a-1a81-4309-8658-73f92c5f6ca6 2026-05-18 03:52:11,825 - DEBUG - Response for delete_port : () 2026-05-18 03:52:11,825 - INFO - Deleted port dbf8afcc-cc28-40fc-9899-cff198982311 2026-05-18 03:52:11,950 - INFO - Deleted port 07742b29-0ceb-4fb1-9f40-ca557952320c 2026-05-18 03:52:12,195 - DEBUG - Response for delete_port : () 2026-05-18 03:52:12,195 - INFO - Deleted port 4425e1a1-1bd6-483c-974e-9dc32ffc4bbf 2026-05-18 03:52:12,195 - INFO - Deleting VN ctest-vn-50095523 2026-05-18 03:52:12,402 - DEBUG - Response for deleting network () 2026-05-18 03:52:12,402 - INFO - Deleting VN ctest-vn-50955044 2026-05-18 03:52:12,554 - DEBUG - Response for deleting network () 2026-05-18 03:52:12,554 - INFO - Deleting VN ctest-vn-36463906 2026-05-18 03:52:12,730 - DEBUG - Response for deleting network () 2026-05-18 03:52:13,560 - INFO - Deleted project: ctest-TestSubInterfaces-91966857, ID : 6e76b315-242c-4f82-b1d6-2f7021093cc0