2026-11-02 04:12:30,589 - INFO - Domain Default found not creating 2026-11-02 04:12:30,838 - INFO - Project ctest-TestSubInterfaces-25069727 not found, creating it 2026-11-02 04:12:31,474 - INFO - Created Project:ctest-TestSubInterfaces-25069727, ID : da00a96e-7b33-48e2-8fac-7d6bdd2987c4 2026-11-02 04:12:34,801 - DEBUG - Response for create_network : {'network': {'id': 'f873ac66-93d3-4b4c-87bc-c4877f55af8e', 'name': 'ctest-vn-67534626', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vn-67534626'], 'port_security_enabled': True, 'description': ''}} 2026-11-02 04:12:35,087 - DEBUG - Response for create_subnet : {'subnet': {'id': 'cb62e916-5858-4abe-8fa8-f13cc3591445', 'name': '', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': 'f873ac66-93d3-4b4c-87bc-c4877f55af8e', 'ip_version': 4, 'cidr': '109.39.192.64/26', 'allocation_pools': [{'start': '109.39.192.66', 'end': '109.39.192.126'}], 'gateway_ip': '109.39.192.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '109.39.192.66', 'tags': [], 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:35,110 - INFO - Created VN ctest-vn-67534626 2026-11-02 04:12:35,126 - DEBUG - VN ctest-vn-67534626 UUID is f873ac66-93d3-4b4c-87bc-c4877f55af8e 2026-11-02 04:12:35,522 - DEBUG - Response for create_network : {'network': {'id': '96a336c7-1c74-475a-b33d-fef8ab946a51', 'name': 'ctest-vn-02424270', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vn-02424270'], 'port_security_enabled': True, 'description': ''}} 2026-11-02 04:12:35,757 - DEBUG - Response for create_subnet : {'subnet': {'id': '4bfd2ab9-4f4b-49b5-b675-4ef7cf4e3a72', 'name': '', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': '96a336c7-1c74-475a-b33d-fef8ab946a51', 'ip_version': 4, 'cidr': '92.79.30.128/26', 'allocation_pools': [{'start': '92.79.30.130', 'end': '92.79.30.190'}], 'gateway_ip': '92.79.30.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '92.79.30.130', 'tags': [], 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:35,778 - INFO - Created VN ctest-vn-02424270 2026-11-02 04:12:35,790 - DEBUG - VN ctest-vn-02424270 UUID is 96a336c7-1c74-475a-b33d-fef8ab946a51 2026-11-02 04:12:36,152 - DEBUG - Response for create_network : {'network': {'id': 'b1d276eb-fc35-487c-9b0a-edd339baaf1a', 'name': 'ctest-vn-23752873', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vn-23752873'], 'port_security_enabled': True, 'description': ''}} 2026-11-02 04:12:36,375 - DEBUG - Response for create_subnet : {'subnet': {'id': '30b3c247-2889-46e5-967a-a4a56fbbcd99', 'name': '', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': 'b1d276eb-fc35-487c-9b0a-edd339baaf1a', 'ip_version': 4, 'cidr': '216.154.25.64/26', 'allocation_pools': [{'start': '216.154.25.66', 'end': '216.154.25.126'}], 'gateway_ip': '216.154.25.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '216.154.25.66', 'tags': [], 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:36,395 - INFO - Created VN ctest-vn-23752873 2026-11-02 04:12:36,409 - DEBUG - VN ctest-vn-23752873 UUID is b1d276eb-fc35-487c-9b0a-edd339baaf1a 2026-11-02 04:12:36,478 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-86106007']} 2026-11-02 04:12:36,791 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-86106007', 'id': 'bf08afef-3ff4-4999-9f15-8689191ee01e', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': '96a336c7-1c74-475a-b33d-fef8ab946a51', 'mac_address': '02:bf:08:af:ef:3f', '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': '92.79.30.131', 'subnet_id': '4bfd2ab9-4f4b-49b5-b675-4ef7cf4e3a72'}], 'security_groups': ['b2e66188-f178-47a4-8337-1e363a7a5604'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'tags': [], 'port_security_enabled': True, 'description': '', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:36,791 - DEBUG - Created port bf08afef-3ff4-4999-9f15-8689191ee01e 2026-11-02 04:12:36,865 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-00111978']} 2026-11-02 04:12:37,309 - DEBUG - Created port 213d37bd-4249-4d55-8fb1-cd72b1c58e49 2026-11-02 04:12:37,425 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-37727190']} 2026-11-02 04:12:37,760 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-37727190', 'id': '6cccd5a0-7237-498a-9c71-d3202a52c8d0', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': '96a336c7-1c74-475a-b33d-fef8ab946a51', 'mac_address': '02:6c:cc:d5:a0:72', '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': '92.79.30.132', 'subnet_id': '4bfd2ab9-4f4b-49b5-b675-4ef7cf4e3a72'}], 'security_groups': ['b2e66188-f178-47a4-8337-1e363a7a5604'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'tags': [], 'port_security_enabled': True, 'description': '', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:37,760 - DEBUG - Created port 6cccd5a0-7237-498a-9c71-d3202a52c8d0 2026-11-02 04:12:37,829 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-58887367']} 2026-11-02 04:12:38,277 - DEBUG - Created port aafabc68-0f42-41f0-a5a9-1b4681d9378e 2026-11-02 04:12:38,389 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-08920036']} 2026-11-02 04:12:38,701 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-08920036', 'id': '62feb86d-8788-4cb7-8492-9f977dd1e5da', 'tenant_id': 'da00a96e7b3348e28fac7d6bdd2987c4', 'network_id': '96a336c7-1c74-475a-b33d-fef8ab946a51', 'mac_address': '02:62:fe:b8:6d:87', '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': '92.79.30.133', 'subnet_id': '4bfd2ab9-4f4b-49b5-b675-4ef7cf4e3a72'}], 'security_groups': ['b2e66188-f178-47a4-8337-1e363a7a5604'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'tags': [], 'port_security_enabled': True, 'description': '', 'project_id': 'da00a96e7b3348e28fac7d6bdd2987c4'}} 2026-11-02 04:12:38,702 - DEBUG - Created port 62feb86d-8788-4cb7-8492-9f977dd1e5da 2026-11-02 04:12:38,777 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-25069727', 'ctest-vmi-66918052']} 2026-11-02 04:12:39,221 - DEBUG - Created port 1b2dfd00-98d2-4932-b283-685e9c650fb3 2026-11-02 04:12:39,339 - INFO - ================================================================================ 2026-11-02 04:12:39,339 - INFO - STARTING TEST : test_vlan_interface_2 2026-11-02 04:12:39,340 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2026-11-02 04:12:40,650 - DEBUG - Nothing to compare xmpp stats {'10.0.0.161': {'10.20.0.254': '0', '10.20.0.17': '0'}, '10.0.0.162': {'10.20.0.254': '0', '10.20.0.17': '0'}} with 2026-11-02 04:12:40,650 - INFO - Initial checks done. Running the testcase now 2026-11-02 04:12:40,650 - INFO - 2026-11-02 04:12:40,724 - DEBUG - Services list from nova: [, , , ] 2026-11-02 04:12:41,205 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6461-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6461-1) 2026-11-02 04:12:41,732 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6461-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6461-2) 2026-11-02 04:12:42,352 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6461-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6461-1) 2026-11-02 04:12:42,476 - INFO - Adding interface with subnet_id cb62e916-5858-4abe-8fa8-f13cc3591445, port_id None to router 88d87d93-c1f1-42d2-b254-041f74fabafe 2026-11-02 04:12:42,906 - INFO - Adding interface with subnet_id 30b3c247-2889-46e5-967a-a4a56fbbcd99, port_id None to router 88d87d93-c1f1-42d2-b254-041f74fabafe 2026-11-02 04:12:43,351 - INFO - Waiting for VM ctest-TestSubInterfaces-25069727-51751161 to be up.. 2026-11-02 04:12:43,449 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:12:48,588 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:12:53,686 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:12:58,778 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:13:03,867 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:13:08,956 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:13:14,059 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:13:19,148 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 04:13:24,350 - DEBUG - VM is in ACTIVE state now 2026-11-02 04:13:24,350 - INFO - VM name : ctest-TestSubInterfaces-25069727-51751161 2026-11-02 04:13:24,464 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 ID is 09f20668-7776-4f9b-8f4c-f9ce00fb2b90 2026-11-02 04:13:24,502 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 launched on Node an-jenkins-deploy-platform-ansible-os-6461-1 2026-11-02 04:13:24,596 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine/09f20668-7776-4f9b-8f4c-f9ce00fb2b90 2026-11-02 04:13:25,008 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine/09f20668-7776-4f9b-8f4c-f9ce00fb2b90 2026-11-02 04:13:25,040 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine-interface/bf08afef-3ff4-4999-9f15-8689191ee01e 2026-11-02 04:13:28,220 - 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 1009ms') 2026-11-02 04:13:28,220 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:28,235 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:32,313 - 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') 2026-11-02 04:13:32,313 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:32,329 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:36,412 - 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') 2026-11-02 04:13:36,412 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:36,429 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:40,505 - 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 1012ms') 2026-11-02 04:13:40,505 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:40,522 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:44,605 - 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 1004ms') 2026-11-02 04:13:44,605 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:44,620 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:48,694 - 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') 2026-11-02 04:13:48,694 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:48,710 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:52,794 - 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 1018ms') 2026-11-02 04:13:52,795 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:52,810 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:13:56,888 - 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 1018ms') 2026-11-02 04:13:56,888 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:13:56,910 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:14:00,992 - 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 1005ms') 2026-11-02 04:14:00,993 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:14:01,009 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:14:05,086 - 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 1005ms') 2026-11-02 04:14:05,086 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:14:05,102 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:14:09,184 - 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') 2026-11-02 04:14:09,184 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:14:09,200 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:14:13,305 - 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 1031ms') 2026-11-02 04:14:13,305 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 failed! 2026-11-02 04:14:13,322 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-25069727:ctest-vn-02424270 is 92.79.30.129 and allocation pool is NOT set 2026-11-02 04:14:15,390 - 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=10.5 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.619 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.619/5.541/10.464/4.922 ms') 2026-11-02 04:14:15,390 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-51751161 passed 2026-11-02 04:14:15,463 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:15,463 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-51751161, IP 92.79.30.131, Port 22 2026-11-02 04:14:15,528 - 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': ''} 2026-11-02 04:14:15,614 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 is NOT ready for SSH connections, VM status: ACTIVE 2026-11-02 04:14:20,615 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:20,615 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-51751161, IP 92.79.30.131, Port 22 2026-11-02 04:14:20,681 - 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': ''} 2026-11-02 04:14:20,768 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 is NOT ready for SSH connections, VM status: ACTIVE 2026-11-02 04:14:25,768 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:25,768 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-51751161, IP 92.79.30.131, Port 22 2026-11-02 04:14:25,827 - 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': ''} 2026-11-02 04:14:25,914 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 is NOT ready for SSH connections, VM status: ACTIVE 2026-11-02 04:14:30,914 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:30,915 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-51751161, IP 92.79.30.131, Port 22 2026-11-02 04:14:30,992 - 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': ''} 2026-11-02 04:14:31,091 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 is NOT ready for SSH connections, VM status: ACTIVE 2026-11-02 04:14:36,092 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:36,092 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-51751161, IP 92.79.30.131, Port 22 2026-11-02 04:14:36,268 - DEBUG - VM ctest-TestSubInterfaces-25069727-51751161 is ready for SSH connections 2026-11-02 04:14:36,268 - INFO - Waiting for VM ctest-TestSubInterfaces-25069727-08746772 to be up.. 2026-11-02 04:14:36,369 - DEBUG - VM is in ACTIVE state now 2026-11-02 04:14:36,370 - INFO - VM name : ctest-TestSubInterfaces-25069727-08746772 2026-11-02 04:14:36,481 - DEBUG - VM ctest-TestSubInterfaces-25069727-08746772 ID is 60f47bef-5591-4e7b-bc8f-46824bd984b8 2026-11-02 04:14:36,481 - DEBUG - VM ctest-TestSubInterfaces-25069727-08746772 launched on Node an-jenkins-deploy-platform-ansible-os-6461-2 2026-11-02 04:14:36,577 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine/60f47bef-5591-4e7b-bc8f-46824bd984b8 2026-11-02 04:14:36,588 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine-interface/63cdbc47-21a2-42b2-8e6b-5d07c49f0a0e 2026-11-02 04:14:37,759 - 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.86 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.542 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.542/2.199/3.856/1.657 ms') 2026-11-02 04:14:37,759 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-25069727-08746772 passed 2026-11-02 04:14:37,830 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:37,830 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-08746772, IP 216.154.25.68, Port 22 2026-11-02 04:14:38,005 - DEBUG - VM ctest-TestSubInterfaces-25069727-08746772 is ready for SSH connections 2026-11-02 04:14:38,005 - INFO - Waiting for VM ctest-TestSubInterfaces-25069727-50846959 to be up.. 2026-11-02 04:14:38,103 - DEBUG - VM is in ACTIVE state now 2026-11-02 04:14:38,103 - INFO - VM name : ctest-TestSubInterfaces-25069727-50846959 2026-11-02 04:14:38,201 - DEBUG - VM ctest-TestSubInterfaces-25069727-50846959 ID is 0ca56e8f-d17b-466b-89e7-3e907224906d 2026-11-02 04:14:38,202 - DEBUG - VM ctest-TestSubInterfaces-25069727-50846959 launched on Node an-jenkins-deploy-platform-ansible-os-6461-1 2026-11-02 04:14:38,283 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine/0ca56e8f-d17b-466b-89e7-3e907224906d 2026-11-02 04:14:38,294 - DEBUG - Requesting: http://10.0.0.191:8082/virtual-machine-interface/62feb86d-8788-4cb7-8492-9f977dd1e5da 2026-11-02 04:14:39,460 - 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=5.49 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=1.42 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.420/3.452/5.485/2.032 ms') 2026-11-02 04:14:39,460 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-25069727-50846959 passed 2026-11-02 04:14:39,530 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:14:39,530 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-25069727-50846959, IP 92.79.30.133, Port 22 2026-11-02 04:14:39,701 - DEBUG - VM ctest-TestSubInterfaces-25069727-50846959 is ready for SSH connections 2026-11-02 04:14:39,701 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 109.39.192.67 -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.161, gateway password: c0ntrail123 2026-11-02 04:14:39,701 - DEBUG - ifconfig -a| grep 109.39.192.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-11-02 04:14:51,712 - DEBUG - None 2026-11-02 04:14:56,714 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 109.39.192.67 -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.161, gateway password: c0ntrail123 2026-11-02 04:14:56,714 - DEBUG - ifconfig -a| grep 109.39.192.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-11-02 04:14:57,240 - DEBUG - None 2026-11-02 04:15:02,240 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 109.39.192.67 -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.161, gateway password: c0ntrail123 2026-11-02 04:15:02,241 - DEBUG - ifconfig -a| grep 109.39.192.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-11-02 04:15:02,794 - DEBUG - eth0.100 2026-11-02 04:15:02,794 - INFO - Interface eth0.100 is found on VM 09f20668-7776-4f9b-8f4c-f9ce00fb2b90 2026-11-02 04:15:02,794 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 216.154.25.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.161, gateway password: c0ntrail123 2026-11-02 04:15:02,794 - DEBUG - ifconfig -a| grep 216.154.25.67 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2026-11-02 04:15:50,722 - DEBUG - eth0.100 2026-11-02 04:15:50,722 - INFO - Interface eth0.100 is found on VM 0ca56e8f-d17b-466b-89e7-3e907224906d 2026-11-02 04:15:50,722 - DEBUG - Running remote_cmd, Cmd : route add -net 216.154.25.64/26 dev eth0.100, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-11-02 04:15:50,722 - DEBUG - route add -net 216.154.25.64/26 dev eth0.100 2026-11-02 04:15:51,088 - DEBUG - None 2026-11-02 04:15:51,088 - DEBUG - Running remote_cmd, Cmd : route add -net 109.39.192.64/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-11-02 04:15:51,088 - DEBUG - route add -net 109.39.192.64/26 dev eth0.100 2026-11-02 04:15:51,444 - DEBUG - None 2026-11-02 04:15:51,444 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 04:15:51,444 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 216.154.25.68, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-11-02 04:15:51,444 - DEBUG - ping -s 56 -c 3 -W 1 216.154.25.68 2026-11-02 04:15:53,711 - DEBUG - PING 216.154.25.68 (216.154.25.68) 56(84) bytes of data. 64 bytes from 216.154.25.68: icmp_req=1 ttl=63 time=8.06 ms 64 bytes from 216.154.25.68: icmp_req=2 ttl=63 time=1.34 ms 64 bytes from 216.154.25.68: icmp_req=3 ttl=63 time=1.50 ms --- 216.154.25.68 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.347/3.637/8.065/3.132 ms 2026-11-02 04:15:53,712 - INFO - Ping to IP 216.154.25.68 from VM ctest-TestSubInterfaces-25069727-51751161 passed 2026-11-02 04:15:53,712 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 216.154.25.67, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-11-02 04:15:53,712 - DEBUG - ping -s 56 -c 3 -W 1 216.154.25.67 2026-11-02 04:15:56,015 - DEBUG - PING 216.154.25.67 (216.154.25.67) 56(84) bytes of data. 64 bytes from 216.154.25.67: icmp_req=1 ttl=63 time=8.95 ms 64 bytes from 216.154.25.67: icmp_req=2 ttl=63 time=1.02 ms 64 bytes from 216.154.25.67: icmp_req=3 ttl=63 time=1.03 ms --- 216.154.25.67 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2003ms rtt min/avg/max/mdev = 1.028/3.671/8.951/3.733 ms 2026-11-02 04:15:56,015 - INFO - Ping to IP 216.154.25.67 from VM ctest-TestSubInterfaces-25069727-51751161 passed 2026-11-02 04:15:56,015 - INFO - Deleting interface with subnet_id 30b3c247-2889-46e5-967a-a4a56fbbcd99, port_id None from router 88d87d93-c1f1-42d2-b254-041f74fabafe 2026-11-02 04:15:56,244 - INFO - Deleting interface with subnet_id cb62e916-5858-4abe-8fa8-f13cc3591445, port_id None from router 88d87d93-c1f1-42d2-b254-041f74fabafe 2026-11-02 04:15:56,526 - INFO - Detaching port 62feb86d-8788-4cb7-8492-9f977dd1e5da from VM ctest-TestSubInterfaces-25069727-50846959 2026-11-02 04:15:56,566 - INFO - Deleting VM ctest-TestSubInterfaces-25069727-50846959 2026-11-02 04:15:56,650 - INFO - Deleting VM ctest-TestSubInterfaces-25069727-08746772 2026-11-02 04:15:56,774 - INFO - Detaching port bf08afef-3ff4-4999-9f15-8689191ee01e from VM ctest-TestSubInterfaces-25069727-51751161 2026-11-02 04:15:56,813 - INFO - Deleting VM ctest-TestSubInterfaces-25069727-51751161 2026-11-02 04:15:58,198 - DEBUG - No XMPP flaps were noticed during the test
2026-11-02 04:15:58,199 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:03:19]
2026-11-02 04:15:58,199 - INFO - -------------------------------------------------------------------------------- 2026-11-02 04:15:58,330 - INFO - Deleted port 1b2dfd00-98d2-4932-b283-685e9c650fb3 2026-11-02 04:15:58,616 - DEBUG - Response for delete_port : () 2026-11-02 04:15:58,617 - INFO - Deleted port 62feb86d-8788-4cb7-8492-9f977dd1e5da 2026-11-02 04:15:58,752 - INFO - Deleted port aafabc68-0f42-41f0-a5a9-1b4681d9378e 2026-11-02 04:15:58,911 - DEBUG - Response for delete_port : () 2026-11-02 04:15:58,911 - INFO - Deleted port 6cccd5a0-7237-498a-9c71-d3202a52c8d0 2026-11-02 04:15:59,025 - INFO - Deleted port 213d37bd-4249-4d55-8fb1-cd72b1c58e49 2026-11-02 04:15:59,270 - DEBUG - Response for delete_port : () 2026-11-02 04:15:59,270 - INFO - Deleted port bf08afef-3ff4-4999-9f15-8689191ee01e 2026-11-02 04:15:59,270 - INFO - Deleting VN ctest-vn-23752873 2026-11-02 04:15:59,321 - DEBUG - VN b1d276eb-fc35-487c-9b0a-edd339baaf1a still in use: Unable to complete operation on network b1d276eb-fc35-487c-9b0a-edd339baaf1a. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-c117a587-d38f-422c-9b4b-a280236dec1b'] 2026-11-02 04:15:59,321 - WARNING - Deleting VN ctest-vn-23752873 failed..Will retry 2026-11-02 04:16:01,477 - DEBUG - Response for deleting network () 2026-11-02 04:16:01,477 - INFO - Deleting VN ctest-vn-02424270 2026-11-02 04:16:01,634 - DEBUG - Response for deleting network () 2026-11-02 04:16:01,635 - INFO - Deleting VN ctest-vn-67534626 2026-11-02 04:16:01,814 - DEBUG - Response for deleting network () 2026-11-02 04:16:02,704 - INFO - Deleted project: ctest-TestSubInterfaces-25069727, ID : da00a96e-7b33-48e2-8fac-7d6bdd2987c4