2025-08-06 14:46:27,634 - INFO - Domain Default found not creating 2025-08-06 14:46:27,784 - INFO - Project ctest-TestPorts-40542843 not found, creating it 2025-08-06 14:46:28,324 - INFO - Created Project:ctest-TestPorts-40542843, ID : 4a9ca969-9979-49e2-bcb6-d91e71309268 2025-08-06 14:46:29,764 - INFO - ================================================================================ 2025-08-06 14:46:29,764 - INFO - STARTING TEST : test_aap_with_fip 2025-08-06 14:46:29,764 - 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 14:46:31,054 - 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.25': '0', '10.20.0.14': '0'}} with 2025-08-06 14:46:31,054 - INFO - Initial checks done. Running the testcase now 2025-08-06 14:46:31,054 - INFO - 2025-08-06 14:46:31,054 - INFO - Create a FVN. Create a FIP-Pool and FIP 2025-08-06 14:46:31,736 - DEBUG - Response for create_network : {'network': {'id': '00aa5816-446c-4f93-8f97-0a3f650d2ca3', 'name': 'ctest-fvn-90891631', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'project_id': '4a9ca969997949e2bcb6d91e71309268', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-fvn-90891631'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 14:46:31,991 - DEBUG - Response for create_subnet : {'subnet': {'id': 'abeca5b8-c3b8-4d22-8a09-a014b047ee0b', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '00aa5816-446c-4f93-8f97-0a3f650d2ca3', 'ip_version': 4, 'cidr': '33.228.30.192/26', 'allocation_pools': [{'start': '33.228.30.194', 'end': '33.228.30.254'}], 'gateway_ip': '33.228.30.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '33.228.30.194', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:46:32,022 - INFO - Created VN ctest-fvn-90891631 2025-08-06 14:46:32,040 - DEBUG - VN ctest-fvn-90891631 UUID is 00aa5816-446c-4f93-8f97-0a3f650d2ca3 2025-08-06 14:46:32,231 - DEBUG - Services list from nova: [, , , ] 2025-08-06 14:46:33,305 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 14:46:33,305 - INFO - Waiting for VM ctest-fvn-vm-84913602 to be up.. 2025-08-06 14:46:33,354 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-06 14:46:38,450 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:46:38,450 - INFO - VM name : ctest-fvn-vm-84913602 2025-08-06 14:46:38,524 - DEBUG - VM ctest-fvn-vm-84913602 ID is 309a8ece-e057-4529-98d6-286b0e1f0e98 2025-08-06 14:46:38,547 - DEBUG - VM ctest-fvn-vm-84913602 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 14:46:38,640 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/309a8ece-e057-4529-98d6-286b0e1f0e98 2025-08-06 14:46:38,940 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/309a8ece-e057-4529-98d6-286b0e1f0e98 2025-08-06 14:46:38,976 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/f8344476-cab3-45eb-8d9a-494de74ccff3 2025-08-06 14:46:42,191 - 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 14:46:42,191 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn-vm-84913602 failed! 2025-08-06 14:46:42,205 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-fvn-90891631 is 33.228.30.193 and allocation pool is NOT set 2025-08-06 14:46:44,270 - 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=12.5 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.57 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.567/8.053/12.540/4.486 ms') 2025-08-06 14:46:44,271 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn-vm-84913602 passed 2025-08-06 14:46:44,383 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:46:44,383 - DEBUG - Waiting to SSH to VM ctest-fvn-vm-84913602, IP 33.228.30.195, Port 22 2025-08-06 14:46:44,449 - DEBUG - Error on ssh to cirros@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 14:46:44,528 - DEBUG - VM ctest-fvn-vm-84913602 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:46:49,529 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:46:49,529 - DEBUG - Waiting to SSH to VM ctest-fvn-vm-84913602, IP 33.228.30.195, Port 22 2025-08-06 14:46:49,687 - DEBUG - VM ctest-fvn-vm-84913602 is ready for SSH connections 2025-08-06 14:46:49,854 - INFO - Creating Floating IP pool some-pool1 in API Server 2025-08-06 14:46:50,015 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 14:46:50,310 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 14:46:50,339 - DEBUG - Requesting: http://10.0.0.254:8082/domain/024378da-7408-4369-ac73-51fa8d4d8d77 2025-08-06 14:46:50,355 - DEBUG - Requesting: http://10.0.0.254:8082/project/4a9ca969-9979-49e2-bcb6-d91e71309268 2025-08-06 14:46:50,450 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/00aa5816-446c-4f93-8f97-0a3f650d2ca3 2025-08-06 14:46:50,464 - DEBUG - Requesting: http://10.0.0.254:8082/floating-ip-pool/0bf33a0d-42d4-419b-91df-62945fbeb0a9 2025-08-06 14:46:50,471 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-08-06 14:46:50,477 - DEBUG - Requesting: http://10.0.0.254:8082/domain/024378da-7408-4369-ac73-51fa8d4d8d77 2025-08-06 14:46:50,489 - DEBUG - Requesting: http://10.0.0.254:8082/project/4a9ca969-9979-49e2-bcb6-d91e71309268 2025-08-06 14:46:50,587 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/00aa5816-446c-4f93-8f97-0a3f650d2ca3 2025-08-06 14:46:50,600 - DEBUG - FIP Pool some-pool1 found in API Server 2025-08-06 14:46:50,600 - INFO - Verification for FIP pool some-pool1 in API Server passed 2025-08-06 14:46:50,615 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information 2025-08-06 14:46:50,621 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information 2025-08-06 14:46:50,627 - DEBUG - Control-node Ifmap-view has FIP pool some-pool1 information 2025-08-06 14:46:50,627 - INFO - Verification for FIP pool some-pool1 in Control-node passed 2025-08-06 14:46:50,627 - INFO - Creating FIP from some-pool1 2025-08-06 14:46:51,151 - DEBUG - Response for create_network : {'network': {'id': '54180904-73bf-4aa4-b8d9-f5c82aa0535a', 'name': 'ctest-vn1-65408116', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'project_id': '4a9ca969997949e2bcb6d91e71309268', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-vn1-65408116'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 14:46:51,406 - DEBUG - Response for create_subnet : {'subnet': {'id': '102f05b8-728e-4ca6-812b-291fdf253578', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '54180904-73bf-4aa4-b8d9-f5c82aa0535a', 'ip_version': 4, 'cidr': '197.93.226.64/26', 'allocation_pools': [{'start': '197.93.226.66', 'end': '197.93.226.126'}], 'gateway_ip': '197.93.226.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '197.93.226.66', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:46:51,430 - INFO - Created VN ctest-vn1-65408116 2025-08-06 14:46:51,442 - DEBUG - VN ctest-vn1-65408116 UUID is 54180904-73bf-4aa4-b8d9-f5c82aa0535a 2025-08-06 14:46:51,793 - DEBUG - Response for create_port : {'port': {'name': '4a798c8d-7df2-457a-a66a-81912e09d8c5', 'id': '4a798c8d-7df2-457a-a66a-81912e09d8c5', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '54180904-73bf-4aa4-b8d9-f5c82aa0535a', 'mac_address': '02:4a:79:8c:8d:7d', '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': '197.93.226.67', 'subnet_id': '102f05b8-728e-4ca6-812b-291fdf253578'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:46:52,041 - DEBUG - Response for create_port : {'port': {'name': 'b5f5b3f8-fe36-4bc3-8a64-bb4159852400', 'id': 'b5f5b3f8-fe36-4bc3-8a64-bb4159852400', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '54180904-73bf-4aa4-b8d9-f5c82aa0535a', 'mac_address': '02:b5:f5:b3:f8:fe', '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': '197.93.226.68', 'subnet_id': '102f05b8-728e-4ca6-812b-291fdf253578'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:46:52,184 - DEBUG - Image by name ubuntu-keepalive not found 2025-08-06 14:46:52,184 - DEBUG - Installing image ubuntu-keepalive 2025-08-06 14:46:52,184 - 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 14:46:52,185 - DEBUG - Image build path http://nexus.opensdn.io/repository///images//ubuntu-keepalive.img.gz 2025-08-06 14:46:52,185 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images//ubuntu-keepalive.img.gz 2025-08-06 14:46:52,196 - 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 14:46:54,159 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-keepalive.img.gz 2025-08-06 14:46:54,159 - DEBUG - Unzip image 2025-08-06 14:46:54,159 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-keepalive.img.gz 2025-08-06 14:47:01,917 - DEBUG - Try to create image in user context 2025-08-06 14:47:06,800 - DEBUG - Image has been created in user context 2025-08-06 14:47:06,800 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-keepalive.img 2025-08-06 14:47:06,911 - DEBUG - Downloaded image has been removed 2025-08-06 14:47:06,925 - DEBUG - Uploaded image status = active 2025-08-06 14:47:07,421 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 14:47:07,970 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 14:47:09,562 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 14:47:09,563 - INFO - Waiting for VM ctest-vm1-43268105 to be up.. 2025-08-06 14:47:09,675 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-06 14:47:14,797 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-06 14:47:19,888 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-06 14:47:24,974 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:47:24,974 - INFO - VM name : ctest-vm1-43268105 2025-08-06 14:47:25,051 - DEBUG - VM ctest-vm1-43268105 ID is ba8ff92d-5d21-43e9-ac25-2bd4e1e96125 2025-08-06 14:47:25,052 - DEBUG - VM ctest-vm1-43268105 launched on Node an-jenkins-deploy-platform-ansible-os-3763-2 2025-08-06 14:47:25,139 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/ba8ff92d-5d21-43e9-ac25-2bd4e1e96125 2025-08-06 14:47:25,152 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/4a798c8d-7df2-457a-a66a-81912e09d8c5 2025-08-06 14:47:28,384 - 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 14:47:28,384 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:28,400 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:32,478 - 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 14:47:32,478 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:32,495 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:36,573 - 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 14:47:36,573 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:36,591 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:40,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 1012ms') 2025-08-06 14:47:40,673 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:40,688 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:44,768 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2025-08-06 14:47:44,768 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:44,788 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:48,862 - 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 14:47:48,862 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:48,877 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:52,953 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-06 14:47:52,953 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:52,967 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:47:57,052 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2025-08-06 14:47:57,052 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:47:57,068 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:01,148 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-06 14:48:01,148 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:01,164 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:05,242 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-06 14:48:05,242 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:05,257 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:09,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 1021ms') 2025-08-06 14:48:09,344 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:09,367 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:13,433 - 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 1003ms') 2025-08-06 14:48:13,433 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:13,449 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:17,532 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-06 14:48:17,532 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:17,548 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:21,635 - 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 14:48:21,635 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 failed! 2025-08-06 14:48:21,652 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-65408116 is 197.93.226.65 and allocation pool is NOT set 2025-08-06 14:48:25,726 - 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=2 ttl=63 time=9.21 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1007ms\r\nrtt min/avg/max/mdev = 9.208/9.208/9.208/0.000 ms') 2025-08-06 14:48:25,726 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-43268105 passed 2025-08-06 14:48:25,840 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:25,840 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:25,906 - 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 14:48:26,005 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:31,005 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:31,005 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:31,073 - 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 14:48:31,162 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:36,164 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:36,164 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:36,230 - 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 14:48:36,312 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:41,312 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:41,313 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:41,382 - 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 14:48:41,470 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:46,471 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:46,471 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:46,538 - 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 14:48:46,665 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:51,665 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:51,666 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:51,734 - 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 14:48:51,814 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:48:56,815 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:48:56,815 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:48:56,882 - 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 14:48:56,970 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:01,971 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:01,972 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:02,038 - 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 14:49:02,120 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:07,121 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:07,121 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:07,190 - 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 14:49:07,274 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:12,275 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:12,275 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:12,341 - 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 14:49:12,427 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:17,427 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:17,428 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:17,494 - 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 14:49:17,579 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:22,580 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:22,580 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:22,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 14:49:22,747 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:27,748 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:27,748 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:27,814 - 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 14:49:27,898 - DEBUG - VM ctest-vm1-43268105 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:49:32,899 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:32,899 - DEBUG - Waiting to SSH to VM ctest-vm1-43268105, IP 197.93.226.67, Port 22 2025-08-06 14:49:33,069 - DEBUG - VM ctest-vm1-43268105 is ready for SSH connections 2025-08-06 14:49:33,069 - INFO - Waiting for VM ctest-vm2-79336560 to be up.. 2025-08-06 14:49:33,157 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:49:33,157 - INFO - VM name : ctest-vm2-79336560 2025-08-06 14:49:33,254 - DEBUG - VM ctest-vm2-79336560 ID is 538b256e-bac0-4331-a992-bf72c282c2b3 2025-08-06 14:49:33,254 - DEBUG - VM ctest-vm2-79336560 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 14:49:33,339 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/538b256e-bac0-4331-a992-bf72c282c2b3 2025-08-06 14:49:33,351 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/b5f5b3f8-fe36-4bc3-8a64-bb4159852400 2025-08-06 14:49:34,575 - 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.86 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.564 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.564/2.211/3.858/1.647 ms') 2025-08-06 14:49:34,575 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vm2-79336560 passed 2025-08-06 14:49:34,688 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:49:34,688 - DEBUG - Waiting to SSH to VM ctest-vm2-79336560, IP 197.93.226.68, Port 22 2025-08-06 14:49:34,857 - DEBUG - VM ctest-vm2-79336560 is ready for SSH connections 2025-08-06 14:49:34,857 - INFO - Waiting for VM ctest-vm_test-63005531 to be up.. 2025-08-06 14:49:34,923 - DEBUG - VM is in ERROR state now 2025-08-06 14:49:34,923 - ERROR - VM in error state. 2025-08-06 14:49:34,923 - ERROR - VM is not in ACTIVE state 2025-08-06 14:49:35,030 - ERROR - Fatal Nova Exception while getting VM detail 2025-08-06 14:49:35,030 - DEBUG - None 2025-08-06 14:49:35,032 - INFO - Skip interface_detach for VM ctest-vm_test-63005531 in state ERROR 2025-08-06 14:49:35,033 - INFO - Deleting VM ctest-vm_test-63005531 2025-08-06 14:49:35,033 - ERROR - VM ctest-vm_test-63005531 has failed to come up 2025-08-06 14:49:35,033 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-08-06T14:47:09Z', '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 14:49:35,036 - INFO - Detaching port b5f5b3f8-fe36-4bc3-8a64-bb4159852400 from VM ctest-vm2-79336560 2025-08-06 14:49:35,092 - INFO - Deleting VM ctest-vm2-79336560 2025-08-06 14:49:35,178 - INFO - Detaching port 4a798c8d-7df2-457a-a66a-81912e09d8c5 from VM ctest-vm1-43268105 2025-08-06 14:49:35,210 - INFO - Deleting VM ctest-vm1-43268105 2025-08-06 14:49:35,555 - DEBUG - Response for delete_port : () 2025-08-06 14:49:35,826 - DEBUG - Response for delete_port : () 2025-08-06 14:49:35,826 - INFO - Deleting VN ctest-vn1-65408116 2025-08-06 14:49:36,064 - DEBUG - Response for deleting network () 2025-08-06 14:49:36,117 - INFO - Deleting the FIP pool some-pool1 2025-08-06 14:49:36,280 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information 2025-08-06 14:49:36,286 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information 2025-08-06 14:49:36,295 - DEBUG - Control-node Ifmap-view does not have FIP pool some-pool1 information 2025-08-06 14:49:36,295 - INFO - Deleting VM ctest-fvn-vm-84913602 2025-08-06 14:49:36,366 - INFO - Deleting VN ctest-fvn-90891631 2025-08-06 14:49:36,409 - DEBUG - VN 00aa5816-446c-4f93-8f97-0a3f650d2ca3 still in use: Unable to complete operation on network 00aa5816-446c-4f93-8f97-0a3f650d2ca3. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-dc9e062b-e51e-4362-b61f-e1a228eabca9'] 2025-08-06 14:49:36,409 - WARNING - Deleting VN ctest-fvn-90891631 failed..Will retry 2025-08-06 14:49:38,602 - DEBUG - Response for deleting network () 2025-08-06 14:49:39,893 - ERROR - AssertionError Python 3.6.8: /usr/bin/python3 Wed Aug 6 14:49:35 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 14:49:39,909 - DEBUG - No XMPP flaps were noticed during the test 2025-08-06 14:49:39,909 - INFO -
2025-08-06 14:49:39,910 - INFO - END TEST : test_aap_with_fip : FAILED[0:03:10]
2025-08-06 14:49:39,910 - INFO - -------------------------------------------------------------------------------- 2025-08-06 14:49:39,915 - INFO - ================================================================================ 2025-08-06 14:49:39,915 - INFO - STARTING TEST : test_aap_with_zero_mac 2025-08-06 14:49:39,915 - 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 14:49:41,206 - 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.25': '0', '10.20.0.14': '0'}} with 2025-08-06 14:49:41,206 - INFO - Initial checks done. Running the testcase now 2025-08-06 14:49:41,206 - INFO - 2025-08-06 14:49:41,507 - DEBUG - Response for create_network : {'network': {'id': 'cd30e03d-47e8-406f-af94-28a1328deef5', 'name': 'ctest-vn1-57833593', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'project_id': '4a9ca969997949e2bcb6d91e71309268', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-vn1-57833593'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 14:49:41,779 - DEBUG - Response for create_subnet : {'subnet': {'id': 'def62b51-3954-4cfb-bb3c-064c8c222087', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'cd30e03d-47e8-406f-af94-28a1328deef5', 'ip_version': 4, 'cidr': '223.238.21.0/26', 'allocation_pools': [{'start': '223.238.21.2', 'end': '223.238.21.62'}], 'gateway_ip': '223.238.21.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '223.238.21.2', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:49:41,802 - INFO - Created VN ctest-vn1-57833593 2025-08-06 14:49:41,816 - DEBUG - VN ctest-vn1-57833593 UUID is cd30e03d-47e8-406f-af94-28a1328deef5 2025-08-06 14:49:42,175 - DEBUG - Response for create_port : {'port': {'name': '7e414308-c7b2-4ba3-8bf6-e9ee33ceacc1', 'id': '7e414308-c7b2-4ba3-8bf6-e9ee33ceacc1', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'cd30e03d-47e8-406f-af94-28a1328deef5', 'mac_address': '02:7e:41:43:08:c7', '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': '223.238.21.3', 'subnet_id': 'def62b51-3954-4cfb-bb3c-064c8c222087'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:49:42,442 - DEBUG - Response for create_port : {'port': {'name': '5f167683-7efb-47e5-84e5-c75c3c2c7293', 'id': '5f167683-7efb-47e5-84e5-c75c3c2c7293', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'cd30e03d-47e8-406f-af94-28a1328deef5', 'mac_address': '02:5f:16:76:83:7e', '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': '223.238.21.4', 'subnet_id': 'def62b51-3954-4cfb-bb3c-064c8c222087'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:49:43,008 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 14:49:43,586 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 14:49:45,249 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 14:49:45,249 - INFO - Waiting for VM ctest-vm1-81169847 to be up.. 2025-08-06 14:49:45,359 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:49:45,360 - INFO - VM name : ctest-vm1-81169847 2025-08-06 14:49:45,439 - DEBUG - VM ctest-vm1-81169847 ID is aabf98c7-5a58-49c1-8431-2459fa143b7a 2025-08-06 14:49:45,439 - DEBUG - VM ctest-vm1-81169847 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 14:49:45,533 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/aabf98c7-5a58-49c1-8431-2459fa143b7a 2025-08-06 14:49:45,649 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/7e414308-c7b2-4ba3-8bf6-e9ee33ceacc1 2025-08-06 14:49:48,886 - 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 14:49:48,886 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:49:48,906 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:49:52,972 - 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 14:49:52,972 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:49:52,989 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:49:57,065 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-08-06 14:49:57,066 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:49:57,082 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:01,163 - 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 1013ms') 2025-08-06 14:50:01,163 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:01,180 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:05,259 - 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 14:50:05,259 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:05,275 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:09,362 - 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 1026ms') 2025-08-06 14:50:09,362 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:09,379 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:13,458 - 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 14:50:13,458 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:13,474 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:17,552 - 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 14:50:17,552 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:17,570 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:21,646 - 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 1013ms') 2025-08-06 14:50:21,646 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:21,663 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:25,745 - 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 1013ms') 2025-08-06 14:50:25,745 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:25,763 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:29,836 - 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 14:50:29,836 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:29,852 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:33,939 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms') 2025-08-06 14:50:33,939 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:33,956 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:38,032 - 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 14:50:38,032 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:38,048 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:42,124 - 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 14:50:42,124 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 failed! 2025-08-06 14:50:42,141 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-57833593 is 223.238.21.1 and allocation pool is NOT set 2025-08-06 14:50:44,212 - 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=9.13 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.30 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 = 2.304/5.716/9.129/3.412 ms') 2025-08-06 14:50:44,213 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm1-81169847 passed 2025-08-06 14:50:44,331 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:50:44,331 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:50:44,400 - 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 14:50:44,482 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:50:49,483 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:50:49,483 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:50:49,549 - 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 14:50:49,647 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:50:54,648 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:50:54,648 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:50:54,713 - 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 14:50:54,797 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:50:59,798 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:50:59,798 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:50:59,865 - 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 14:50:59,941 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:04,942 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:04,942 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:04,999 - 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 14:51:05,082 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:10,083 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:10,083 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:10,149 - 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 14:51:10,228 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:15,229 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:15,229 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:15,298 - 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 14:51:15,387 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:20,388 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:20,388 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:20,453 - 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 14:51:20,535 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:25,536 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:25,536 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:25,601 - 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 14:51:25,688 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:30,688 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:30,689 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:30,758 - 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 14:51:30,864 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:35,865 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:35,865 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:35,923 - 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 14:51:36,051 - DEBUG - VM ctest-vm1-81169847 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:41,052 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:41,052 - DEBUG - Waiting to SSH to VM ctest-vm1-81169847, IP 223.238.21.3, Port 22 2025-08-06 14:51:41,221 - DEBUG - VM ctest-vm1-81169847 is ready for SSH connections 2025-08-06 14:51:41,221 - INFO - Waiting for VM ctest-vm2-67922859 to be up.. 2025-08-06 14:51:41,330 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:51:41,330 - INFO - VM name : ctest-vm2-67922859 2025-08-06 14:51:41,419 - DEBUG - VM ctest-vm2-67922859 ID is 4ed8b2e4-6810-4fb2-ae69-2f2247f791c7 2025-08-06 14:51:41,420 - DEBUG - VM ctest-vm2-67922859 launched on Node an-jenkins-deploy-platform-ansible-os-3763-2 2025-08-06 14:51:41,498 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/4ed8b2e4-6810-4fb2-ae69-2f2247f791c7 2025-08-06 14:51:41,529 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/5f167683-7efb-47e5-84e5-c75c3c2c7293 2025-08-06 14:51:42,764 - 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.28 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.58 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.583/2.929/4.275/1.346 ms') 2025-08-06 14:51:42,764 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vm2-67922859 passed 2025-08-06 14:51:42,881 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:42,881 - DEBUG - Waiting to SSH to VM ctest-vm2-67922859, IP 223.238.21.4, Port 22 2025-08-06 14:51:42,950 - 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 14:51:43,030 - DEBUG - VM ctest-vm2-67922859 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:48,030 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:48,030 - DEBUG - Waiting to SSH to VM ctest-vm2-67922859, IP 223.238.21.4, Port 22 2025-08-06 14:51:48,098 - 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 14:51:48,184 - DEBUG - VM ctest-vm2-67922859 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:53,185 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:53,185 - DEBUG - Waiting to SSH to VM ctest-vm2-67922859, IP 223.238.21.4, Port 22 2025-08-06 14:51:53,253 - 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 14:51:53,343 - DEBUG - VM ctest-vm2-67922859 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:51:58,344 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:51:58,344 - DEBUG - Waiting to SSH to VM ctest-vm2-67922859, IP 223.238.21.4, Port 22 2025-08-06 14:51:58,513 - DEBUG - VM ctest-vm2-67922859 is ready for SSH connections 2025-08-06 14:51:58,514 - INFO - Waiting for VM ctest-vm_test-40012073 to be up.. 2025-08-06 14:51:58,576 - DEBUG - VM is in ERROR state now 2025-08-06 14:51:58,576 - ERROR - VM in error state. 2025-08-06 14:51:58,577 - ERROR - VM is not in ACTIVE state 2025-08-06 14:51:58,658 - ERROR - Fatal Nova Exception while getting VM detail 2025-08-06 14:51:58,659 - DEBUG - None 2025-08-06 14:51:58,659 - INFO - Skip interface_detach for VM ctest-vm_test-40012073 in state ERROR 2025-08-06 14:51:58,660 - INFO - Deleting VM ctest-vm_test-40012073 2025-08-06 14:51:58,660 - ERROR - VM ctest-vm_test-40012073 has failed to come up 2025-08-06 14:51:58,660 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-08-06T14:49:45Z', '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 14:51:58,660 - INFO - Detaching port 5f167683-7efb-47e5-84e5-c75c3c2c7293 from VM ctest-vm2-67922859 2025-08-06 14:51:58,696 - INFO - Deleting VM ctest-vm2-67922859 2025-08-06 14:51:58,769 - INFO - Detaching port 7e414308-c7b2-4ba3-8bf6-e9ee33ceacc1 from VM ctest-vm1-81169847 2025-08-06 14:51:58,798 - INFO - Deleting VM ctest-vm1-81169847 2025-08-06 14:51:59,113 - DEBUG - Response for delete_port : () 2025-08-06 14:51:59,364 - DEBUG - Response for delete_port : () 2025-08-06 14:51:59,364 - INFO - Deleting VN ctest-vn1-57833593 2025-08-06 14:51:59,545 - DEBUG - Response for deleting network () 2025-08-06 14:52:00,836 - ERROR - AssertionError Python 3.6.8: /usr/bin/python3 Wed Aug 6 14:51:58 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=) 1160 assert vm2_fixture.wait_till_vm_is_up(), 'VM does not seem to be up' 1161 assert vm_test_fixture.wait_till_vm_is_up( 1162 ), 'VM does not seem to be up' 1163 for port in port_list: 1164 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 1162, in test_aap_with_zero_mac ), 'VM does not seem to be up' AssertionError: VM does not seem to be up 2025-08-06 14:52:00,854 - DEBUG - No XMPP flaps were noticed during the test 2025-08-06 14:52:00,854 - INFO -
2025-08-06 14:52:00,854 - INFO - END TEST : test_aap_with_zero_mac : FAILED[0:02:21]
2025-08-06 14:52:00,854 - INFO - -------------------------------------------------------------------------------- 2025-08-06 14:52:00,860 - INFO - ================================================================================ 2025-08-06 14:52:00,861 - INFO - STARTING TEST : test_ports_bindings 2025-08-06 14:52:00,861 - 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 14:52:02,164 - 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.25': '0', '10.20.0.14': '0'}} with 2025-08-06 14:52:02,164 - INFO - Initial checks done. Running the testcase now 2025-08-06 14:52:02,164 - INFO - 2025-08-06 14:52:02,481 - DEBUG - Response for create_network : {'network': {'id': '42d52e20-3a3a-4dbb-ba77-fd335a942add', 'name': 'ctest-vn-85762461', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'project_id': '4a9ca969997949e2bcb6d91e71309268', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-vn-85762461'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 14:52:02,722 - DEBUG - Response for create_subnet : {'subnet': {'id': '0e592fc0-ba19-4f9f-badd-ce4c803f8a5b', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '42d52e20-3a3a-4dbb-ba77-fd335a942add', 'ip_version': 4, 'cidr': '152.18.222.192/26', 'allocation_pools': [{'start': '152.18.222.194', 'end': '152.18.222.254'}], 'gateway_ip': '152.18.222.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '152.18.222.194', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:02,748 - INFO - Created VN ctest-vn-85762461 2025-08-06 14:52:02,764 - DEBUG - VN ctest-vn-85762461 UUID is 42d52e20-3a3a-4dbb-ba77-fd335a942add 2025-08-06 14:52:02,843 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-vmi-69307661']} 2025-08-06 14:52:03,160 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-69307661', 'id': 'b4e56d5d-2444-4048-8976-a0dfc44a2c4c', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': '42d52e20-3a3a-4dbb-ba77-fd335a942add', 'mac_address': '02:b4:e5:6d:5d:24', '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': '152.18.222.195', 'subnet_id': '0e592fc0-ba19-4f9f-badd-ce4c803f8a5b'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:03,160 - DEBUG - Created port b4e56d5d-2444-4048-8976-a0dfc44a2c4c 2025-08-06 14:52:03,230 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/b4e56d5d-2444-4048-8976-a0dfc44a2c4c 2025-08-06 14:52:03,266 - INFO - VMI b4e56d5d-2444-4048-8976-a0dfc44a2c4c verification in API Server passed 2025-08-06 14:52:03,416 - DEBUG - Response for delete_port : () 2025-08-06 14:52:03,416 - INFO - Deleted port b4e56d5d-2444-4048-8976-a0dfc44a2c4c 2025-08-06 14:52:03,416 - INFO - Deleting VN ctest-vn-85762461 2025-08-06 14:52:03,574 - DEBUG - Response for deleting network () 2025-08-06 14:52:04,910 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 14:52:04,911 - INFO - END TEST : test_ports_bindings : PASSED[0:00:04]
2025-08-06 14:52:04,911 - INFO - -------------------------------------------------------------------------------- 2025-08-06 14:52:04,917 - INFO - ================================================================================ 2025-08-06 14:52:04,917 - INFO - STARTING TEST : test_ports_specific_subnet_ip 2025-08-06 14:52:04,917 - 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 14:52:06,224 - 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.25': '0', '10.20.0.14': '0'}} with 2025-08-06 14:52:06,224 - INFO - Initial checks done. Running the testcase now 2025-08-06 14:52:06,224 - INFO - 2025-08-06 14:52:06,474 - DEBUG - Response for create_network : {'network': {'id': 'd175f871-b5d1-4f0d-95c0-fa4a0af40d8c', 'name': 'ctest-vn1-87681459', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'project_id': '4a9ca969997949e2bcb6d91e71309268', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-40542843', 'ctest-vn1-87681459'], 'port_security_enabled': True, 'description': ''}} 2025-08-06 14:52:06,680 - DEBUG - Response for create_subnet : {'subnet': {'id': '94be5b3e-654c-40cb-af4b-a1c13b04f51c', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'd175f871-b5d1-4f0d-95c0-fa4a0af40d8c', 'ip_version': 4, 'cidr': '57.117.197.128/26', 'allocation_pools': [{'start': '57.117.197.130', 'end': '57.117.197.190'}], 'gateway_ip': '57.117.197.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '57.117.197.130', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:06,951 - DEBUG - Response for create_subnet : {'subnet': {'id': '06f1c655-ef74-4306-8c83-c31dca218d0a', 'name': '', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'd175f871-b5d1-4f0d-95c0-fa4a0af40d8c', 'ip_version': 4, 'cidr': '148.57.201.192/26', 'allocation_pools': [{'start': '148.57.201.194', 'end': '148.57.201.254'}], 'gateway_ip': '148.57.201.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '148.57.201.194', 'tags': [], 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:06,981 - INFO - Created VN ctest-vn1-87681459 2025-08-06 14:52:06,996 - DEBUG - VN ctest-vn1-87681459 UUID is d175f871-b5d1-4f0d-95c0-fa4a0af40d8c 2025-08-06 14:52:07,368 - DEBUG - Response for create_port : {'port': {'name': '999c863e-19c6-4c48-a2a7-a3ab50df6510', 'id': '999c863e-19c6-4c48-a2a7-a3ab50df6510', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'd175f871-b5d1-4f0d-95c0-fa4a0af40d8c', 'mac_address': '02:99:9c:86:3e: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': '57.117.197.133', 'subnet_id': '94be5b3e-654c-40cb-af4b-a1c13b04f51c'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:07,610 - DEBUG - Response for create_port : {'port': {'name': 'd742b5c7-3597-443c-9a46-15d5d062d335', 'id': 'd742b5c7-3597-443c-9a46-15d5d062d335', 'tenant_id': '4a9ca969997949e2bcb6d91e71309268', 'network_id': 'd175f871-b5d1-4f0d-95c0-fa4a0af40d8c', 'mac_address': '02:d7:42:b5:c7:35', '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': '148.57.201.197', 'subnet_id': '06f1c655-ef74-4306-8c83-c31dca218d0a'}], 'security_groups': ['ad099ec1-9599-42c3-b09f-89f4100e89ce'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '4a9ca969997949e2bcb6d91e71309268'}} 2025-08-06 14:52:08,107 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-2) 2025-08-06 14:52:08,688 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3763-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3763-1) 2025-08-06 14:52:08,688 - INFO - Waiting for VM ctest-vn1-vm1-42659942 to be up.. 2025-08-06 14:52:08,771 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-06 14:52:13,855 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:52:13,855 - INFO - VM name : ctest-vn1-vm1-42659942 2025-08-06 14:52:13,952 - DEBUG - VM ctest-vn1-vm1-42659942 ID is b340ff1b-b6f5-478b-9d3b-a503ee36b402 2025-08-06 14:52:13,952 - DEBUG - VM ctest-vn1-vm1-42659942 launched on Node an-jenkins-deploy-platform-ansible-os-3763-2 2025-08-06 14:52:14,031 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/b340ff1b-b6f5-478b-9d3b-a503ee36b402 2025-08-06 14:52:14,041 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/999c863e-19c6-4c48-a2a7-a3ab50df6510 2025-08-06 14:52:17,276 - 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 14:52:17,276 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-42659942 failed! 2025-08-06 14:52:17,292 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-87681459 is 57.117.197.129 and allocation pool is NOT set 2025-08-06 14:52:17,292 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-87681459 is 148.57.201.193 and allocation pool is NOT set 2025-08-06 14:52:21,372 - 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 1007ms') 2025-08-06 14:52:21,372 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-42659942 failed! 2025-08-06 14:52:21,392 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-87681459 is 57.117.197.129 and allocation pool is NOT set 2025-08-06 14:52:21,392 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-40542843:ctest-vn1-87681459 is 148.57.201.193 and allocation pool is NOT set 2025-08-06 14:52:23,467 - 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=14.7 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.15 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 = 2.149/8.429/14.710/6.280 ms') 2025-08-06 14:52:23,468 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-42659942 passed 2025-08-06 14:52:23,580 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:23,580 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-42659942, IP 57.117.197.133, Port 22 2025-08-06 14:52:23,649 - DEBUG - Error on ssh to cirros@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 14:52:23,735 - DEBUG - VM ctest-vn1-vm1-42659942 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:52:28,735 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:28,735 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-42659942, IP 57.117.197.133, Port 22 2025-08-06 14:52:28,801 - DEBUG - Error on ssh to cirros@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 14:52:28,883 - DEBUG - VM ctest-vn1-vm1-42659942 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-06 14:52:33,884 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:33,884 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-42659942, IP 57.117.197.133, Port 22 2025-08-06 14:52:34,053 - DEBUG - VM ctest-vn1-vm1-42659942 is ready for SSH connections 2025-08-06 14:52:34,054 - INFO - Waiting for VM ctest-vn1-vm2-82578612 to be up.. 2025-08-06 14:52:34,138 - DEBUG - VM is in ACTIVE state now 2025-08-06 14:52:34,138 - INFO - VM name : ctest-vn1-vm2-82578612 2025-08-06 14:52:34,222 - DEBUG - VM ctest-vn1-vm2-82578612 ID is 12eeb104-ff26-495e-b6ee-faa38294d09e 2025-08-06 14:52:34,222 - DEBUG - VM ctest-vn1-vm2-82578612 launched on Node an-jenkins-deploy-platform-ansible-os-3763-1 2025-08-06 14:52:34,304 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine/12eeb104-ff26-495e-b6ee-faa38294d09e 2025-08-06 14:52:34,315 - DEBUG - Requesting: http://10.0.0.48:8082/virtual-machine-interface/d742b5c7-3597-443c-9a46-15d5d062d335 2025-08-06 14:52:35,525 - 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.60 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.312 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.312/1.956/3.600/1.644 ms') 2025-08-06 14:52:35,526 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm2-82578612 passed 2025-08-06 14:52:35,643 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:35,643 - DEBUG - Waiting to SSH to VM ctest-vn1-vm2-82578612, IP 148.57.201.197, Port 22 2025-08-06 14:52:35,803 - DEBUG - VM ctest-vn1-vm2-82578612 is ready for SSH connections 2025-08-06 14:52:35,803 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:35,803 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:35,803 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-06 14:52:35,803 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 57.117.197.133, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-08-06 14:52:35,803 - DEBUG - ping -s 56 -c 3 -W 1 57.117.197.133 2025-08-06 14:52:38,782 - DEBUG - PING 57.117.197.133 (57.117.197.133): 56 data bytes 64 bytes from 57.117.197.133: seq=0 ttl=63 time=6.942 ms 64 bytes from 57.117.197.133: seq=1 ttl=63 time=1.524 ms 64 bytes from 57.117.197.133: seq=2 ttl=63 time=1.409 ms --- 57.117.197.133 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.409/3.291/6.942 ms 2025-08-06 14:52:38,782 - INFO - Ping to IP 57.117.197.133 from VM ctest-vn1-vm2-82578612 passed 2025-08-06 14:52:38,783 - INFO - Detaching port d742b5c7-3597-443c-9a46-15d5d062d335 from VM ctest-vn1-vm2-82578612 2025-08-06 14:52:38,814 - INFO - Deleting VM ctest-vn1-vm2-82578612 2025-08-06 14:52:38,887 - INFO - Detaching port 999c863e-19c6-4c48-a2a7-a3ab50df6510 from VM ctest-vn1-vm1-42659942 2025-08-06 14:52:38,934 - INFO - Deleting VM ctest-vn1-vm1-42659942 2025-08-06 14:52:39,257 - DEBUG - Response for delete_port : () 2025-08-06 14:52:39,496 - DEBUG - Response for delete_port : () 2025-08-06 14:52:39,496 - INFO - Deleting VN ctest-vn1-87681459 2025-08-06 14:52:39,699 - DEBUG - Response for deleting network () 2025-08-06 14:52:41,013 - DEBUG - No XMPP flaps were noticed during the test
2025-08-06 14:52:41,013 - INFO - END TEST : test_ports_specific_subnet_ip : PASSED[0:00:37]
2025-08-06 14:52:41,013 - INFO - -------------------------------------------------------------------------------- 2025-08-06 14:52:41,774 - INFO - Deleted project: ctest-TestPorts-40542843, ID : 4a9ca969-9979-49e2-bcb6-d91e71309268