2025-08-11 03:22:48,435 - INFO - Domain Default found not creating 2025-08-11 03:22:48,591 - INFO - Project ctest-TestSubInterfaces-56849397 not found, creating it 2025-08-11 03:22:49,085 - INFO - Created Project:ctest-TestSubInterfaces-56849397, ID : bdbcbe8b-edde-4ee8-ac46-604d83bde384 2025-08-11 03:22:51,701 - DEBUG - Response for create_network : {'network': {'id': '631ad353-4bc4-40d6-a45b-2f17e7aba3db', 'name': 'ctest-vn-10966688', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vn-10966688'], 'port_security_enabled': True, 'description': ''}} 2025-08-11 03:22:52,012 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a96255a9-8041-4e73-93ed-b5eb1dfc5852', 'name': '', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': '631ad353-4bc4-40d6-a45b-2f17e7aba3db', 'ip_version': 4, 'cidr': '208.237.188.192/26', 'allocation_pools': [{'start': '208.237.188.194', 'end': '208.237.188.254'}], 'gateway_ip': '208.237.188.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '208.237.188.194', 'tags': [], 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:52,033 - INFO - Created VN ctest-vn-10966688 2025-08-11 03:22:52,047 - DEBUG - VN ctest-vn-10966688 UUID is 631ad353-4bc4-40d6-a45b-2f17e7aba3db 2025-08-11 03:22:52,359 - DEBUG - Response for create_network : {'network': {'id': 'cf421fb1-c9bb-455b-ac30-a309cbf65ded', 'name': 'ctest-vn-17187359', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vn-17187359'], 'port_security_enabled': True, 'description': ''}} 2025-08-11 03:22:52,571 - DEBUG - Response for create_subnet : {'subnet': {'id': '56df21ae-3fab-450a-b7de-b39994beea36', 'name': '', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': 'cf421fb1-c9bb-455b-ac30-a309cbf65ded', 'ip_version': 4, 'cidr': '96.214.5.192/26', 'allocation_pools': [{'start': '96.214.5.194', 'end': '96.214.5.254'}], 'gateway_ip': '96.214.5.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '96.214.5.194', 'tags': [], 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:52,594 - INFO - Created VN ctest-vn-17187359 2025-08-11 03:22:52,606 - DEBUG - VN ctest-vn-17187359 UUID is cf421fb1-c9bb-455b-ac30-a309cbf65ded 2025-08-11 03:22:52,928 - DEBUG - Response for create_network : {'network': {'id': '9f567031-a18a-4044-bb7f-ce28cf4294ef', 'name': 'ctest-vn-05196645', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vn-05196645'], 'port_security_enabled': True, 'description': ''}} 2025-08-11 03:22:53,185 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c0ea9446-6fa9-4134-bfe2-9cd486d2b049', 'name': '', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': '9f567031-a18a-4044-bb7f-ce28cf4294ef', 'ip_version': 4, 'cidr': '120.95.14.128/26', 'allocation_pools': [{'start': '120.95.14.130', 'end': '120.95.14.190'}], 'gateway_ip': '120.95.14.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '120.95.14.130', 'tags': [], 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:53,207 - INFO - Created VN ctest-vn-05196645 2025-08-11 03:22:53,219 - DEBUG - VN ctest-vn-05196645 UUID is 9f567031-a18a-4044-bb7f-ce28cf4294ef 2025-08-11 03:22:53,293 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-77000347']} 2025-08-11 03:22:53,607 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-77000347', 'id': '7c03b2c7-0b17-4f9b-b67c-34735912b20c', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': 'cf421fb1-c9bb-455b-ac30-a309cbf65ded', 'mac_address': '02:7c:03:b2:c7:0b', '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': '96.214.5.195', 'subnet_id': '56df21ae-3fab-450a-b7de-b39994beea36'}], 'security_groups': ['316ec612-d25f-46a7-b3ed-df97a5424623'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:53,607 - DEBUG - Created port 7c03b2c7-0b17-4f9b-b67c-34735912b20c 2025-08-11 03:22:53,684 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-67161524']} 2025-08-11 03:22:54,119 - DEBUG - Created port 8cfd90f3-a043-4fd0-81d8-a0efa4f48d19 2025-08-11 03:22:54,235 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-10128465']} 2025-08-11 03:22:54,516 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-10128465', 'id': '0c5dfb53-20d1-433e-8754-d2ef12e1f7fc', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': 'cf421fb1-c9bb-455b-ac30-a309cbf65ded', 'mac_address': '02:0c:5d:fb:53:20', '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': '96.214.5.196', 'subnet_id': '56df21ae-3fab-450a-b7de-b39994beea36'}], 'security_groups': ['316ec612-d25f-46a7-b3ed-df97a5424623'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:54,516 - DEBUG - Created port 0c5dfb53-20d1-433e-8754-d2ef12e1f7fc 2025-08-11 03:22:54,582 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-24618299']} 2025-08-11 03:22:54,999 - DEBUG - Created port cab729b8-8dcb-490b-ad6a-b0f8c3a07834 2025-08-11 03:22:55,107 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-73104667']} 2025-08-11 03:22:55,412 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-73104667', 'id': '1740caf5-541b-459a-866c-5cab69f164bd', 'tenant_id': 'bdbcbe8bedde4ee8ac46604d83bde384', 'network_id': 'cf421fb1-c9bb-455b-ac30-a309cbf65ded', 'mac_address': '02:17:40:ca:f5:54', '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': '96.214.5.197', 'subnet_id': '56df21ae-3fab-450a-b7de-b39994beea36'}], 'security_groups': ['316ec612-d25f-46a7-b3ed-df97a5424623'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': 'bdbcbe8bedde4ee8ac46604d83bde384'}} 2025-08-11 03:22:55,412 - DEBUG - Created port 1740caf5-541b-459a-866c-5cab69f164bd 2025-08-11 03:22:55,482 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-56849397', 'ctest-vmi-42624040']} 2025-08-11 03:22:55,879 - DEBUG - Created port e389c747-c8f9-4d48-be01-66dac47a9b90 2025-08-11 03:22:55,989 - INFO - ================================================================================ 2025-08-11 03:22:55,989 - INFO - STARTING TEST : test_vlan_interface_2 2025-08-11 03:22:55,989 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2025-08-11 03:22:57,246 - DEBUG - Nothing to compare xmpp stats {'10.0.0.57': {'10.20.0.18': '0', '10.20.0.129': '0'}, '10.0.0.65': {'10.20.0.129': '0', '10.20.0.25': '0'}} with 2025-08-11 03:22:57,246 - INFO - Initial checks done. Running the testcase now 2025-08-11 03:22:57,246 - INFO - 2025-08-11 03:22:57,298 - DEBUG - Services list from nova: [, , , ] 2025-08-11 03:22:57,645 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-2) 2025-08-11 03:22:58,850 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-1) 2025-08-11 03:22:59,637 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-2) 2025-08-11 03:22:59,785 - INFO - Adding interface with subnet_id a96255a9-8041-4e73-93ed-b5eb1dfc5852, port_id None to router 71fc5608-6dab-4342-8e83-4e287ce22c8e 2025-08-11 03:23:00,203 - INFO - Adding interface with subnet_id c0ea9446-6fa9-4134-bfe2-9cd486d2b049, port_id None to router 71fc5608-6dab-4342-8e83-4e287ce22c8e 2025-08-11 03:23:00,708 - INFO - Waiting for VM ctest-TestSubInterfaces-56849397-40954555 to be up.. 2025-08-11 03:23:00,831 - DEBUG - VM is in ACTIVE state now 2025-08-11 03:23:00,831 - INFO - VM name : ctest-TestSubInterfaces-56849397-40954555 2025-08-11 03:23:00,929 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 ID is 972af883-0d1b-4283-b9ea-698ceb98de00 2025-08-11 03:23:00,958 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 launched on Node an-jenkins-deploy-platform-ansible-os-3794-2 2025-08-11 03:23:01,046 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/972af883-0d1b-4283-b9ea-698ceb98de00 2025-08-11 03:23:01,339 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/972af883-0d1b-4283-b9ea-698ceb98de00 2025-08-11 03:23:01,597 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/7c03b2c7-0b17-4f9b-b67c-34735912b20c 2025-08-11 03:23:04,905 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms') 2025-08-11 03:23:04,906 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:04,923 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:08,999 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-08-11 03:23:08,999 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:09,014 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:13,099 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2025-08-11 03:23:13,099 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:13,115 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:17,192 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-08-11 03:23:17,192 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:17,214 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:21,290 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms') 2025-08-11 03:23:21,290 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:21,304 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:25,388 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-11 03:23:25,388 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:25,403 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:29,476 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms') 2025-08-11 03:23:29,476 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:29,495 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:33,578 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-08-11 03:23:33,578 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:33,593 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:37,666 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1000ms') 2025-08-11 03:23:37,666 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:37,683 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:41,768 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1025ms') 2025-08-11 03:23:41,768 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 failed! 2025-08-11 03:23:41,789 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-56849397:ctest-vn-17187359 is 96.214.5.193 and allocation pool is NOT set 2025-08-11 03:23:43,865 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=4.74 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=6.32 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 4.738/5.527/6.317/0.789 ms') 2025-08-11 03:23:43,865 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-40954555 passed 2025-08-11 03:23:43,976 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:23:43,976 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-40954555, IP 96.214.5.195, Port 22 2025-08-11 03:23:44,044 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-11 03:23:44,168 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 03:23:49,169 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:23:49,169 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-40954555, IP 96.214.5.195, Port 22 2025-08-11 03:23:49,242 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-11 03:23:49,324 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 03:23:54,325 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:23:54,325 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-40954555, IP 96.214.5.195, Port 22 2025-08-11 03:23:54,402 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-11 03:23:54,488 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 03:23:59,489 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:23:59,489 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-40954555, IP 96.214.5.195, Port 22 2025-08-11 03:23:59,567 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-11 03:23:59,645 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-11 03:24:04,646 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:24:04,647 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-40954555, IP 96.214.5.195, Port 22 2025-08-11 03:24:04,825 - DEBUG - VM ctest-TestSubInterfaces-56849397-40954555 is ready for SSH connections 2025-08-11 03:24:04,825 - INFO - Waiting for VM ctest-TestSubInterfaces-56849397-23509740 to be up.. 2025-08-11 03:24:04,937 - DEBUG - VM is in ACTIVE state now 2025-08-11 03:24:04,937 - INFO - VM name : ctest-TestSubInterfaces-56849397-23509740 2025-08-11 03:24:05,028 - DEBUG - VM ctest-TestSubInterfaces-56849397-23509740 ID is d402381f-2693-42a9-b6f9-41b159cc8025 2025-08-11 03:24:05,029 - DEBUG - VM ctest-TestSubInterfaces-56849397-23509740 launched on Node an-jenkins-deploy-platform-ansible-os-3794-1 2025-08-11 03:24:05,125 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/d402381f-2693-42a9-b6f9-41b159cc8025 2025-08-11 03:24:05,136 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/0eaea9dc-4430-4499-b9b3-50590e6e543b 2025-08-11 03:24:06,571 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=3.50 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.495 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.495/1.999/3.503/1.504 ms') 2025-08-11 03:24:06,572 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-56849397-23509740 passed 2025-08-11 03:24:06,685 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:24:06,685 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-23509740, IP 120.95.14.132, Port 22 2025-08-11 03:24:06,854 - DEBUG - VM ctest-TestSubInterfaces-56849397-23509740 is ready for SSH connections 2025-08-11 03:24:06,854 - INFO - Waiting for VM ctest-TestSubInterfaces-56849397-68683192 to be up.. 2025-08-11 03:24:06,937 - DEBUG - VM is in ACTIVE state now 2025-08-11 03:24:06,937 - INFO - VM name : ctest-TestSubInterfaces-56849397-68683192 2025-08-11 03:24:07,015 - DEBUG - VM ctest-TestSubInterfaces-56849397-68683192 ID is 793f9a0d-9d12-4c9f-97d2-3a9ecf5a6ea6 2025-08-11 03:24:07,015 - DEBUG - VM ctest-TestSubInterfaces-56849397-68683192 launched on Node an-jenkins-deploy-platform-ansible-os-3794-2 2025-08-11 03:24:07,093 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/793f9a0d-9d12-4c9f-97d2-3a9ecf5a6ea6 2025-08-11 03:24:07,106 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/1740caf5-541b-459a-866c-5cab69f164bd 2025-08-11 03:24:08,331 - 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=6.08 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.462 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.462/3.272/6.083/2.810 ms') 2025-08-11 03:24:08,331 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-56849397-68683192 passed 2025-08-11 03:24:08,448 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:24:08,448 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-56849397-68683192, IP 96.214.5.197, Port 22 2025-08-11 03:24:08,619 - DEBUG - VM ctest-TestSubInterfaces-56849397-68683192 is ready for SSH connections 2025-08-11 03:24:08,619 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:24:08,619 - DEBUG - ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-11 03:24:28,198 - DEBUG - None 2025-08-11 03:24:33,198 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:24:33,198 - DEBUG - ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-11 03:24:35,050 - DEBUG - None 2025-08-11 03:24:40,051 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:24:40,051 - DEBUG - ifconfig -a| grep 208.237.188.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-11 03:24:41,800 - DEBUG - eth0.100 2025-08-11 03:24:41,801 - INFO - Interface eth0.100 is found on VM 972af883-0d1b-4283-b9ea-698ceb98de00 2025-08-11 03:24:41,801 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 120.95.14.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.65, gateway password: c0ntrail123 2025-08-11 03:24:41,801 - DEBUG - ifconfig -a| grep 120.95.14.131 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-11 03:25:18,942 - DEBUG - eth0.100 2025-08-11 03:25:18,942 - INFO - Interface eth0.100 is found on VM 793f9a0d-9d12-4c9f-97d2-3a9ecf5a6ea6 2025-08-11 03:25:18,942 - DEBUG - Running remote_cmd, Cmd : route add -net 120.95.14.128/26 dev eth0.100, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:25:18,942 - DEBUG - route add -net 120.95.14.128/26 dev eth0.100 2025-08-11 03:25:19,435 - DEBUG - None 2025-08-11 03:25:19,435 - DEBUG - Running remote_cmd, Cmd : route add -net 208.237.188.192/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:25:19,435 - DEBUG - route add -net 208.237.188.192/26 dev eth0.100 2025-08-11 03:25:20,005 - DEBUG - None 2025-08-11 03:25:20,005 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-11 03:25:20,005 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 120.95.14.132, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:25:20,005 - DEBUG - ping -s 56 -c 3 -W 1 120.95.14.132 2025-08-11 03:25:22,471 - DEBUG - PING 120.95.14.132 (120.95.14.132) 56(84) bytes of data. 64 bytes from 120.95.14.132: icmp_req=1 ttl=63 time=10.0 ms 64 bytes from 120.95.14.132: icmp_req=2 ttl=63 time=1.31 ms 64 bytes from 120.95.14.132: icmp_req=3 ttl=63 time=1.12 ms --- 120.95.14.132 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2005ms rtt min/avg/max/mdev = 1.122/4.151/10.016/4.148 ms 2025-08-11 03:25:22,471 - INFO - Ping to IP 120.95.14.132 from VM ctest-TestSubInterfaces-56849397-40954555 passed 2025-08-11 03:25:22,471 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 120.95.14.131, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.65, gateway password: c0ntrail123 2025-08-11 03:25:22,471 - DEBUG - ping -s 56 -c 3 -W 1 120.95.14.131 2025-08-11 03:25:24,947 - DEBUG - PING 120.95.14.131 (120.95.14.131) 56(84) bytes of data. 64 bytes from 120.95.14.131: icmp_req=1 ttl=63 time=9.91 ms 64 bytes from 120.95.14.131: icmp_req=2 ttl=63 time=0.862 ms 64 bytes from 120.95.14.131: icmp_req=3 ttl=63 time=0.778 ms --- 120.95.14.131 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 0.778/3.853/9.919/4.289 ms 2025-08-11 03:25:24,948 - INFO - Ping to IP 120.95.14.131 from VM ctest-TestSubInterfaces-56849397-40954555 passed 2025-08-11 03:25:24,948 - INFO - Deleting interface with subnet_id c0ea9446-6fa9-4134-bfe2-9cd486d2b049, port_id None from router 71fc5608-6dab-4342-8e83-4e287ce22c8e 2025-08-11 03:25:25,163 - INFO - Deleting interface with subnet_id a96255a9-8041-4e73-93ed-b5eb1dfc5852, port_id None from router 71fc5608-6dab-4342-8e83-4e287ce22c8e 2025-08-11 03:25:25,465 - INFO - Detaching port 1740caf5-541b-459a-866c-5cab69f164bd from VM ctest-TestSubInterfaces-56849397-68683192 2025-08-11 03:25:25,509 - INFO - Deleting VM ctest-TestSubInterfaces-56849397-68683192 2025-08-11 03:25:25,588 - INFO - Deleting VM ctest-TestSubInterfaces-56849397-23509740 2025-08-11 03:25:25,706 - INFO - Detaching port 7c03b2c7-0b17-4f9b-b67c-34735912b20c from VM ctest-TestSubInterfaces-56849397-40954555 2025-08-11 03:25:25,763 - INFO - Deleting VM ctest-TestSubInterfaces-56849397-40954555 2025-08-11 03:25:27,182 - DEBUG - No XMPP flaps were noticed during the test
2025-08-11 03:25:27,182 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:02:32]
2025-08-11 03:25:27,182 - INFO - -------------------------------------------------------------------------------- 2025-08-11 03:25:27,324 - INFO - Deleted port e389c747-c8f9-4d48-be01-66dac47a9b90 2025-08-11 03:25:27,539 - DEBUG - Response for delete_port : () 2025-08-11 03:25:27,539 - INFO - Deleted port 1740caf5-541b-459a-866c-5cab69f164bd 2025-08-11 03:25:27,651 - INFO - Deleted port cab729b8-8dcb-490b-ad6a-b0f8c3a07834 2025-08-11 03:25:27,835 - DEBUG - Response for delete_port : () 2025-08-11 03:25:27,835 - INFO - Deleted port 0c5dfb53-20d1-433e-8754-d2ef12e1f7fc 2025-08-11 03:25:27,984 - INFO - Deleted port 8cfd90f3-a043-4fd0-81d8-a0efa4f48d19 2025-08-11 03:25:28,179 - DEBUG - Response for delete_port : () 2025-08-11 03:25:28,179 - INFO - Deleted port 7c03b2c7-0b17-4f9b-b67c-34735912b20c 2025-08-11 03:25:28,179 - INFO - Deleting VN ctest-vn-05196645 2025-08-11 03:25:28,351 - DEBUG - Response for deleting network () 2025-08-11 03:25:28,351 - INFO - Deleting VN ctest-vn-17187359 2025-08-11 03:25:28,504 - DEBUG - Response for deleting network () 2025-08-11 03:25:28,505 - INFO - Deleting VN ctest-vn-10966688 2025-08-11 03:25:28,686 - DEBUG - Response for deleting network () 2025-08-11 03:25:29,660 - INFO - Deleted project: ctest-TestSubInterfaces-56849397, ID : bdbcbe8b-edde-4ee8-ac46-604d83bde384