2025-08-06 07:50:13,258 - INFO - Domain Default found not creating
2025-08-06 07:50:13,432 - INFO - Project ctest-TestPorts-91290424 not found, creating it
2025-08-06 07:50:14,097 - INFO - Created Project:ctest-TestPorts-91290424, ID : 46c0bc0f-f290-4887-9b5f-52c806d631bf
2025-08-06 07:50:15,705 - INFO - ================================================================================
2025-08-06 07:50:15,706 - INFO - STARTING TEST : test_aap_with_fip
2025-08-06 07:50:15,706 - INFO - TEST DESCRIPTION :
1. Create 2 VMs and enable keepalived between them, specifying a vIP.
2. Update the ports of the respective VMs to allow the vIP so configured.
3. Associate the same FIP to both the ports using API.
4. In the Floating IP object, add the vIP as the fixed_ip_address.
5. Ping to the vIP and FIP should be answered by the AAP active port.
6. Cause a keepalived mastership switchover.
7. The vIP and FIP should still be accessible via the new VRRP master.
Maintainer: ganeshahv@juniper.net
2025-08-06 07:50:16,989 - 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 07:50:16,989 - INFO - Initial checks done. Running the testcase now
2025-08-06 07:50:16,989 - INFO -
2025-08-06 07:50:16,989 - INFO - Create a FVN. Create a FIP-Pool and FIP
2025-08-06 07:50:17,777 - DEBUG - Response for create_network : {'network': {'id': 'b4693e17-a850-4f5b-aae0-e32d96d7e0d2', 'name': 'ctest-fvn-92494486', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'project_id': '46c0bc0ff29048879b5f52c806d631bf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-fvn-92494486'], 'port_security_enabled': True, 'description': ''}}
2025-08-06 07:50:18,176 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b85457c6-61ee-4fe0-bad4-e6185a75eec6', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': 'b4693e17-a850-4f5b-aae0-e32d96d7e0d2', 'ip_version': 4, 'cidr': '163.118.24.0/26', 'allocation_pools': [{'start': '163.118.24.2', 'end': '163.118.24.62'}], 'gateway_ip': '163.118.24.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '163.118.24.2', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:50:18,208 - INFO - Created VN ctest-fvn-92494486
2025-08-06 07:50:18,226 - DEBUG - VN ctest-fvn-92494486 UUID is b4693e17-a850-4f5b-aae0-e32d96d7e0d2
2025-08-06 07:50:18,392 - DEBUG - Services list from nova: [, , , ]
2025-08-06 07:50:19,571 - 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 07:50:19,571 - INFO - Waiting for VM ctest-fvn-vm-85685686 to be up..
2025-08-06 07:50:19,622 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-06 07:50:24,723 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:50:24,723 - INFO - VM name : ctest-fvn-vm-85685686
2025-08-06 07:50:24,844 - DEBUG - VM ctest-fvn-vm-85685686 ID is a223f626-f08c-41f7-b430-6b4c779d7709
2025-08-06 07:50:24,889 - DEBUG - VM ctest-fvn-vm-85685686 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1
2025-08-06 07:50:24,998 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/a223f626-f08c-41f7-b430-6b4c779d7709
2025-08-06 07:50:25,307 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/a223f626-f08c-41f7-b430-6b4c779d7709
2025-08-06 07:50:25,345 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/c08daa38-8440-4382-a8ec-b72119b90a9b
2025-08-06 07:50:28,568 - 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 07:50:28,568 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn-vm-85685686 failed!
2025-08-06 07:50:28,587 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-fvn-92494486 is 163.118.24.1 and allocation pool is NOT set
2025-08-06 07:50:30,649 - 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.99 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.517 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.517/2.251/3.986/1.734 ms')
2025-08-06 07:50:30,650 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn-vm-85685686 passed
2025-08-06 07:50:30,772 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:50:30,772 - DEBUG - Waiting to SSH to VM ctest-fvn-vm-85685686, IP 163.118.24.3, Port 22
2025-08-06 07:50:30,935 - DEBUG - VM ctest-fvn-vm-85685686 is ready for SSH connections
2025-08-06 07:50:31,118 - INFO - Creating Floating IP pool some-pool1 in API Server
2025-08-06 07:50:31,281 - DEBUG - Requesting: http://10.0.0.48:8082/domains
2025-08-06 07:50:31,587 - DEBUG - Requesting: http://10.0.0.48:8082/domains
2025-08-06 07:50:31,622 - DEBUG - Requesting: http://10.0.0.48:8082/domain/e3e88518-0617-4e53-bc15-162decab76e0
2025-08-06 07:50:31,641 - DEBUG - Requesting: http://10.0.0.48:8082/project/46c0bc0f-f290-4887-9b5f-52c806d631bf
2025-08-06 07:50:31,742 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-network/b4693e17-a850-4f5b-aae0-e32d96d7e0d2
2025-08-06 07:50:31,759 - DEBUG - Requesting: http://10.0.0.48:8082/floating-ip-pool/216fd876-3bf0-4a6c-881e-a6b3514cd4ef
2025-08-06 07:50:31,768 - DEBUG - Requesting: http://10.0.0.48:8082/domains
2025-08-06 07:50:31,776 - DEBUG - Requesting: http://10.0.0.48:8082/domain/e3e88518-0617-4e53-bc15-162decab76e0
2025-08-06 07:50:31,793 - DEBUG - Requesting: http://10.0.0.48:8082/project/46c0bc0f-f290-4887-9b5f-52c806d631bf
2025-08-06 07:50:31,901 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-network/b4693e17-a850-4f5b-aae0-e32d96d7e0d2
2025-08-06 07:50:31,913 - DEBUG - FIP Pool some-pool1 found in API Server
2025-08-06 07:50:31,913 - INFO - Verification for FIP pool some-pool1 in API Server passed
2025-08-06 07:50:31,930 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information
2025-08-06 07:50:31,937 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information
2025-08-06 07:50:31,944 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information
2025-08-06 07:50:31,945 - INFO - Verification for FIP pool some-pool1 in Control-node passed
2025-08-06 07:50:31,945 - INFO - Creating FIP from some-pool1
2025-08-06 07:50:32,445 - DEBUG - Response for create_network : {'network': {'id': '3ed679b4-0f0c-4aab-93e9-48f45f8efeb3', 'name': 'ctest-vn1-47672438', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'project_id': '46c0bc0ff29048879b5f52c806d631bf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-vn1-47672438'], 'port_security_enabled': True, 'description': ''}}
2025-08-06 07:50:32,715 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a7b069bb-4b78-4c8f-a573-9810a2c8678e', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '3ed679b4-0f0c-4aab-93e9-48f45f8efeb3', 'ip_version': 4, 'cidr': '116.255.191.128/26', 'allocation_pools': [{'start': '116.255.191.130', 'end': '116.255.191.190'}], 'gateway_ip': '116.255.191.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '116.255.191.130', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:50:32,748 - INFO - Created VN ctest-vn1-47672438
2025-08-06 07:50:32,768 - DEBUG - VN ctest-vn1-47672438 UUID is 3ed679b4-0f0c-4aab-93e9-48f45f8efeb3
2025-08-06 07:50:33,174 - DEBUG - Response for create_port : {'port': {'name': '8294bc7f-9b38-45f5-9c29-e80acf5d93aa', 'id': '8294bc7f-9b38-45f5-9c29-e80acf5d93aa', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '3ed679b4-0f0c-4aab-93e9-48f45f8efeb3', 'mac_address': '02:82:94:bc:7f:9b', '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': '116.255.191.131', 'subnet_id': 'a7b069bb-4b78-4c8f-a573-9810a2c8678e'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:50:33,529 - DEBUG - Response for create_port : {'port': {'name': 'b84f09a4-ef2f-400f-9105-3bb0634be504', 'id': 'b84f09a4-ef2f-400f-9105-3bb0634be504', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '3ed679b4-0f0c-4aab-93e9-48f45f8efeb3', 'mac_address': '02:b8:4f:09:a4:ef', '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': '116.255.191.132', 'subnet_id': 'a7b069bb-4b78-4c8f-a573-9810a2c8678e'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:50:33,726 - DEBUG - Image by name ubuntu-keepalive not found
2025-08-06 07:50:33,726 - DEBUG - Installing image ubuntu-keepalive
2025-08-06 07:50:33,726 - DEBUG - Image info {'name': 'ubuntu-keepalive.img.gz', 'webserver': '', 'location': '/images/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_large', 'params': '--container-format ovf --disk-format qcow2 --property hypervisor_type=qemu', 'name_docker': 'phusion-baseimage-enablesshd'}
2025-08-06 07:50:33,726 - DEBUG - Image build path http://nexus.opensdn.io/repository///images//ubuntu-keepalive.img.gz
2025-08-06 07:50:33,726 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images//ubuntu-keepalive.img.gz
2025-08-06 07:50:33,741 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: wget -nv http://nexus.opensdn.io/repository///images//ubuntu-keepalive.img.gz -O /contrail-test/images/ubuntu-keepalive.img.gz
2025-08-06 07:50:35,724 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-keepalive.img.gz
2025-08-06 07:50:35,725 - DEBUG - Unzip image
2025-08-06 07:50:35,725 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-keepalive.img.gz
2025-08-06 07:50:44,424 - DEBUG - Try to create image in user context
2025-08-06 07:50:50,662 - DEBUG - Image has been created in user context
2025-08-06 07:50:50,662 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-keepalive.img
2025-08-06 07:50:50,840 - DEBUG - Downloaded image has been removed
2025-08-06 07:50:50,868 - DEBUG - Uploaded image status = active
2025-08-06 07:50:51,534 - 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 07:50:52,409 - 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 07:50:54,726 - 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 07:50:54,727 - INFO - Waiting for VM ctest-vm1-20462638 to be up..
2025-08-06 07:50:54,875 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-06 07:50:59,978 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-06 07:51:05,082 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:51:05,082 - INFO - VM name : ctest-vm1-20462638
2025-08-06 07:51:05,197 - DEBUG - VM ctest-vm1-20462638 ID is c6e158c3-8454-4d21-ba3c-f00050db5b93
2025-08-06 07:51:05,197 - DEBUG - VM ctest-vm1-20462638 launched on Node an-jenkins-deploy-platform-ansible-os-3761-2
2025-08-06 07:51:05,302 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/c6e158c3-8454-4d21-ba3c-f00050db5b93
2025-08-06 07:51:05,318 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/8294bc7f-9b38-45f5-9c29-e80acf5d93aa
2025-08-06 07:51:08,574 - 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 1032ms')
2025-08-06 07:51:08,574 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:08,593 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:12,673 - 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')
2025-08-06 07:51:12,673 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:12,693 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:16,774 - 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 07:51:16,774 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:16,791 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:20,868 - 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 1006ms')
2025-08-06 07:51:20,868 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:20,888 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:24,965 - 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 07:51:24,965 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:24,988 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:29,064 - 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 1006ms')
2025-08-06 07:51:29,064 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:29,089 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:33,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 1031ms')
2025-08-06 07:51:33,184 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:33,203 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:37,289 - 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')
2025-08-06 07:51:37,289 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:37,310 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:41,383 - 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 07:51:41,383 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:41,402 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:45,472 - 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 1006ms')
2025-08-06 07:51:45,472 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:45,490 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:49,569 - 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 07:51:49,569 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:49,588 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:53,670 - 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 07:51:53,670 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:53,692 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:51:57,764 - 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')
2025-08-06 07:51:57,764 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:51:57,783 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:52:01,861 - 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 1006ms')
2025-08-06 07:52:01,861 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 failed!
2025-08-06 07:52:01,877 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-47672438 is 116.255.191.129 and allocation pool is NOT set
2025-08-06 07:52:03,947 - 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.91 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.27 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 = 1.266/4.090/6.914/2.824 ms')
2025-08-06 07:52:03,947 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-20462638 passed
2025-08-06 07:52:04,069 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:04,069 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:04,136 - 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 07:52:04,241 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:09,241 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:09,242 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:09,308 - 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 07:52:09,405 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:14,406 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:14,406 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:14,474 - 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 07:52:14,584 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:19,584 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:19,584 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:19,653 - 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 07:52:19,762 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:24,763 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:24,763 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:24,829 - 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 07:52:24,923 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:29,924 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:29,925 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:29,983 - 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 07:52:30,120 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:35,121 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:35,122 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:35,189 - 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 07:52:35,288 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:40,288 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:40,289 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:40,358 - 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 07:52:40,456 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:45,457 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:45,457 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:45,514 - 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 07:52:45,659 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:50,660 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:50,661 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:50,729 - 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 07:52:50,843 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:52:55,844 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:52:55,845 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:52:55,915 - 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 07:52:56,011 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:53:01,012 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:53:01,012 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:53:01,081 - 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 07:53:01,184 - DEBUG - VM ctest-vm1-20462638 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:53:06,185 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:53:06,185 - DEBUG - Waiting to SSH to VM ctest-vm1-20462638, IP 116.255.191.131, Port 22
2025-08-06 07:53:06,358 - DEBUG - VM ctest-vm1-20462638 is ready for SSH connections
2025-08-06 07:53:06,358 - INFO - Waiting for VM ctest-vm2-16402716 to be up..
2025-08-06 07:53:06,463 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:53:06,463 - INFO - VM name : ctest-vm2-16402716
2025-08-06 07:53:06,566 - DEBUG - VM ctest-vm2-16402716 ID is 0e2a351d-e080-431c-9f04-02c5b05257bd
2025-08-06 07:53:06,566 - DEBUG - VM ctest-vm2-16402716 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1
2025-08-06 07:53:06,708 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/0e2a351d-e080-431c-9f04-02c5b05257bd
2025-08-06 07:53:06,722 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/b84f09a4-ef2f-400f-9105-3bb0634be504
2025-08-06 07:53:08,006 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=3.09 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.471 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.471/1.778/3.086/1.307 ms')
2025-08-06 07:53:08,006 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vm2-16402716 passed
2025-08-06 07:53:08,127 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:53:08,127 - DEBUG - Waiting to SSH to VM ctest-vm2-16402716, IP 116.255.191.132, Port 22
2025-08-06 07:53:08,284 - DEBUG - VM ctest-vm2-16402716 is ready for SSH connections
2025-08-06 07:53:08,284 - INFO - Waiting for VM ctest-vm_test-89697360 to be up..
2025-08-06 07:53:08,354 - DEBUG - VM is in ERROR state now
2025-08-06 07:53:08,354 - ERROR - VM in error state.
2025-08-06 07:53:08,354 - ERROR - VM is not in ACTIVE state
2025-08-06 07:53:08,471 - ERROR - Fatal Nova Exception while getting VM detail
2025-08-06 07:53:08,472 - DEBUG - None
2025-08-06 07:53:08,474 - INFO - Skip interface_detach for VM ctest-vm_test-89697360 in state ERROR
2025-08-06 07:53:08,474 - INFO - Deleting VM ctest-vm_test-89697360
2025-08-06 07:53:08,475 - ERROR - VM ctest-vm_test-89697360 has failed to come up
2025-08-06 07:53:08,475 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-08-06T07:50:54Z', 'message': 'No valid host was found. ', 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 1581, in schedule_and_build_instances\n instance_uuids, return_alternates=True)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 942, in _schedule_instances\n return_alternates=return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/client/query.py", line 42, in select_destinations\n instance_uuids, return_objects, return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/rpcapi.py", line 160, in select_destinations\n return cctxt.call(ctxt, \'select_destinations\', **msg_args)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/client.py", line 192, in call\n retry=self.retry, transport_options=self.transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/transport.py", line 128, in _send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 691, in send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 681, in _send\n raise result\nnova.exception_Remote.NoValidHost_Remote: No valid host was found. \nTraceback (most recent call last):\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 241, in inner\n return func(*args, **kwargs)\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/manager.py", line 209, in select_destinations\n raise exception.NoValidHost(reason="")\n\nnova.exception.NoValidHost: No valid host was found. \n\n'}
2025-08-06 07:53:08,477 - INFO - Detaching port b84f09a4-ef2f-400f-9105-3bb0634be504 from VM ctest-vm2-16402716
2025-08-06 07:53:08,532 - INFO - Deleting VM ctest-vm2-16402716
2025-08-06 07:53:08,629 - INFO - Detaching port 8294bc7f-9b38-45f5-9c29-e80acf5d93aa from VM ctest-vm1-20462638
2025-08-06 07:53:08,670 - INFO - Deleting VM ctest-vm1-20462638
2025-08-06 07:53:09,085 - DEBUG - Response for delete_port : ()
2025-08-06 07:53:09,369 - DEBUG - Response for delete_port : ()
2025-08-06 07:53:09,369 - INFO - Deleting VN ctest-vn1-47672438
2025-08-06 07:53:09,587 - DEBUG - Response for deleting network ()
2025-08-06 07:53:09,646 - INFO - Deleting the FIP pool some-pool1
2025-08-06 07:53:09,832 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information
2025-08-06 07:53:09,844 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information
2025-08-06 07:53:09,853 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information
2025-08-06 07:53:09,853 - INFO - Deleting VM ctest-fvn-vm-85685686
2025-08-06 07:53:09,946 - INFO - Deleting VN ctest-fvn-92494486
2025-08-06 07:53:10,000 - DEBUG - VN b4693e17-a850-4f5b-aae0-e32d96d7e0d2 still in use: Unable to complete operation on network b4693e17-a850-4f5b-aae0-e32d96d7e0d2. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-aad962e2-5e1f-4965-996e-30c51ccd337d']
2025-08-06 07:53:10,000 - WARNING - Deleting VN ctest-fvn-92494486 failed..Will retry
2025-08-06 07:53:12,244 - DEBUG - Response for deleting network ()
2025-08-06 07:53:13,573 - ERROR - AssertionError
Python 3.6.8: /usr/bin/python3
Wed Aug 6 07:53:08 2025
A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
78 log.info('Initial checks done. Running the testcase now')
79 log.info('')
80 result = function(self, *args, **kwargs)
81 if self.inputs.upgrade:
82 pid = os.getpid()
result = None
function =
self =
args = ()
kwargs = {}
/contrail-test/scripts/neutron/test_ports.py in test_aap_with_fip(self=)
1081 assert vm2_fixture.wait_till_vm_is_up(), 'VM does not seem to be up'
1082 assert vm_test_fixture.wait_till_vm_is_up(
1083 ), 'VM does not seem to be up'
1084 for port in port_list:
1085 self.config_aap(
AssertionError: VM does not seem to be up
__cause__ = None
__class__ =
__context__ = None
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = 'Assertion failed.'
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
args = ('VM does not seem to be up',)
with_traceback =
The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/neutron/test_ports.py", line 1083, in test_aap_with_fip
), 'VM does not seem to be up'
AssertionError: VM does not seem to be up
2025-08-06 07:53:13,592 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 07:53:13,592 - INFO -
2025-08-06 07:53:13,592 - INFO - END TEST : test_aap_with_fip : FAILED[0:02:58]
2025-08-06 07:53:13,592 - INFO - --------------------------------------------------------------------------------
2025-08-06 07:53:13,597 - INFO - ================================================================================
2025-08-06 07:53:13,597 - INFO - STARTING TEST : test_aap_with_zero_mac
2025-08-06 07:53:13,597 - INFO - TEST DESCRIPTION :
Verify VIP reachability over L2 network when AAP MAC is configured with all zeo
1. Launch 2 vms on same virtual network.
2. Configure high availability between them with keepalived.
3. Launch third VM in same VM.
4. Check the reachability of VIP from 3rd VM.
5. Shutdown keepalive in master VM to induce VIP switch over.
6. Check the reachability of VIP from 3rd VM again.
7. Bring back master VM which will cause switchover of VIP again.
8. Check the reachability of VIP from 3rd VM again.
Pass criteria: Step 4,6 and 8 should pass
Maintainer: chhandak@juniper.net
2025-08-06 07:53:14,887 - 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 07:53:14,887 - INFO - Initial checks done. Running the testcase now
2025-08-06 07:53:14,887 - INFO -
2025-08-06 07:53:15,212 - DEBUG - Response for create_network : {'network': {'id': '0e876dbd-a66c-4ffc-b5a9-88eb630902f5', 'name': 'ctest-vn1-70165690', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'project_id': '46c0bc0ff29048879b5f52c806d631bf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-vn1-70165690'], 'port_security_enabled': True, 'description': ''}}
2025-08-06 07:53:15,499 - DEBUG - Response for create_subnet : {'subnet': {'id': '47f88c3e-9ba7-46fc-a6f0-d77b766cf02b', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '0e876dbd-a66c-4ffc-b5a9-88eb630902f5', 'ip_version': 4, 'cidr': '155.75.81.128/26', 'allocation_pools': [{'start': '155.75.81.130', 'end': '155.75.81.190'}], 'gateway_ip': '155.75.81.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '155.75.81.130', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:53:15,543 - INFO - Created VN ctest-vn1-70165690
2025-08-06 07:53:15,583 - DEBUG - VN ctest-vn1-70165690 UUID is 0e876dbd-a66c-4ffc-b5a9-88eb630902f5
2025-08-06 07:53:16,036 - DEBUG - Response for create_port : {'port': {'name': 'f3d27dc2-b5d2-4845-a223-a4f2bbd89a42', 'id': 'f3d27dc2-b5d2-4845-a223-a4f2bbd89a42', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '0e876dbd-a66c-4ffc-b5a9-88eb630902f5', 'mac_address': '02:f3:d2:7d:c2:b5', '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': '155.75.81.131', 'subnet_id': '47f88c3e-9ba7-46fc-a6f0-d77b766cf02b'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:53:16,460 - DEBUG - Response for create_port : {'port': {'name': 'ccace5ad-19c5-44de-8a37-4e86bd25e7e7', 'id': 'ccace5ad-19c5-44de-8a37-4e86bd25e7e7', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '0e876dbd-a66c-4ffc-b5a9-88eb630902f5', 'mac_address': '02:cc:ac:e5:ad:19', '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': '155.75.81.132', 'subnet_id': '47f88c3e-9ba7-46fc-a6f0-d77b766cf02b'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:53:17,144 - 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 07:53:17,854 - 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 07:53:19,613 - 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 07:53:19,613 - INFO - Waiting for VM ctest-vm1-98837843 to be up..
2025-08-06 07:53:19,706 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:53:19,707 - INFO - VM name : ctest-vm1-98837843
2025-08-06 07:53:19,808 - DEBUG - VM ctest-vm1-98837843 ID is d6f7cc68-db9a-4583-a633-037bc53d30f2
2025-08-06 07:53:19,808 - DEBUG - VM ctest-vm1-98837843 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1
2025-08-06 07:53:19,927 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/d6f7cc68-db9a-4583-a633-037bc53d30f2
2025-08-06 07:53:19,942 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/f3d27dc2-b5d2-4845-a223-a4f2bbd89a42
2025-08-06 07:53:23,193 - 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-06 07:53:23,194 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:23,211 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:27,295 - 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 1016ms')
2025-08-06 07:53:27,295 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:27,313 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:31,385 - 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 07:53:31,385 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:31,411 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:35,481 - 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')
2025-08-06 07:53:35,481 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:35,498 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:39,583 - 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')
2025-08-06 07:53:39,583 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:39,602 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:43,675 - 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 07:53:43,675 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:43,697 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:47,766 - 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 1011ms')
2025-08-06 07:53:47,766 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:47,782 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:51,869 - 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 1023ms')
2025-08-06 07:53:51,869 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:51,888 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:53:55,959 - 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 07:53:55,959 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:53:55,984 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:54:00,061 - 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 1016ms')
2025-08-06 07:54:00,061 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:54:00,080 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:54:04,156 - 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 1001ms')
2025-08-06 07:54:04,156 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:54:04,175 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:54:08,252 - 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 1011ms')
2025-08-06 07:54:08,252 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:54:08,270 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:54:12,344 - 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 07:54:12,344 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 failed!
2025-08-06 07:54:12,364 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-70165690 is 155.75.81.129 and allocation pool is NOT set
2025-08-06 07:54:14,426 - 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.58 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.875 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.875/2.729/4.584/1.854 ms')
2025-08-06 07:54:14,427 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-98837843 passed
2025-08-06 07:54:14,550 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:14,550 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:14,618 - 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 07:54:14,734 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:19,734 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:19,735 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:19,794 - 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 07:54:19,893 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:24,894 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:24,894 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:24,964 - 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 07:54:25,099 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:30,099 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:30,100 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:30,167 - 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 07:54:30,275 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:35,275 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:35,275 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:35,334 - 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 07:54:35,461 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:40,462 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:40,462 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:40,521 - 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 07:54:40,617 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:45,618 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:45,618 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:45,688 - 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 07:54:45,796 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:50,797 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:50,797 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:50,853 - 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 07:54:50,959 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:54:55,960 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:54:55,960 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:54:56,028 - 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 07:54:56,141 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:55:01,141 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:01,142 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:55:01,210 - 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 07:55:01,307 - DEBUG - VM ctest-vm1-98837843 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:55:06,307 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:06,307 - DEBUG - Waiting to SSH to VM ctest-vm1-98837843, IP 155.75.81.131, Port 22
2025-08-06 07:55:06,479 - DEBUG - VM ctest-vm1-98837843 is ready for SSH connections
2025-08-06 07:55:06,479 - INFO - Waiting for VM ctest-vm2-97532188 to be up..
2025-08-06 07:55:06,569 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:55:06,569 - INFO - VM name : ctest-vm2-97532188
2025-08-06 07:55:06,673 - DEBUG - VM ctest-vm2-97532188 ID is e22a6318-aab8-48fd-93ed-27924306ba68
2025-08-06 07:55:06,673 - DEBUG - VM ctest-vm2-97532188 launched on Node an-jenkins-deploy-platform-ansible-os-3761-2
2025-08-06 07:55:06,781 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/e22a6318-aab8-48fd-93ed-27924306ba68
2025-08-06 07:55:06,808 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/ccace5ad-19c5-44de-8a37-4e86bd25e7e7
2025-08-06 07:55:08,023 - 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.54 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.595 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.595/2.065/3.536/1.470 ms')
2025-08-06 07:55:08,023 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm2-97532188 passed
2025-08-06 07:55:08,141 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:08,141 - DEBUG - Waiting to SSH to VM ctest-vm2-97532188, IP 155.75.81.132, Port 22
2025-08-06 07:55:08,209 - 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 07:55:08,303 - DEBUG - VM ctest-vm2-97532188 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:55:13,304 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:13,304 - DEBUG - Waiting to SSH to VM ctest-vm2-97532188, IP 155.75.81.132, Port 22
2025-08-06 07:55:13,364 - 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 07:55:13,479 - DEBUG - VM ctest-vm2-97532188 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:55:18,480 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:18,480 - DEBUG - Waiting to SSH to VM ctest-vm2-97532188, IP 155.75.81.132, Port 22
2025-08-06 07:55:18,539 - 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 07:55:18,714 - DEBUG - VM ctest-vm2-97532188 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-06 07:55:23,716 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:23,716 - DEBUG - Waiting to SSH to VM ctest-vm2-97532188, IP 155.75.81.132, Port 22
2025-08-06 07:55:23,889 - DEBUG - VM ctest-vm2-97532188 is ready for SSH connections
2025-08-06 07:55:23,890 - INFO - Waiting for VM ctest-vm_test-08179025 to be up..
2025-08-06 07:55:23,995 - DEBUG - VM is in ERROR state now
2025-08-06 07:55:23,996 - ERROR - VM in error state.
2025-08-06 07:55:23,996 - ERROR - VM is not in ACTIVE state
2025-08-06 07:55:24,101 - ERROR - Fatal Nova Exception while getting VM detail
2025-08-06 07:55:24,101 - DEBUG - None
2025-08-06 07:55:24,103 - INFO - Skip interface_detach for VM ctest-vm_test-08179025 in state ERROR
2025-08-06 07:55:24,103 - INFO - Deleting VM ctest-vm_test-08179025
2025-08-06 07:55:24,103 - ERROR - VM ctest-vm_test-08179025 has failed to come up
2025-08-06 07:55:24,103 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-08-06T07:53:19Z', 'message': 'No valid host was found. ', 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 1581, in schedule_and_build_instances\n instance_uuids, return_alternates=True)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 942, in _schedule_instances\n return_alternates=return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/client/query.py", line 42, in select_destinations\n instance_uuids, return_objects, return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/rpcapi.py", line 160, in select_destinations\n return cctxt.call(ctxt, \'select_destinations\', **msg_args)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/client.py", line 192, in call\n retry=self.retry, transport_options=self.transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/transport.py", line 128, in _send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 691, in send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 681, in _send\n raise result\nnova.exception_Remote.NoValidHost_Remote: No valid host was found. \nTraceback (most recent call last):\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 241, in inner\n return func(*args, **kwargs)\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/manager.py", line 209, in select_destinations\n raise exception.NoValidHost(reason="")\n\nnova.exception.NoValidHost: No valid host was found. \n\n'}
2025-08-06 07:55:24,103 - INFO - Detaching port ccace5ad-19c5-44de-8a37-4e86bd25e7e7 from VM ctest-vm2-97532188
2025-08-06 07:55:24,162 - INFO - Deleting VM ctest-vm2-97532188
2025-08-06 07:55:24,315 - INFO - Detaching port f3d27dc2-b5d2-4845-a223-a4f2bbd89a42 from VM ctest-vm1-98837843
2025-08-06 07:55:24,394 - INFO - Deleting VM ctest-vm1-98837843
2025-08-06 07:55:24,867 - DEBUG - Response for delete_port : ()
2025-08-06 07:55:25,134 - DEBUG - Response for delete_port : ()
2025-08-06 07:55:25,135 - INFO - Deleting VN ctest-vn1-70165690
2025-08-06 07:55:25,382 - DEBUG - Response for deleting network ()
2025-08-06 07:55:26,630 - ERROR - AssertionError
Python 3.6.8: /usr/bin/python3
Wed Aug 6 07:55:24 2025
A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
78 log.info('Initial checks done. Running the testcase now')
79 log.info('')
80 result = function(self, *args, **kwargs)
81 if self.inputs.upgrade:
82 pid = os.getpid()
result = None
function =
self =
args = ()
kwargs = {}
/contrail-test/scripts/neutron/test_ports.py in test_aap_with_zero_mac(self=)
1161 assert vm2_fixture.wait_till_vm_is_up(), 'VM does not seem to be up'
1162 assert vm_test_fixture.wait_till_vm_is_up(
1163 ), 'VM does not seem to be up'
1164 for port in port_list:
1165 self.config_aap(
AssertionError: VM does not seem to be up
__cause__ = None
__class__ =
__context__ = None
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = 'Assertion failed.'
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
args = ('VM does not seem to be up',)
with_traceback =
The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/neutron/test_ports.py", line 1163, in test_aap_with_zero_mac
), 'VM does not seem to be up'
AssertionError: VM does not seem to be up
2025-08-06 07:55:26,645 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 07:55:26,646 - INFO -
2025-08-06 07:55:26,646 - INFO - END TEST : test_aap_with_zero_mac : FAILED[0:02:13]
2025-08-06 07:55:26,646 - INFO - --------------------------------------------------------------------------------
2025-08-06 07:55:26,649 - INFO - ================================================================================
2025-08-06 07:55:26,649 - INFO - STARTING TEST : test_ports_bindings
2025-08-06 07:55:26,649 - INFO - TEST DESCRIPTION :
Verify that we are able to create a port with custom port bindings
Steps:
1) Create Port with Port bindings profile set to {'foo': 'bar'}
2) Retrieve and verify the same is set
2025-08-06 07:55:27,960 - 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 07:55:27,960 - INFO - Initial checks done. Running the testcase now
2025-08-06 07:55:27,960 - INFO -
2025-08-06 07:55:28,290 - DEBUG - Response for create_network : {'network': {'id': '1441eb21-1581-4a27-aac1-947dc07c134e', 'name': 'ctest-vn-02689966', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'project_id': '46c0bc0ff29048879b5f52c806d631bf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-vn-02689966'], 'port_security_enabled': True, 'description': ''}}
2025-08-06 07:55:28,586 - DEBUG - Response for create_subnet : {'subnet': {'id': '4d191cac-568b-44ec-b8a3-15be15b972dd', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '1441eb21-1581-4a27-aac1-947dc07c134e', 'ip_version': 4, 'cidr': '126.92.96.0/26', 'allocation_pools': [{'start': '126.92.96.2', 'end': '126.92.96.62'}], 'gateway_ip': '126.92.96.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '126.92.96.2', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:28,614 - INFO - Created VN ctest-vn-02689966
2025-08-06 07:55:28,633 - DEBUG - VN ctest-vn-02689966 UUID is 1441eb21-1581-4a27-aac1-947dc07c134e
2025-08-06 07:55:28,738 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-vmi-41991450']}
2025-08-06 07:55:29,053 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-41991450', 'id': '0aba4d95-46fb-4862-a2f4-332fd3e841c1', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '1441eb21-1581-4a27-aac1-947dc07c134e', 'mac_address': '02:0a:ba:4d:95:46', 'binding:profile': {'foo': 'bar'}, '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': '126.92.96.3', 'subnet_id': '4d191cac-568b-44ec-b8a3-15be15b972dd'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:29,053 - DEBUG - Created port 0aba4d95-46fb-4862-a2f4-332fd3e841c1
2025-08-06 07:55:29,167 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/0aba4d95-46fb-4862-a2f4-332fd3e841c1
2025-08-06 07:55:29,186 - INFO - VMI 0aba4d95-46fb-4862-a2f4-332fd3e841c1 verification in API Server passed
2025-08-06 07:55:29,346 - DEBUG - Response for delete_port : ()
2025-08-06 07:55:29,346 - INFO - Deleted port 0aba4d95-46fb-4862-a2f4-332fd3e841c1
2025-08-06 07:55:29,346 - INFO - Deleting VN ctest-vn-02689966
2025-08-06 07:55:29,560 - DEBUG - Response for deleting network ()
2025-08-06 07:55:30,838 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 07:55:30,838 - INFO - END TEST : test_ports_bindings : PASSED[0:00:04]
2025-08-06 07:55:30,838 - INFO - --------------------------------------------------------------------------------
2025-08-06 07:55:30,843 - INFO - ================================================================================
2025-08-06 07:55:30,843 - INFO - STARTING TEST : test_ports_specific_subnet_ip
2025-08-06 07:55:30,843 - INFO - TEST DESCRIPTION : Create ports with specific Subnet and IP
Create two ports in a VN with 2 subnets and specific IPs
Attach to two VMs
Ping between them should pass
2025-08-06 07:55:32,141 - 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 07:55:32,141 - INFO - Initial checks done. Running the testcase now
2025-08-06 07:55:32,141 - INFO -
2025-08-06 07:55:32,495 - DEBUG - Response for create_network : {'network': {'id': '7ce9f8a9-a44f-40c0-861e-569a26524194', 'name': 'ctest-vn1-45889537', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'project_id': '46c0bc0ff29048879b5f52c806d631bf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-91290424', 'ctest-vn1-45889537'], 'port_security_enabled': True, 'description': ''}}
2025-08-06 07:55:32,789 - DEBUG - Response for create_subnet : {'subnet': {'id': '1ccaaf5f-85b2-4383-b2f3-3d090e2fdcfa', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '7ce9f8a9-a44f-40c0-861e-569a26524194', 'ip_version': 4, 'cidr': '206.48.19.64/26', 'allocation_pools': [{'start': '206.48.19.66', 'end': '206.48.19.126'}], 'gateway_ip': '206.48.19.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '206.48.19.66', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:33,039 - DEBUG - Response for create_subnet : {'subnet': {'id': '2a6ecd41-f2d2-441b-96d0-688ca7cb07f1', 'name': '', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '7ce9f8a9-a44f-40c0-861e-569a26524194', 'ip_version': 4, 'cidr': '206.48.173.128/26', 'allocation_pools': [{'start': '206.48.173.130', 'end': '206.48.173.190'}], 'gateway_ip': '206.48.173.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '206.48.173.130', 'tags': [], 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:33,075 - INFO - Created VN ctest-vn1-45889537
2025-08-06 07:55:33,089 - DEBUG - VN ctest-vn1-45889537 UUID is 7ce9f8a9-a44f-40c0-861e-569a26524194
2025-08-06 07:55:33,498 - DEBUG - Response for create_port : {'port': {'name': '664d9aea-2a68-4c0b-8fe8-64c3193e0da5', 'id': '664d9aea-2a68-4c0b-8fe8-64c3193e0da5', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '7ce9f8a9-a44f-40c0-861e-569a26524194', 'mac_address': '02:66:4d:9a:ea:2a', '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': '206.48.19.69', 'subnet_id': '1ccaaf5f-85b2-4383-b2f3-3d090e2fdcfa'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:33,880 - DEBUG - Response for create_port : {'port': {'name': '01b5a001-7981-43a9-a95a-dae9a3bb0733', 'id': '01b5a001-7981-43a9-a95a-dae9a3bb0733', 'tenant_id': '46c0bc0ff29048879b5f52c806d631bf', 'network_id': '7ce9f8a9-a44f-40c0-861e-569a26524194', 'mac_address': '02:01:b5:a0:01:79', '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': '206.48.173.133', 'subnet_id': '2a6ecd41-f2d2-441b-96d0-688ca7cb07f1'}], 'security_groups': ['5f3ed81e-257c-4763-b526-9e8392a75dc2'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '46c0bc0ff29048879b5f52c806d631bf'}}
2025-08-06 07:55:34,550 - 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 07:55:35,383 - 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 07:55:35,383 - INFO - Waiting for VM ctest-vn1-vm1-35794914 to be up..
2025-08-06 07:55:35,598 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-06 07:55:40,686 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:55:40,686 - INFO - VM name : ctest-vn1-vm1-35794914
2025-08-06 07:55:40,775 - DEBUG - VM ctest-vn1-vm1-35794914 ID is feececd4-42d2-4491-935b-eccc1571ed7c
2025-08-06 07:55:40,775 - DEBUG - VM ctest-vn1-vm1-35794914 launched on Node an-jenkins-deploy-platform-ansible-os-3761-2
2025-08-06 07:55:40,860 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/feececd4-42d2-4491-935b-eccc1571ed7c
2025-08-06 07:55:40,898 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/664d9aea-2a68-4c0b-8fe8-64c3193e0da5
2025-08-06 07:55:44,164 - 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')
2025-08-06 07:55:44,164 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-35794914 failed!
2025-08-06 07:55:44,182 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-45889537 is 206.48.19.65 and allocation pool is NOT set
2025-08-06 07:55:44,182 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-45889537 is 206.48.173.129 and allocation pool is NOT set
2025-08-06 07:55:48,255 - 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 1011ms')
2025-08-06 07:55:48,256 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-35794914 failed!
2025-08-06 07:55:48,276 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-45889537 is 206.48.19.65 and allocation pool is NOT set
2025-08-06 07:55:48,277 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-91290424:ctest-vn1-45889537 is 206.48.173.129 and allocation pool is NOT set
2025-08-06 07:55:50,353 - 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=5.15 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.63 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 = 3.629/4.389/5.150/0.760 ms')
2025-08-06 07:55:50,353 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-35794914 passed
2025-08-06 07:55:50,484 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:50,484 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-35794914, IP 206.48.19.69, Port 22
2025-08-06 07:55:50,666 - DEBUG - VM ctest-vn1-vm1-35794914 is ready for SSH connections
2025-08-06 07:55:50,666 - INFO - Waiting for VM ctest-vn1-vm2-05018309 to be up..
2025-08-06 07:55:50,834 - DEBUG - VM is in ACTIVE state now
2025-08-06 07:55:50,834 - INFO - VM name : ctest-vn1-vm2-05018309
2025-08-06 07:55:50,999 - DEBUG - VM ctest-vn1-vm2-05018309 ID is 01aeffc0-32b1-4c9a-b648-c06d210e5fef
2025-08-06 07:55:50,999 - DEBUG - VM ctest-vn1-vm2-05018309 launched on Node an-jenkins-deploy-platform-ansible-os-3761-1
2025-08-06 07:55:51,132 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/01aeffc0-32b1-4c9a-b648-c06d210e5fef
2025-08-06 07:55:51,144 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/01b5a001-7981-43a9-a95a-dae9a3bb0733
2025-08-06 07:55:52,376 - 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.03 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.414 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.414/2.221/4.028/1.807 ms')
2025-08-06 07:55:52,376 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm2-05018309 passed
2025-08-06 07:55:52,495 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:52,495 - DEBUG - Waiting to SSH to VM ctest-vn1-vm2-05018309, IP 206.48.173.133, Port 22
2025-08-06 07:55:52,660 - DEBUG - VM ctest-vn1-vm2-05018309 is ready for SSH connections
2025-08-06 07:55:52,660 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:52,660 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:52,660 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-06 07:55:52,660 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 206.48.19.69, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-08-06 07:55:52,661 - DEBUG - ping -s 56 -c 3 -W 1 206.48.19.69
2025-08-06 07:55:56,643 - DEBUG - PING 206.48.19.69 (206.48.19.69): 56 data bytes
64 bytes from 206.48.19.69: seq=0 ttl=63 time=5.423 ms
64 bytes from 206.48.19.69: seq=1 ttl=63 time=1.451 ms
64 bytes from 206.48.19.69: seq=2 ttl=63 time=1.387 ms
--- 206.48.19.69 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.387/2.753/5.423 ms
2025-08-06 07:55:56,643 - INFO - Ping to IP 206.48.19.69 from VM ctest-vn1-vm2-05018309 passed
2025-08-06 07:55:56,643 - INFO - Detaching port 01b5a001-7981-43a9-a95a-dae9a3bb0733 from VM ctest-vn1-vm2-05018309
2025-08-06 07:55:56,682 - INFO - Deleting VM ctest-vn1-vm2-05018309
2025-08-06 07:55:56,768 - INFO - Detaching port 664d9aea-2a68-4c0b-8fe8-64c3193e0da5 from VM ctest-vn1-vm1-35794914
2025-08-06 07:55:56,809 - INFO - Deleting VM ctest-vn1-vm1-35794914
2025-08-06 07:55:57,217 - DEBUG - Response for delete_port : ()
2025-08-06 07:55:57,474 - DEBUG - Response for delete_port : ()
2025-08-06 07:55:57,474 - INFO - Deleting VN ctest-vn1-45889537
2025-08-06 07:55:57,685 - DEBUG - Response for deleting network ()
2025-08-06 07:55:59,038 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 07:55:59,038 - INFO - END TEST : test_ports_specific_subnet_ip : PASSED[0:00:29]
2025-08-06 07:55:59,038 - INFO - --------------------------------------------------------------------------------
2025-08-06 07:55:59,809 - INFO - Deleted project: ctest-TestPorts-91290424, ID : 46c0bc0f-f290-4887-9b5f-52c806d631bf