2025-08-06 09:13:00,595 - INFO - Domain Default found not creating 2025-08-06 09:13:00,801 - INFO - Project ctest-TestSubInterfaces-63219713 not found, creating it 2025-08-06 09:13:01,397 - INFO - Created Project:ctest-TestSubInterfaces-63219713, ID : 0ca1b0c5-fc55-4732-8a7b-0b8c64e493a8 2025-08-06 09:13:03,850 - DEBUG - Response for create_network : {'network': {'id': '916ebc84-a3e2-47ec-a4cc-da0c87fac859', 'name': 'ctest-vn-65352169', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vn-65352169'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 09:13:04,132 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f94d1b9b-b368-47d8-aceb-03128e359c5a', 'name': '', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '916ebc84-a3e2-47ec-a4cc-da0c87fac859', 'ip_version': 4, 'cidr': '149.129.240.192/26', 'allocation_pools': [{'start': '149.129.240.194', 'end': '149.129.240.254'}], 'gateway_ip': '149.129.240.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '149.129.240.194', 'tags': [], 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:04,175 - INFO - Created VN ctest-vn-65352169 2025-08-06 09:13:04,191 - DEBUG - VN ctest-vn-65352169 UUID is 916ebc84-a3e2-47ec-a4cc-da0c87fac859 2025-08-06 09:13:04,642 - DEBUG - Response for create_network : {'network': {'id': '816b2847-3996-40d9-b7ce-27702240fc8b', 'name': 'ctest-vn-45953868', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vn-45953868'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 09:13:04,919 - DEBUG - Response for create_subnet : {'subnet': {'id': '76b5c107-ad6b-4cc8-a4ce-a940059ee7a1', 'name': '', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '816b2847-3996-40d9-b7ce-27702240fc8b', 'ip_version': 4, 'cidr': '157.151.238.128/26', 'allocation_pools': [{'start': '157.151.238.130', 'end': '157.151.238.190'}], 'gateway_ip': '157.151.238.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '157.151.238.130', 'tags': [], 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:04,955 - INFO - Created VN ctest-vn-45953868 2025-08-06 09:13:04,980 - DEBUG - VN ctest-vn-45953868 UUID is 816b2847-3996-40d9-b7ce-27702240fc8b 2025-08-06 09:13:05,441 - DEBUG - Response for create_network : {'network': {'id': '821d26a0-5713-4c72-896e-60bb663fa693', 'name': 'ctest-vn-14102812', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vn-14102812'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 09:13:05,775 - DEBUG - Response for create_subnet : {'subnet': {'id': '0906346b-fee3-4f02-8945-6bd14081ea92', 'name': '', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '821d26a0-5713-4c72-896e-60bb663fa693', 'ip_version': 4, 'cidr': '62.245.187.0/26', 'allocation_pools': [{'start': '62.245.187.2', 'end': '62.245.187.62'}], 'gateway_ip': '62.245.187.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '62.245.187.2', 'tags': [], 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:05,825 - INFO - Created VN ctest-vn-14102812 2025-08-06 09:13:05,844 - DEBUG - VN ctest-vn-14102812 UUID is 821d26a0-5713-4c72-896e-60bb663fa693 2025-08-06 09:13:05,939 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-85825176']} 2025-08-06 09:13:06,318 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-85825176', 'id': '9d904e00-b684-4555-8a5b-2509e5f1cb54', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '816b2847-3996-40d9-b7ce-27702240fc8b', 'mac_address': '02:9d:90:4e:00:b6', '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': '157.151.238.131', 'subnet_id': '76b5c107-ad6b-4cc8-a4ce-a940059ee7a1'}], 'security_groups': ['b6753e37-d5e3-4773-9863-05f9034b4e5c'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:06,318 - DEBUG - Created port 9d904e00-b684-4555-8a5b-2509e5f1cb54 2025-08-06 09:13:06,395 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-82530246']} 2025-08-06 09:13:06,970 - DEBUG - Created port ea1694fd-7407-4e9c-b052-a87311b5bdb8 2025-08-06 09:13:07,099 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-06970218']} 2025-08-06 09:13:07,525 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-06970218', 'id': '9ff26789-496d-480f-a1df-55f44b9404a4', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '816b2847-3996-40d9-b7ce-27702240fc8b', 'mac_address': '02:9f:f2:67:89:49', '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': '157.151.238.132', 'subnet_id': '76b5c107-ad6b-4cc8-a4ce-a940059ee7a1'}], 'security_groups': ['b6753e37-d5e3-4773-9863-05f9034b4e5c'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:07,526 - DEBUG - Created port 9ff26789-496d-480f-a1df-55f44b9404a4 2025-08-06 09:13:07,603 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-55035211']} 2025-08-06 09:13:08,082 - DEBUG - Created port d651fa36-b4c9-4b45-afb2-a8b640938453 2025-08-06 09:13:08,203 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-15021198']} 2025-08-06 09:13:08,590 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-15021198', 'id': 'b7ffba24-762c-4bfd-9d22-63f7122d9499', 'tenant_id': '0ca1b0c5fc5547328a7b0b8c64e493a8', 'network_id': '816b2847-3996-40d9-b7ce-27702240fc8b', 'mac_address': '02:b7:ff:ba:24:76', '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': '157.151.238.133', 'subnet_id': '76b5c107-ad6b-4cc8-a4ce-a940059ee7a1'}], 'security_groups': ['b6753e37-d5e3-4773-9863-05f9034b4e5c'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '0ca1b0c5fc5547328a7b0b8c64e493a8'}} 2025-08-06 09:13:08,590 - DEBUG - Created port b7ffba24-762c-4bfd-9d22-63f7122d9499 2025-08-06 09:13:08,660 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestSubInterfaces-63219713', 'ctest-vmi-24846162']} 2025-08-06 09:13:09,106 - DEBUG - Created port d7ea2235-c86c-438e-911c-85e8a777474e 2025-08-06 09:13:09,225 - INFO - ================================================================================ 2025-08-06 09:13:09,225 - INFO - STARTING TEST : test_vlan_interface_2 2025-08-06 09:13:09,225 - INFO - TEST DESCRIPTION : Test ping/hping between tagged-untagged vmis across VNs 2025-08-06 09:13:10,533 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.25': '0', '10.20.0.14': '0'}, '10.0.0.57': {'10.20.0.14': '0', '10.20.0.254': '0'}} with 2025-08-06 09:13:10,534 - INFO - Initial checks done. Running the testcase now 2025-08-06 09:13:10,534 - INFO - 2025-08-06 09:13:10,705 - DEBUG - Services list from nova: [, , , ] 2025-08-06 09:13:11,201 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3761-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3761-1) 2025-08-06 09:13:12,599 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3761-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3761-2) 2025-08-06 09:13:13,747 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3761-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3761-1) 2025-08-06 09:13:13,944 - INFO - Adding interface with subnet_id f94d1b9b-b368-47d8-aceb-03128e359c5a, port_id None to router c4c659cb-ea95-4b28-acf8-b6438533d105 2025-08-06 09:13:14,443 - INFO - Adding interface with subnet_id 0906346b-fee3-4f02-8945-6bd14081ea92, port_id None to router c4c659cb-ea95-4b28-acf8-b6438533d105 2025-08-06 09:13:15,046 - INFO - Waiting for VM ctest-TestSubInterfaces-63219713-76129769 to be up.. 2025-08-06 09:13:15,205 - DEBUG - VM is in ACTIVE state now 2025-08-06 09:13:15,206 - INFO - VM name : ctest-TestSubInterfaces-63219713-76129769 2025-08-06 09:13:15,324 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 ID is 6f6c1fa7-ca97-4e31-97ae-0d87bfbb7c67 2025-08-06 09:13:15,353 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1 2025-08-06 09:13:15,450 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/6f6c1fa7-ca97-4e31-97ae-0d87bfbb7c67 2025-08-06 09:13:15,745 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/6f6c1fa7-ca97-4e31-97ae-0d87bfbb7c67 2025-08-06 09:13:15,787 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/9d904e00-b684-4555-8a5b-2509e5f1cb54 2025-08-06 09:13:19,035 - 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 1020ms') 2025-08-06 09:13:19,035 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:19,057 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:23,132 - 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') 2025-08-06 09:13:23,133 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:23,149 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:27,230 - 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 1008ms') 2025-08-06 09:13:27,230 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:27,247 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:31,321 - 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-06 09:13:31,321 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:31,339 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:35,422 - 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 1020ms') 2025-08-06 09:13:35,422 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:35,439 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:39,519 - 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') 2025-08-06 09:13:39,520 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:39,539 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:43,619 - 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 1015ms') 2025-08-06 09:13:43,619 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:43,639 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:47,713 - 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-06 09:13:47,713 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:47,739 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:51,839 - 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 1030ms') 2025-08-06 09:13:51,839 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 failed! 2025-08-06 09:13:51,859 - DEBUG - Gateway for vn default-domain:ctest-TestSubInterfaces-63219713:ctest-vn-45953868 is 157.151.238.129 and allocation pool is NOT set 2025-08-06 09:13:53,932 - 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=6.70 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.97 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 = 1.966/4.333/6.701/2.367 ms') 2025-08-06 09:13:53,932 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-76129769 passed 2025-08-06 09:13:54,048 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:13:54,049 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-76129769, IP 157.151.238.131, Port 22 2025-08-06 09:13:54,115 - 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-06 09:13:54,218 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 09:13:59,219 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:13:59,219 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-76129769, IP 157.151.238.131, Port 22 2025-08-06 09:13:59,287 - 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-06 09:13:59,395 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 09:14:04,397 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:04,397 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-76129769, IP 157.151.238.131, Port 22 2025-08-06 09:14:04,471 - 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-06 09:14:04,580 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 09:14:09,581 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:09,581 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-76129769, IP 157.151.238.131, Port 22 2025-08-06 09:14:09,652 - 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-06 09:14:09,751 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 09:14:14,752 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:14,752 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-76129769, IP 157.151.238.131, Port 22 2025-08-06 09:14:14,904 - DEBUG - VM ctest-TestSubInterfaces-63219713-76129769 is ready for SSH connections 2025-08-06 09:14:14,904 - INFO - Waiting for VM ctest-TestSubInterfaces-63219713-51221338 to be up.. 2025-08-06 09:14:15,030 - DEBUG - VM is in ACTIVE state now 2025-08-06 09:14:15,030 - INFO - VM name : ctest-TestSubInterfaces-63219713-51221338 2025-08-06 09:14:15,129 - DEBUG - VM ctest-TestSubInterfaces-63219713-51221338 ID is 76a277a7-9511-4803-b314-6f93dd145fc2 2025-08-06 09:14:15,129 - DEBUG - VM ctest-TestSubInterfaces-63219713-51221338 launched on Node an-jenkins-deploy-platform-ansible-os-3761-2 2025-08-06 09:14:15,230 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/76a277a7-9511-4803-b314-6f93dd145fc2 2025-08-06 09:14:15,242 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/f58b2797-19f6-434f-a06c-79a49fd1b80d 2025-08-06 09:14:16,471 - 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.58 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.52 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 = 3.518/3.548/3.578/0.030 ms') 2025-08-06 09:14:16,472 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestSubInterfaces-63219713-51221338 passed 2025-08-06 09:14:16,593 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:16,594 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-51221338, IP 62.245.187.4, Port 22 2025-08-06 09:14:16,650 - 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-06 09:14:16,753 - DEBUG - VM ctest-TestSubInterfaces-63219713-51221338 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 09:14:21,754 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:21,754 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-51221338, IP 62.245.187.4, Port 22 2025-08-06 09:14:21,928 - DEBUG - VM ctest-TestSubInterfaces-63219713-51221338 is ready for SSH connections 2025-08-06 09:14:21,928 - INFO - Waiting for VM ctest-TestSubInterfaces-63219713-23714677 to be up.. 2025-08-06 09:14:22,041 - DEBUG - VM is in ACTIVE state now 2025-08-06 09:14:22,041 - INFO - VM name : ctest-TestSubInterfaces-63219713-23714677 2025-08-06 09:14:22,137 - DEBUG - VM ctest-TestSubInterfaces-63219713-23714677 ID is a6a2024d-3a33-4903-9887-7af583d370e7 2025-08-06 09:14:22,137 - DEBUG - VM ctest-TestSubInterfaces-63219713-23714677 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1 2025-08-06 09:14:22,230 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/a6a2024d-3a33-4903-9887-7af583d370e7 2025-08-06 09:14:22,245 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/b7ffba24-762c-4bfd-9d22-63f7122d9499 2025-08-06 09:14:23,452 - 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.16 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=2.68 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 = 2.676/2.915/3.155/0.239 ms') 2025-08-06 09:14:23,452 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestSubInterfaces-63219713-23714677 passed 2025-08-06 09:14:23,569 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:14:23,569 - DEBUG - Waiting to SSH to VM ctest-TestSubInterfaces-63219713-23714677, IP 157.151.238.133, Port 22 2025-08-06 09:14:23,744 - DEBUG - VM ctest-TestSubInterfaces-63219713-23714677 is ready for SSH connections 2025-08-06 09:14:23,744 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 149.129.240.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.49, gateway password: c0ntrail123 2025-08-06 09:14:23,744 - DEBUG - ifconfig -a| grep 149.129.240.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 09:14:37,848 - DEBUG - None 2025-08-06 09:14:42,849 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 149.129.240.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.49, gateway password: c0ntrail123 2025-08-06 09:14:42,849 - DEBUG - ifconfig -a| grep 149.129.240.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 09:14:43,956 - DEBUG - None 2025-08-06 09:14:48,957 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 149.129.240.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.49, gateway password: c0ntrail123 2025-08-06 09:14:48,958 - DEBUG - ifconfig -a| grep 149.129.240.195 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 09:14:49,936 - DEBUG - eth0.100 2025-08-06 09:14:49,936 - INFO - Interface eth0.100 is found on VM 6f6c1fa7-ca97-4e31-97ae-0d87bfbb7c67 2025-08-06 09:14:49,936 - DEBUG - Running remote_cmd, Cmd : ifconfig -a| grep 62.245.187.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.49, gateway password: c0ntrail123 2025-08-06 09:14:49,937 - DEBUG - ifconfig -a| grep 62.245.187.3 -A2 -B4| grep -i 'hwaddr\|flags' | awk '{print $1}' | cut -d ':' -f 1 2025-08-06 09:15:26,610 - DEBUG - eth0.100 2025-08-06 09:15:26,611 - INFO - Interface eth0.100 is found on VM a6a2024d-3a33-4903-9887-7af583d370e7 2025-08-06 09:15:26,611 - DEBUG - Running remote_cmd, Cmd : route add -net 62.245.187.0/26 dev eth0.100, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 09:15:26,611 - DEBUG - route add -net 62.245.187.0/26 dev eth0.100 2025-08-06 09:15:27,125 - DEBUG - None 2025-08-06 09:15:27,125 - DEBUG - Running remote_cmd, Cmd : route add -net 149.129.240.192/26 dev eth0.100, host_string: ubuntu@169.254.0.5, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 09:15:27,125 - DEBUG - route add -net 149.129.240.192/26 dev eth0.100 2025-08-06 09:15:27,632 - DEBUG - None 2025-08-06 09:15:27,632 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 09:15:27,632 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 62.245.187.4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 09:15:27,632 - DEBUG - ping -s 56 -c 3 -W 1 62.245.187.4 2025-08-06 09:15:30,061 - DEBUG - PING 62.245.187.4 (62.245.187.4) 56(84) bytes of data. 64 bytes from 62.245.187.4: icmp_req=1 ttl=63 time=9.36 ms 64 bytes from 62.245.187.4: icmp_req=2 ttl=63 time=1.56 ms 64 bytes from 62.245.187.4: icmp_req=3 ttl=63 time=1.55 ms --- 62.245.187.4 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.554/4.161/9.362/3.677 ms 2025-08-06 09:15:30,061 - INFO - Ping to IP 62.245.187.4 from VM ctest-TestSubInterfaces-63219713-76129769 passed 2025-08-06 09:15:30,062 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 62.245.187.3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 09:15:30,062 - DEBUG - ping -s 56 -c 3 -W 1 62.245.187.3 2025-08-06 09:15:32,501 - DEBUG - PING 62.245.187.3 (62.245.187.3) 56(84) bytes of data. 64 bytes from 62.245.187.3: icmp_req=1 ttl=63 time=7.45 ms 64 bytes from 62.245.187.3: icmp_req=2 ttl=63 time=1.13 ms 64 bytes from 62.245.187.3: icmp_req=3 ttl=63 time=0.924 ms --- 62.245.187.3 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2003ms rtt min/avg/max/mdev = 0.924/3.170/7.453/3.029 ms 2025-08-06 09:15:32,501 - INFO - Ping to IP 62.245.187.3 from VM ctest-TestSubInterfaces-63219713-76129769 passed 2025-08-06 09:15:32,501 - INFO - Deleting interface with subnet_id 0906346b-fee3-4f02-8945-6bd14081ea92, port_id None from router c4c659cb-ea95-4b28-acf8-b6438533d105 2025-08-06 09:15:32,787 - INFO - Deleting interface with subnet_id f94d1b9b-b368-47d8-aceb-03128e359c5a, port_id None from router c4c659cb-ea95-4b28-acf8-b6438533d105 2025-08-06 09:15:33,171 - INFO - Detaching port b7ffba24-762c-4bfd-9d22-63f7122d9499 from VM ctest-TestSubInterfaces-63219713-23714677 2025-08-06 09:15:33,250 - INFO - Deleting VM ctest-TestSubInterfaces-63219713-23714677 2025-08-06 09:15:33,341 - INFO - Deleting VM ctest-TestSubInterfaces-63219713-51221338 2025-08-06 09:15:33,425 - INFO - Detaching port 9d904e00-b684-4555-8a5b-2509e5f1cb54 from VM ctest-TestSubInterfaces-63219713-76129769 2025-08-06 09:15:33,461 - INFO - Deleting VM ctest-TestSubInterfaces-63219713-76129769 2025-08-06 09:15:34,847 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 09:15:34,848 - INFO - END TEST : test_vlan_interface_2 : PASSED[0:02:25]
2025-08-06 09:15:34,848 - INFO - -------------------------------------------------------------------------------- 2025-08-06 09:15:34,999 - INFO - Deleted port d7ea2235-c86c-438e-911c-85e8a777474e 2025-08-06 09:15:35,291 - DEBUG - Response for delete_port : () 2025-08-06 09:15:35,291 - INFO - Deleted port b7ffba24-762c-4bfd-9d22-63f7122d9499 2025-08-06 09:15:35,538 - INFO - Deleted port d651fa36-b4c9-4b45-afb2-a8b640938453 2025-08-06 09:15:35,741 - DEBUG - Response for delete_port : () 2025-08-06 09:15:35,741 - INFO - Deleted port 9ff26789-496d-480f-a1df-55f44b9404a4 2025-08-06 09:15:35,868 - INFO - Deleted port ea1694fd-7407-4e9c-b052-a87311b5bdb8 2025-08-06 09:15:36,172 - DEBUG - Response for delete_port : () 2025-08-06 09:15:36,172 - INFO - Deleted port 9d904e00-b684-4555-8a5b-2509e5f1cb54 2025-08-06 09:15:36,173 - INFO - Deleting VN ctest-vn-14102812 2025-08-06 09:15:36,389 - DEBUG - Response for deleting network () 2025-08-06 09:15:36,389 - INFO - Deleting VN ctest-vn-45953868 2025-08-06 09:15:36,628 - DEBUG - Response for deleting network () 2025-08-06 09:15:36,628 - INFO - Deleting VN ctest-vn-65352169 2025-08-06 09:15:36,857 - DEBUG - Response for deleting network () 2025-08-06 09:15:37,641 - INFO - Deleted project: ctest-TestSubInterfaces-63219713, ID : 0ca1b0c5-fc55-4732-8a7b-0b8c64e493a8