2026-05-28 03:45:26,997 - INFO - Domain Default found not creating 2026-05-28 03:45:27,230 - INFO - Project ctest-TestSubInterfaces-91991022 not found, creating it 2026-05-28 03:45:27,836 - INFO - Created Project:ctest-TestSubInterfaces-91991022, ID : 53cb4697-cdbb-443b-ba15-09e089438c5f 2026-05-28 03:45:30,824 - DEBUG - Response for create_network : {'network': {'id': 'd0ba2ef3-5677-4376-9a3d-ee86313e6191', 'name': 'ctest-vn-24362507', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'project_id': '53cb4697cdbb443bba1509e089438c5f', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vn-24362507'], 'port_security_enabled': True, 'description': ''}} 2026-05-28 03:45:31,159 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd1c6d618-ccdd-4600-aae7-ef0ab28da3b1', 'name': '', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'd0ba2ef3-5677-4376-9a3d-ee86313e6191', 'ip_version': 4, 'cidr': '174.63.233.0/26', 'allocation_pools': [{'start': '174.63.233.2', 'end': '174.63.233.62'}], 'gateway_ip': '174.63.233.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '174.63.233.2', 'tags': [], 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:31,203 - INFO - Created VN ctest-vn-24362507 2026-05-28 03:45:31,219 - DEBUG - VN ctest-vn-24362507 UUID is d0ba2ef3-5677-4376-9a3d-ee86313e6191 2026-05-28 03:45:31,618 - DEBUG - Response for create_network : {'network': {'id': 'e4659e96-2e3d-4d2c-9118-f13e41ffbcd1', 'name': 'ctest-vn-01343241', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'project_id': '53cb4697cdbb443bba1509e089438c5f', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vn-01343241'], 'port_security_enabled': True, 'description': ''}} 2026-05-28 03:45:31,899 - DEBUG - Response for create_subnet : {'subnet': {'id': '8ac15631-f693-45a6-a7a2-1af1bce75cca', 'name': '', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'e4659e96-2e3d-4d2c-9118-f13e41ffbcd1', 'ip_version': 4, 'cidr': '175.146.225.128/26', 'allocation_pools': [{'start': '175.146.225.130', 'end': '175.146.225.190'}], 'gateway_ip': '175.146.225.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '175.146.225.130', 'tags': [], 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:31,932 - INFO - Created VN ctest-vn-01343241 2026-05-28 03:45:31,954 - DEBUG - VN ctest-vn-01343241 UUID is e4659e96-2e3d-4d2c-9118-f13e41ffbcd1 2026-05-28 03:45:32,380 - DEBUG - Response for create_network : {'network': {'id': 'a96112af-1dc2-41d3-9c44-a35ce65c9871', 'name': 'ctest-vn-15237971', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'project_id': '53cb4697cdbb443bba1509e089438c5f', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vn-15237971'], 'port_security_enabled': True, 'description': ''}} 2026-05-28 03:45:32,691 - DEBUG - Response for create_subnet : {'subnet': {'id': '6523f706-38f2-4e61-8c98-aca2cf5f2c41', 'name': '', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'a96112af-1dc2-41d3-9c44-a35ce65c9871', 'ip_version': 4, 'cidr': '151.39.107.64/26', 'allocation_pools': [{'start': '151.39.107.66', 'end': '151.39.107.126'}], 'gateway_ip': '151.39.107.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '151.39.107.66', 'tags': [], 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:32,725 - INFO - Created VN ctest-vn-15237971 2026-05-28 03:45:32,740 - DEBUG - VN ctest-vn-15237971 UUID is a96112af-1dc2-41d3-9c44-a35ce65c9871 2026-05-28 03:45:32,851 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-37312464']} 2026-05-28 03:45:33,361 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-37312464', 'id': '07ce008c-3ac6-447d-8a72-33564991359c', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'e4659e96-2e3d-4d2c-9118-f13e41ffbcd1', 'mac_address': '02:07:ce:00:8c:3a', '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': '175.146.225.131', 'subnet_id': '8ac15631-f693-45a6-a7a2-1af1bce75cca'}], 'security_groups': ['33572556-a234-4426-8865-6d97e510d7f6'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:33,361 - DEBUG - Created port 07ce008c-3ac6-447d-8a72-33564991359c 2026-05-28 03:45:33,443 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-76287701']} 2026-05-28 03:45:33,933 - DEBUG - Created port dde55735-4ec9-45f4-9945-615df29aec90 2026-05-28 03:45:34,057 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-45659610']} 2026-05-28 03:45:34,404 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-45659610', 'id': '3590ae0c-0c30-47eb-86a2-d0142db7cfa0', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'e4659e96-2e3d-4d2c-9118-f13e41ffbcd1', 'mac_address': '02:35:90:ae:0c:0c', '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': '175.146.225.132', 'subnet_id': '8ac15631-f693-45a6-a7a2-1af1bce75cca'}], 'security_groups': ['33572556-a234-4426-8865-6d97e510d7f6'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:34,404 - DEBUG - Created port 3590ae0c-0c30-47eb-86a2-d0142db7cfa0 2026-05-28 03:45:34,485 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-79378467']} 2026-05-28 03:45:34,945 - DEBUG - Created port 14983ec8-95af-4de2-b7d1-86bc258b3728 2026-05-28 03:45:35,065 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-31353036']} 2026-05-28 03:45:35,409 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-31353036', 'id': '9c61fcb2-b85b-4435-96b2-4a16784e240b', 'tenant_id': '53cb4697cdbb443bba1509e089438c5f', 'network_id': 'e4659e96-2e3d-4d2c-9118-f13e41ffbcd1', 'mac_address': '02:9c:61:fc:b2:b8', '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': '175.146.225.133', 'subnet_id': '8ac15631-f693-45a6-a7a2-1af1bce75cca'}], 'security_groups': ['33572556-a234-4426-8865-6d97e510d7f6'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '53cb4697cdbb443bba1509e089438c5f'}} 2026-05-28 03:45:35,409 - DEBUG - Created port 9c61fcb2-b85b-4435-96b2-4a16784e240b 2026-05-28 03:45:35,492 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-91991022', 'ctest-vmi-82976550']} 2026-05-28 03:45:36,089 - DEBUG - Created port c7316889-36f5-4adb-aec1-931ae7dd42b6 2026-05-28 03:45:36,216 - INFO - ================================================================================ 2026-05-28 03:45:36,217 - INFO - STARTING TEST : test_vlan_interface_2 2026-05-28 03:45:36,217 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2026-05-28 03:45:37,557 - DEBUG - Nothing to compare xmpp stats {'10.0.0.48': {'10.20.0.252': '1', '10.20.0.249': '0'}, '10.0.0.49': {'10.20.0.249': '0', '10.20.0.19': '0'}} with 2026-05-28 03:45:37,557 - INFO - Initial checks done. Running the testcase now 2026-05-28 03:45:37,557 - INFO - 2026-05-28 03:45:37,842 - DEBUG - Services list from nova: [, , , ] 2026-05-28 03:45:38,613 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5841-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5841-1) 2026-05-28 03:45:40,457 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5841-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5841-2) 2026-05-28 03:45:41,910 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5841-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5841-1) 2026-05-28 03:45:42,129 - INFO - Adding interface with subnet_id d1c6d618-ccdd-4600-aae7-ef0ab28da3b1, port_id None to router 3660276f-6c1a-40b2-85f7-c67275ee8a48 2026-05-28 03:45:42,541 - INFO - Adding interface with subnet_id 6523f706-38f2-4e61-8c98-aca2cf5f2c41, port_id None to router 3660276f-6c1a-40b2-85f7-c67275ee8a48 2026-05-28 03:45:43,265 - INFO - Waiting for VM ctest-TestSubInterfaces-91991022-27488577 to be up.. 2026-05-28 03:45:43,535 - DEBUG - VM is in ACTIVE state now 2026-05-28 03:45:43,536 - INFO - VM name : ctest-TestSubInterfaces-91991022-27488577 2026-05-28 03:45:43,696 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 ID is 5101241b-9b2b-46de-b245-26c8d13868c9 2026-05-28 03:45:43,781 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 launched on Node an-jenkins-deploy-platform-ansible-os-5841-1 2026-05-28 03:45:43,931 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine/5101241b-9b2b-46de-b245-26c8d13868c9 2026-05-28 03:45:44,263 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine/5101241b-9b2b-46de-b245-26c8d13868c9 2026-05-28 03:45:44,313 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine-interface/07ce008c-3ac6-447d-8a72-33564991359c 2026-05-28 03:45:47,582 - 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-28 03:45:47,582 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:45:47,599 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:45:51,680 - 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-28 03:45:51,681 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:45:51,704 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:45:55,779 - 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-28 03:45:55,779 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:45:55,796 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:45:59,868 - 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-28 03:45:59,868 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:45:59,886 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:03,970 - 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-28 03:46:03,970 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:03,993 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:08,062 - 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 1002ms') 2026-05-28 03:46:08,062 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:08,084 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:12,162 - 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-28 03:46:12,162 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:12,179 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:16,254 - 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-28 03:46:16,254 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:16,271 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:20,351 - 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-28 03:46:20,351 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:20,369 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:24,451 - 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-28 03:46:24,451 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:24,475 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:28,543 - 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-28 03:46:28,543 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 failed! 2026-05-28 03:46:28,560 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-91991022:ctest-vn-01343241 is 175.146.225.129 and allocation pool is NOT set 2026-05-28 03:46:32,637 - 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=5.45 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1013ms\r\nrtt min/avg/max/mdev = 5.449/5.449/5.449/0.000 ms') 2026-05-28 03:46:32,637 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-27488577 passed 2026-05-28 03:46:32,724 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:32,725 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:32,795 - 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-28 03:46:32,941 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-28 03:46:37,942 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:37,942 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:38,013 - 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-28 03:46:38,144 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-28 03:46:43,145 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:43,145 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:43,214 - 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-28 03:46:43,342 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-28 03:46:48,343 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:48,343 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:48,410 - 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-28 03:46:48,520 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-28 03:46:53,521 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:53,521 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:53,591 - 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-28 03:46:53,704 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is NOT ready for SSH connections, VM status: ACTIVE 2026-05-28 03:46:58,705 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:46:58,706 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-27488577, IP 175.146.225.131, Port 22 2026-05-28 03:46:58,879 - DEBUG - VM ctest-TestSubInterfaces-91991022-27488577 is ready for SSH connections 2026-05-28 03:46:58,880 - INFO - Waiting for VM ctest-TestSubInterfaces-91991022-41314851 to be up.. 2026-05-28 03:46:59,000 - DEBUG - VM is in ACTIVE state now 2026-05-28 03:46:59,001 - INFO - VM name : ctest-TestSubInterfaces-91991022-41314851 2026-05-28 03:46:59,122 - DEBUG - VM ctest-TestSubInterfaces-91991022-41314851 ID is bd69e830-79bd-4c89-9d85-9219877562e1 2026-05-28 03:46:59,122 - DEBUG - VM ctest-TestSubInterfaces-91991022-41314851 launched on Node an-jenkins-deploy-platform-ansible-os-5841-2 2026-05-28 03:46:59,230 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine/bd69e830-79bd-4c89-9d85-9219877562e1 2026-05-28 03:46:59,243 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine-interface/531faced-60a2-4ae7-9778-be360c68f4ae 2026-05-28 03:47:00,437 - 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.44 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=1.47 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 = 1.465/2.454/3.444/0.989 ms') 2026-05-28 03:47:00,437 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-91991022-41314851 passed 2026-05-28 03:47:00,517 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:47:00,517 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-41314851, IP 151.39.107.68, Port 22 2026-05-28 03:47:00,695 - DEBUG - VM ctest-TestSubInterfaces-91991022-41314851 is ready for SSH connections 2026-05-28 03:47:00,695 - INFO - Waiting for VM ctest-TestSubInterfaces-91991022-76163626 to be up.. 2026-05-28 03:47:00,833 - DEBUG - VM is in ACTIVE state now 2026-05-28 03:47:00,833 - INFO - VM name : ctest-TestSubInterfaces-91991022-76163626 2026-05-28 03:47:00,954 - DEBUG - VM ctest-TestSubInterfaces-91991022-76163626 ID is c8794459-be27-4499-aaef-f9c25adc58ec 2026-05-28 03:47:00,954 - DEBUG - VM ctest-TestSubInterfaces-91991022-76163626 launched on Node an-jenkins-deploy-platform-ansible-os-5841-1 2026-05-28 03:47:01,092 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine/c8794459-be27-4499-aaef-f9c25adc58ec 2026-05-28 03:47:01,108 - DEBUG - Requesting: http://10.0.0.131:8082/virtual-machine-interface/9c61fcb2-b85b-4435-96b2-4a16784e240b 2026-05-28 03:47:02,324 - 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=8.26 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=0.966 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 = 0.966/4.613/8.260/3.647 ms') 2026-05-28 03:47:02,324 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-TestSubInterfaces-91991022-76163626 passed 2026-05-28 03:47:02,405 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:47:02,405 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-91991022-76163626, IP 175.146.225.133, Port 22 2026-05-28 03:47:02,583 - DEBUG - VM ctest-TestSubInterfaces-91991022-76163626 is ready for SSH connections 2026-05-28 03:47:02,584 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 174.63.233.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.48, gateway password: c0ntrail123 2026-05-28 03:47:02,584 - DEBUG - ifconfig -a| grep 174.63.233.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-28 03:47:24,904 - DEBUG - None 2026-05-28 03:47:29,905 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 174.63.233.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.48, gateway password: c0ntrail123 2026-05-28 03:47:29,905 - DEBUG - ifconfig -a| grep 174.63.233.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-28 03:47:32,719 - DEBUG - None 2026-05-28 03:47:37,719 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 174.63.233.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.48, gateway password: c0ntrail123 2026-05-28 03:47:37,719 - DEBUG - ifconfig -a| grep 174.63.233.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-28 03:47:39,994 - DEBUG - eth0.100 2026-05-28 03:47:39,994 - INFO - Interface eth0.100 is found on VM 5101241b-9b2b-46de-b245-26c8d13868c9 2026-05-28 03:47:39,994 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 151.39.107.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.48, gateway password: c0ntrail123 2026-05-28 03:47:39,994 - DEBUG - ifconfig -a| grep 151.39.107.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-05-28 03:48:22,074 - DEBUG - eth0.100 2026-05-28 03:48:22,074 - INFO - Interface eth0.100 is found on VM c8794459-be27-4499-aaef-f9c25adc58ec 2026-05-28 03:48:22,074 - DEBUG - Running remote_cmd, Cmd : route add -net 151.39.107.64/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.48, gateway password: c0ntrail123 2026-05-28 03:48:22,074 - DEBUG - route add -net 151.39.107.64/26 dev eth0.100 2026-05-28 03:48:22,640 - DEBUG - None 2026-05-28 03:48:22,640 - DEBUG - Running remote_cmd, Cmd : route add -net 174.63.233.0/26 dev eth0.100, host_string: ubuntu@169.254.0.7, password: ubuntugateway: ubuntu@10.0.0.48, gateway password: c0ntrail123 2026-05-28 03:48:22,640 - DEBUG - route add -net 174.63.233.0/26 dev eth0.100 2026-05-28 03:48:23,221 - DEBUG - None 2026-05-28 03:48:23,222 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-05-28 03:48:23,222 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 151.39.107.68, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.48, gateway password: c0ntrail123 2026-05-28 03:48:23,223 - DEBUG - ping -s 56 -c 3 -W 1 151.39.107.68 2026-05-28 03:48:25,759 - DEBUG - PING 151.39.107.68 (151.39.107.68) 56(84) bytes of data. 64 bytes from 151.39.107.68: icmp_req=1 ttl=63 time=14.2 ms 64 bytes from 151.39.107.68: icmp_req=2 ttl=63 time=1.72 ms 64 bytes from 151.39.107.68: icmp_req=3 ttl=63 time=1.25 ms --- 151.39.107.68 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2006ms rtt min/avg/max/mdev = 1.251/5.759/14.299/6.041 ms 2026-05-28 03:48:25,759 - INFO - Ping to IP 151.39.107.68 from VM ctest-TestSubInterfaces-91991022-27488577 passed 2026-05-28 03:48:25,760 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 151.39.107.67, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.48, gateway password: c0ntrail123 2026-05-28 03:48:25,760 - DEBUG - ping -s 56 -c 3 -W 1 151.39.107.67 2026-05-28 03:48:28,298 - DEBUG - PING 151.39.107.67 (151.39.107.67) 56(84) bytes of data. 64 bytes from 151.39.107.67: icmp_req=1 ttl=63 time=18.6 ms 64 bytes from 151.39.107.67: icmp_req=2 ttl=63 time=1.15 ms 64 bytes from 151.39.107.67: icmp_req=3 ttl=63 time=1.17 ms --- 151.39.107.67 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.152/6.993/18.654/8.245 ms 2026-05-28 03:48:28,298 - INFO - Ping to IP 151.39.107.67 from VM ctest-TestSubInterfaces-91991022-27488577 passed 2026-05-28 03:48:28,298 - INFO - Deleting interface with subnet_id 6523f706-38f2-4e61-8c98-aca2cf5f2c41, port_id None from router 3660276f-6c1a-40b2-85f7-c67275ee8a48 2026-05-28 03:48:28,556 - INFO - Deleting interface with subnet_id d1c6d618-ccdd-4600-aae7-ef0ab28da3b1, port_id None from router 3660276f-6c1a-40b2-85f7-c67275ee8a48 2026-05-28 03:48:28,987 - INFO - Detaching port 9c61fcb2-b85b-4435-96b2-4a16784e240b from VM ctest-TestSubInterfaces-91991022-76163626 2026-05-28 03:48:29,070 - INFO - Deleting VM ctest-TestSubInterfaces-91991022-76163626 2026-05-28 03:48:29,260 - INFO - Deleting VM ctest-TestSubInterfaces-91991022-41314851 2026-05-28 03:48:29,384 - INFO - Detaching port 07ce008c-3ac6-447d-8a72-33564991359c from VM ctest-TestSubInterfaces-91991022-27488577 2026-05-28 03:48:29,447 - INFO - Deleting VM ctest-TestSubInterfaces-91991022-27488577 2026-05-28 03:48:30,930 - DEBUG - No XMPP flaps were noticed during the test
2026-05-28 03:48:30,931 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:02:54]
2026-05-28 03:48:30,931 - INFO - -------------------------------------------------------------------------------- 2026-05-28 03:48:31,102 - INFO - Deleted port c7316889-36f5-4adb-aec1-931ae7dd42b6 2026-05-28 03:48:31,557 - DEBUG - Response for delete_port : () 2026-05-28 03:48:31,557 - INFO - Deleted port 9c61fcb2-b85b-4435-96b2-4a16784e240b 2026-05-28 03:48:31,727 - INFO - Deleted port 14983ec8-95af-4de2-b7d1-86bc258b3728 2026-05-28 03:48:31,963 - DEBUG - Response for delete_port : () 2026-05-28 03:48:31,963 - INFO - Deleted port 3590ae0c-0c30-47eb-86a2-d0142db7cfa0 2026-05-28 03:48:32,136 - INFO - Deleted port dde55735-4ec9-45f4-9945-615df29aec90 2026-05-28 03:48:32,407 - DEBUG - Response for delete_port : () 2026-05-28 03:48:32,407 - INFO - Deleted port 07ce008c-3ac6-447d-8a72-33564991359c 2026-05-28 03:48:32,407 - INFO - Deleting VN ctest-vn-15237971 2026-05-28 03:48:32,637 - DEBUG - Response for deleting network () 2026-05-28 03:48:32,638 - INFO - Deleting VN ctest-vn-01343241 2026-05-28 03:48:32,942 - DEBUG - Response for deleting network () 2026-05-28 03:48:32,943 - INFO - Deleting VN ctest-vn-24362507 2026-05-28 03:48:33,207 - DEBUG - Response for deleting network () 2026-05-28 03:48:34,127 - INFO - Deleted project: ctest-TestSubInterfaces-91991022, ID : 53cb4697-cdbb-443b-ba15-09e089438c5f