2025-10-02 01:59:16,929 - INFO - Domain Default found not creating
2025-10-02 01:59:17,084 - INFO - Project ctest-FloatingipBasicTestSanity-90634719 not found, creating it
2025-10-02 01:59:17,685 - INFO - Created Project:ctest-FloatingipBasicTestSanity-90634719, ID : 5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:19,171 - INFO - ================================================================================
2025-10-02 01:59:19,172 - INFO - STARTING TEST : test_floating_ip
2025-10-02 01:59:19,172 - INFO - TEST DESCRIPTION : Test to validate floating-ip Assignment to a VM. It creates a VM, assigns a FIP to it and pings to a IP in the FIP VN.
2025-10-02 01:59:19,811 - DEBUG - Nothing to compare xmpp stats {'10.0.0.33': {'10.20.0.25': '0', '10.20.0.14': '0'}, '10.0.0.130': {'10.20.0.254': '0', '10.20.0.14': '0'}} with
2025-10-02 01:59:19,811 - INFO - Initial checks done. Running the testcase now
2025-10-02 01:59:19,812 - INFO -
2025-10-02 01:59:19,832 - DEBUG - Services list from nova: [, , , ]
2025-10-02 01:59:19,832 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4210-2', 'an-jenkins-deploy-platform-ansible-os-4210-1']}
2025-10-02 01:59:20,478 - DEBUG - Response for create_network : {'network': {'id': 'f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a', 'name': 'ctest-fvn-93214152', 'tenant_id': '5055f68715f446f49cdde17d31c0a69e', 'project_id': '5055f68715f446f49cdde17d31c0a69e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-90634719', 'ctest-fvn-93214152'], 'port_security_enabled': True, 'description': ''}}
2025-10-02 01:59:20,718 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b9b06516-997b-4ead-95ea-51a680189488', 'name': '', 'tenant_id': '5055f68715f446f49cdde17d31c0a69e', 'network_id': 'f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a', 'ip_version': 4, 'cidr': '113.10.81.192/26', 'allocation_pools': [{'start': '113.10.81.194', 'end': '113.10.81.254'}], 'gateway_ip': '113.10.81.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '113.10.81.194', 'tags': [], 'project_id': '5055f68715f446f49cdde17d31c0a69e'}}
2025-10-02 01:59:20,740 - INFO - Created VN ctest-fvn-93214152
2025-10-02 01:59:20,753 - DEBUG - VN ctest-fvn-93214152 UUID is f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:20,814 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:21,104 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:21,131 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:21,146 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:21,261 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,271 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,280 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 01:59:21,288 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 01:59:21,297 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/e5aea047-1a8c-418d-bef0-ad3aae299607
2025-10-02 01:59:21,304 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-02 01:59:21,304 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,313 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 01:59:21,328 - INFO - Verified VN network id 9 for VN f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,328 - INFO - Verifications in API Server for VN ctest-fvn-93214152 passed
2025-10-02 01:59:21,328 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,340 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 01:59:21,347 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 01:59:21,353 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/e5aea047-1a8c-418d-bef0-ad3aae299607
2025-10-02 01:59:21,366 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17508718557003730878', 'uuid-lslong': '13333974364165604186'}, 'enable': 'true', 'created': '2025-10-02T01:59:20', 'last-modified': '2025-10-02T01:59:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.703052'}
2025-10-02 01:59:21,372 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-02 01:59:21,377 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17508718557003730878', 'uuid-lslong': '13333974364165604186'}, 'enable': 'true', 'created': '2025-10-02T01:59:20', 'last-modified': '2025-10-02T01:59:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.717001'}
2025-10-02 01:59:21,385 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-02 01:59:21,390 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17508718557003730878', 'uuid-lslong': '13333974364165604186'}, 'enable': 'true', 'created': '2025-10-02T01:59:20', 'last-modified': '2025-10-02T01:59:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.726279'}
2025-10-02 01:59:21,397 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-02 01:59:21,397 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-fvn-93214152 passed
2025-10-02 01:59:21,397 - DEBUG - ====Verifying policy data for ctest-fvn-93214152 in API_Server ======
2025-10-02 01:59:21,397 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:21,404 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:21,414 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:21,505 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:21,514 - DEBUG - =>VN ctest-fvn-93214152 has no policy to be verified
2025-10-02 01:59:21,514 - DEBUG - Verifying the vn in opserver
2025-10-02 01:59:21,514 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152 virtual network link through opserver 10.0.0.56
2025-10-02 01:59:21,514 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-02 01:59:21,806 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-02 01:59:21,859 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152?flat'}
2025-10-02 01:59:21,859 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152 virtual network link through opserver 10.0.0.38
2025-10-02 01:59:21,859 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-02 01:59:22,149 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-02 01:59:22,200 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152?flat'}
2025-10-02 01:59:22,200 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152 virtual network link through opserver 10.0.0.49
2025-10-02 01:59:22,200 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-10-02 01:59:22,490 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-10-02 01:59:22,541 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152?flat'}
2025-10-02 01:59:22,541 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152 is found in opserver
2025-10-02 01:59:22,558 - DEBUG - Do not have enough data to verify VN in agent
2025-10-02 01:59:22,566 - DEBUG - VRF ids for VN ctest-fvn-93214152: {}
2025-10-02 01:59:22,835 - DEBUG - Response for create_network : {'network': {'id': '4e8f858c-1fe8-44da-9dd5-88499ec5313d', 'name': 'ctest-vn1-86237260', 'tenant_id': '5055f68715f446f49cdde17d31c0a69e', 'project_id': '5055f68715f446f49cdde17d31c0a69e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-90634719', 'ctest-vn1-86237260'], 'port_security_enabled': True, 'description': ''}}
2025-10-02 01:59:23,040 - DEBUG - Response for create_subnet : {'subnet': {'id': '505ee238-c429-4269-9354-78e704b1d4a0', 'name': '', 'tenant_id': '5055f68715f446f49cdde17d31c0a69e', 'network_id': '4e8f858c-1fe8-44da-9dd5-88499ec5313d', 'ip_version': 4, 'cidr': '81.141.43.0/26', 'allocation_pools': [{'start': '81.141.43.2', 'end': '81.141.43.62'}], 'gateway_ip': '81.141.43.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '81.141.43.2', 'tags': [], 'project_id': '5055f68715f446f49cdde17d31c0a69e'}}
2025-10-02 01:59:23,062 - INFO - Created VN ctest-vn1-86237260
2025-10-02 01:59:23,072 - DEBUG - VN ctest-vn1-86237260 UUID is 4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,144 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:23,151 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:23,165 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:23,264 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,278 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,287 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 01:59:23,301 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 01:59:23,309 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/e3c09112-a3b7-4cb6-ad49-c3ec13b5a223
2025-10-02 01:59:23,315 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-02 01:59:23,315 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,323 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 01:59:23,338 - INFO - Verified VN network id 10 for VN 4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,338 - INFO - Verifications in API Server for VN ctest-vn1-86237260 passed
2025-10-02 01:59:23,338 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,347 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 01:59:23,353 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 01:59:23,358 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/e3c09112-a3b7-4cb6-ad49-c3ec13b5a223
2025-10-02 01:59:23,370 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5660890093505234138', 'uuid-lslong': '11373146283771769149'}, 'enable': 'true', 'created': '2025-10-02T01:59:22', 'last-modified': '2025-10-02T01:59:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.388602'}
2025-10-02 01:59:23,375 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-02 01:59:23,379 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5660890093505234138', 'uuid-lslong': '11373146283771769149'}, 'enable': 'true', 'created': '2025-10-02T01:59:22', 'last-modified': '2025-10-02T01:59:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.389539'}
2025-10-02 01:59:23,385 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-02 01:59:23,390 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-90634719', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5660890093505234138', 'uuid-lslong': '11373146283771769149'}, 'enable': 'true', 'created': '2025-10-02T01:59:22', 'last-modified': '2025-10-02T01:59:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.410201'}
2025-10-02 01:59:23,396 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-02 01:59:23,396 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-86237260 passed
2025-10-02 01:59:23,396 - DEBUG - ====Verifying policy data for ctest-vn1-86237260 in API_Server ======
2025-10-02 01:59:23,396 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:23,401 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:23,412 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:23,514 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/4e8f858c-1fe8-44da-9dd5-88499ec5313d
2025-10-02 01:59:23,523 - DEBUG - =>VN ctest-vn1-86237260 has no policy to be verified
2025-10-02 01:59:23,523 - DEBUG - Verifying the vn in opserver
2025-10-02 01:59:23,523 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 virtual network link through opserver 10.0.0.56
2025-10-02 01:59:23,523 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-02 01:59:23,581 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260?flat'}
2025-10-02 01:59:23,581 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 virtual network link through opserver 10.0.0.38
2025-10-02 01:59:23,581 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2025-10-02 01:59:23,629 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260?flat'}
2025-10-02 01:59:23,630 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 virtual network link through opserver 10.0.0.49
2025-10-02 01:59:23,630 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-10-02 01:59:23,676 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260?flat'}
2025-10-02 01:59:23,676 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is found in opserver
2025-10-02 01:59:23,698 - DEBUG - Do not have enough data to verify VN in agent
2025-10-02 01:59:23,707 - DEBUG - VRF ids for VN ctest-vn1-86237260: {}
2025-10-02 01:59:23,757 - DEBUG - Image by name ubuntu not found
2025-10-02 01:59:23,757 - DEBUG - Installing image ubuntu
2025-10-02 01:59:23,757 - DEBUG - Image info {'name': 'ubuntu-traffic.vmdk.gz', 'webserver': '', 'location': '/images/converts/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_small', 'params': '--container-format bare --disk-format vmdk --property vmware_disktype="sparse" --property vmware_adaptertype="ide" --property hw_scsi_model=virtio-scsi --property hw_disk_bus_model=virtio-scsi --property hw_disk_bus=virtio', 'name_docker': 'ubuntu-traffic-docker', 'vmdk': 'ubuntu-traffic-disk1.vmdk', 'shrinked_vmdk': "'no'"}
2025-10-02 01:59:23,757 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic.vmdk.gz
2025-10-02 01:59:23,757 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic.vmdk.gz
2025-10-02 01:59:23,769 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: wget -nv http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic.vmdk.gz -O /contrail-test/images/ubuntu-traffic.vmdk.gz
2025-10-02 01:59:28,947 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-traffic.vmdk.gz
2025-10-02 01:59:28,948 - DEBUG - Unzip image
2025-10-02 01:59:28,948 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-traffic.vmdk.gz
2025-10-02 01:59:43,914 - DEBUG - Try to create image in user context
2025-10-02 01:59:54,722 - DEBUG - Image has been created in user context
2025-10-02 01:59:54,722 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-traffic.vmdk
2025-10-02 01:59:54,885 - DEBUG - Downloaded image has been removed
2025-10-02 01:59:54,897 - DEBUG - Uploaded image status = active
2025-10-02 01:59:55,867 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4210-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4210-2)
2025-10-02 01:59:57,217 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4210-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4210-1)
2025-10-02 01:59:57,395 - INFO - Creating Floating IP pool ctest-some-pool-02543857 in API Server
2025-10-02 01:59:57,593 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:57,603 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:57,690 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:57,817 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:57,837 - DEBUG - Requesting: http://10.0.0.56:8082/floating-ip-pool/172b786b-8f4b-4f3e-8f62-3e2a6810af45
2025-10-02 01:59:57,849 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 01:59:57,857 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 01:59:57,872 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 01:59:58,022 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/f2fb76c3-2e7f-4fbe-b90b-cb09ac41835a
2025-10-02 01:59:58,039 - DEBUG - FIP Pool ctest-some-pool-02543857 found in API Server
2025-10-02 01:59:58,039 - INFO - Verification for FIP pool ctest-some-pool-02543857 in API Server passed
2025-10-02 01:59:58,065 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-02543857 information
2025-10-02 01:59:58,077 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-02543857 information
2025-10-02 01:59:58,089 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-02543857 information
2025-10-02 01:59:58,089 - INFO - Verification for FIP pool ctest-some-pool-02543857 in Control-node passed
2025-10-02 01:59:58,090 - INFO - Waiting for VM ctest-vn1_vm1_name-49311779 to be up..
2025-10-02 01:59:58,227 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:03,349 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:08,475 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:13,564 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:18,648 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:23,726 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:28,834 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:33,946 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:39,027 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:44,110 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:49,197 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-02 02:00:54,289 - DEBUG - VM is in ACTIVE state now
2025-10-02 02:00:54,289 - INFO - VM name : ctest-vn1_vm1_name-49311779
2025-10-02 02:00:54,375 - DEBUG - VM ctest-vn1_vm1_name-49311779 ID is b71600fc-d5e5-43b1-a93e-978413dfb1c5
2025-10-02 02:00:54,403 - DEBUG - VM ctest-vn1_vm1_name-49311779 launched on Node an-jenkins-deploy-platform-ansible-os-4210-2
2025-10-02 02:00:54,495 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/b71600fc-d5e5-43b1-a93e-978413dfb1c5
2025-10-02 02:00:54,804 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/b71600fc-d5e5-43b1-a93e-978413dfb1c5
2025-10-02 02:00:54,835 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/32254dd7-d9be-4d76-bec5-11ccb1e8a4b0
2025-10-02 02:00:57,984 - 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 1022ms')
2025-10-02 02:00:57,984 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:00:57,998 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:02,021 - 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-10-02 02:01:02,021 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:02,034 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:06,090 - 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-10-02 02:01:06,090 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:06,105 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:10,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 1024ms')
2025-10-02 02:01:10,148 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:10,165 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:14,218 - 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-10-02 02:01:14,218 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:14,235 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:18,275 - 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-10-02 02:01:18,275 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:18,289 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:22,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 1033ms')
2025-10-02 02:01:22,345 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:22,357 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:26,405 - 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 1029ms')
2025-10-02 02:01:26,405 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:26,418 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:30,468 - 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-10-02 02:01:30,468 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 failed!
2025-10-02 02:01:30,482 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-vn1-86237260 is 81.141.43.1 and allocation pool is NOT set
2025-10-02 02:01:32,503 - 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.86 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.755 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.755/3.807/6.859/3.052 ms')
2025-10-02 02:01:32,504 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-49311779 passed
2025-10-02 02:01:32,575 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:32,575 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-49311779, IP 81.141.43.3, Port 22
2025-10-02 02:01:32,599 - 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-10-02 02:01:32,685 - DEBUG - VM ctest-vn1_vm1_name-49311779 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-02 02:01:37,685 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:37,686 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-49311779, IP 81.141.43.3, Port 22
2025-10-02 02:01:37,710 - 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-10-02 02:01:37,784 - DEBUG - VM ctest-vn1_vm1_name-49311779 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-02 02:01:42,785 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:42,785 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-49311779, IP 81.141.43.3, Port 22
2025-10-02 02:01:42,799 - 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-10-02 02:01:42,879 - DEBUG - VM ctest-vn1_vm1_name-49311779 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-02 02:01:47,880 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:47,880 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-49311779, IP 81.141.43.3, Port 22
2025-10-02 02:01:47,893 - 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-10-02 02:01:47,986 - DEBUG - VM ctest-vn1_vm1_name-49311779 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-02 02:01:52,987 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:52,987 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-49311779, IP 81.141.43.3, Port 22
2025-10-02 02:01:53,056 - DEBUG - VM ctest-vn1_vm1_name-49311779 is ready for SSH connections
2025-10-02 02:01:53,202 - DEBUG - Created Floating IP : ('113.10.81.196', 'efcc5b79-ae57-49d7-b34d-02de980de441')
2025-10-02 02:01:53,202 - DEBUG - Associating FIP 113.10.81.196 to b71600fc-d5e5-43b1-a93e-978413dfb1c5
2025-10-02 02:01:53,227 - DEBUG - Associating FIP ID efcc5b79-ae57-49d7-b34d-02de980de441 with Port ID 32254dd7-d9be-4d76-bec5-11ccb1e8a4b0
2025-10-02 02:01:53,305 - INFO - Waiting for VM ctest-fvn_vm1_name-26274507 to be up..
2025-10-02 02:01:53,403 - DEBUG - VM is in ACTIVE state now
2025-10-02 02:01:53,403 - INFO - VM name : ctest-fvn_vm1_name-26274507
2025-10-02 02:01:53,482 - DEBUG - VM ctest-fvn_vm1_name-26274507 ID is 7c66f89b-660e-494e-bb4f-151fe73122a5
2025-10-02 02:01:53,482 - DEBUG - VM ctest-fvn_vm1_name-26274507 launched on Node an-jenkins-deploy-platform-ansible-os-4210-1
2025-10-02 02:01:53,557 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/7c66f89b-660e-494e-bb4f-151fe73122a5
2025-10-02 02:01:53,567 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/f57d2641-0260-4c00-a3d1-ef5e28891f7e
2025-10-02 02:01:54,689 - 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.28 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.500 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.500/1.890/3.281/1.390 ms')
2025-10-02 02:01:54,689 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn_vm1_name-26274507 passed
2025-10-02 02:01:54,754 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:54,754 - DEBUG - Waiting to SSH to VM ctest-fvn_vm1_name-26274507, IP 113.10.81.195, Port 22
2025-10-02 02:01:54,837 - DEBUG - VM ctest-fvn_vm1_name-26274507 is ready for SSH connections
2025-10-02 02:01:54,992 - INFO - Route for FIP 113.10.81.196 is fine on Control-node 10.0.0.38
2025-10-02 02:01:55,000 - INFO - Route for FIP 113.10.81.196 is fine on Control-node 10.0.0.49
2025-10-02 02:01:55,011 - INFO - Route for FIP 113.10.81.196 is fine on Control-node 10.0.0.56
2025-10-02 02:01:55,011 - INFO - FIP 113.10.81.196 verification for passed on all Control-nodes
2025-10-02 02:01:55,012 - INFO - FIP ID efcc5b79-ae57-49d7-b34d-02de980de441(113.10.81.196) validation in Control node passed
2025-10-02 02:01:55,045 - DEBUG - agent_label query returned:{'nh': {'type': 'tunnel', 'ref_count': '15', 'valid': 'true', 'policy': 'disabled', 'sip': '10.20.0.252', 'dip': '10.20.0.249', 'vrf': 'default-domain:default-project:ip-fabric:__default__', 'mac': ['fa:16:3e:55:9e:d0'], 'tunnel_type': 'MPLSoUDP', 'nh_index': '22', 'vxlan_flag': 'false', 'intf_flags': '0', 'isid': '0', 'learning_enabled': 'false', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'crypt_all_traffic': 'false', 'crypt_path_available': 'false', 'crypt_interface': None}, 'label': '25', 'vxlan_id': '0', 'peer': '10.20.0.14', 'dest_vn_list': ['default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152'], 'unresolved': 'false', 'sg_list': ['8000007'], 'supported_tunnel_type': 'MPLSoGRE MPLSoUDP ', 'active_tunnel_type': 'MPLSoUDP', 'stale': 'false', 'path_preference_data': {'sequence': '0', 'preference': '200', 'ecmp': 'true'}, 'active_label': '25', 'ecmp_hashing_fields': 'l3-source-address,l3-destination-address,l4-protocol,l4-source-port,l4-destination-port,', 'communities': None, 'peer_sequence_number': '1', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'tag_list': None, 'inactive': 'false', 'origin_vn': None}
2025-10-02 02:01:55,045 - DEBUG - Route for FIP IP 113.10.81.196 is present in agent 10.0.0.33
2025-10-02 02:01:55,045 - DEBUG - FIP 113.10.81.196 verification for VM ctest-vn1_vm1_name-49311779 in Agent 10.0.0.33 passed
2025-10-02 02:01:55,063 - DEBUG - agent_label query returned:{'nh': {'type': 'interface', 'ref_count': '42', 'valid': 'true', 'policy': 'enabled', 'itf': 'tap32254dd7-d9', 'mac': ['2:32:25:4d:d7:d9'], 'mcast': 'disabled', 'nh_index': '31', 'vxlan_flag': 'false', 'intf_flags': '1', 'isid': '0', 'learning_enabled': 'false', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'crypt_all_traffic': 'false', 'crypt_path_available': 'false', 'crypt_interface': None}, 'label': '25', 'vxlan_id': '0', 'peer': '10.20.0.14', 'dest_vn_list': ['default-domain:ctest-FloatingipBasicTestSanity-90634719:ctest-fvn-93214152'], 'unresolved': 'false', 'sg_list': ['8000007'], 'supported_tunnel_type': 'MPLSoGRE MPLSoUDP ', 'active_tunnel_type': 'MPLSoUDP', 'stale': 'false', 'path_preference_data': {'sequence': '0', 'preference': '200', 'ecmp': 'true'}, 'active_label': '25', 'ecmp_hashing_fields': 'l3-source-address,l3-destination-address,l4-protocol,l4-source-port,l4-destination-port,', 'communities': None, 'peer_sequence_number': '1', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'tag_list': None, 'inactive': 'false', 'origin_vn': None}
2025-10-02 02:01:55,063 - DEBUG - Route for FIP IP 113.10.81.196 is present in agent 10.0.0.130
2025-10-02 02:01:55,063 - DEBUG - FIP 113.10.81.196 verification for VM ctest-vn1_vm1_name-49311779 in Agent 10.0.0.130 passed
2025-10-02 02:01:55,063 - INFO - FIP ID efcc5b79-ae57-49d7-b34d-02de980de441(113.10.81.196) validation in agents passed
2025-10-02 02:01:55,064 - DEBUG - Requesting: http://10.0.0.56:8082/floating-ip/efcc5b79-ae57-49d7-b34d-02de980de441
2025-10-02 02:01:55,072 - DEBUG - FIP efcc5b79-ae57-49d7-b34d-02de980de441 is present in API server
2025-10-02 02:01:55,072 - INFO - FIP ID efcc5b79-ae57-49d7-b34d-02de980de441(113.10.81.196) validation in API Server passed
2025-10-02 02:01:55,073 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-02 02:01:55,073 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 113.10.81.195, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.130, gateway password: c0ntrail123
2025-10-02 02:01:55,073 - DEBUG - ping -s 56 -c 3 -W 1 113.10.81.195
2025-10-02 02:02:16,014 - DEBUG - PING 113.10.81.195 (113.10.81.195) 56(84) bytes of data.
64 bytes from 113.10.81.195: icmp_req=1 ttl=64 time=10.4 ms
64 bytes from 113.10.81.195: icmp_req=2 ttl=64 time=1.03 ms
64 bytes from 113.10.81.195: icmp_req=3 ttl=64 time=1.06 ms
--- 113.10.81.195 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.031/4.173/10.425/4.420 ms
2025-10-02 02:02:16,015 - INFO - Ping to IP 113.10.81.195 from VM ctest-vn1_vm1_name-49311779 passed
2025-10-02 02:02:16,015 - DEBUG - Disassociating port from FIP ID : efcc5b79-ae57-49d7-b34d-02de980de441
2025-10-02 02:02:16,080 - DEBUG - Deleting FIP ID efcc5b79-ae57-49d7-b34d-02de980de441
2025-10-02 02:02:16,176 - INFO - Deleting the FIP pool ctest-some-pool-02543857
2025-10-02 02:02:16,284 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-02543857 information
2025-10-02 02:02:16,288 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-02543857 information
2025-10-02 02:02:16,293 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-02543857 information
2025-10-02 02:02:16,293 - INFO - Deleting VM ctest-fvn_vm1_name-26274507
2025-10-02 02:02:16,362 - INFO - Deleting VM ctest-vn1_vm1_name-49311779
2025-10-02 02:02:16,427 - INFO - Deleting VN ctest-vn1-86237260
2025-10-02 02:02:16,474 - DEBUG - VN 4e8f858c-1fe8-44da-9dd5-88499ec5313d still in use: Unable to complete operation on network 4e8f858c-1fe8-44da-9dd5-88499ec5313d. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-032caf8a-72d7-4431-9a45-f69785f7966b']
2025-10-02 02:02:16,474 - WARNING - Deleting VN ctest-vn1-86237260 failed..Will retry
2025-10-02 02:02:18,626 - DEBUG - Response for deleting network ()
2025-10-02 02:02:18,626 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/0ad00752-7e2c-4874-bb1a-8203931ab51e
2025-10-02 02:02:18,632 - DEBUG - Response Code: 404
2025-10-02 02:02:18,632 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 02:02:18,638 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 02:02:18,695 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 02:02:18,779 - INFO - Validated that VN ctest-vn1-86237260 is not found in API Server
2025-10-02 02:02:18,788 - DEBUG - VN ctest-vn1-86237260 is not present in Agent 10.0.0.33
2025-10-02 02:02:18,797 - DEBUG - VN ctest-vn1-86237260 is not present in Agent 10.0.0.130
2025-10-02 02:02:18,797 - INFO - Validated that VN ctest-vn1-86237260 is not in any agent
2025-10-02 02:02:18,823 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-86237260 info
2025-10-02 02:02:18,823 - INFO - Deleting VN ctest-fvn-93214152
2025-10-02 02:02:19,021 - DEBUG - Response for deleting network ()
2025-10-02 02:02:19,022 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/07f071e2-fbc4-48a5-9938-907c1e69a6c7
2025-10-02 02:02:19,027 - DEBUG - Response Code: 404
2025-10-02 02:02:19,027 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-02 02:02:19,031 - DEBUG - Requesting: http://10.0.0.56:8082/domain/b0543e69-2184-4be1-8e23-ac5840233bc6
2025-10-02 02:02:19,043 - DEBUG - Requesting: http://10.0.0.56:8082/project/5055f687-15f4-46f4-9cdd-e17d31c0a69e
2025-10-02 02:02:19,137 - INFO - Validated that VN ctest-fvn-93214152 is not found in API Server
2025-10-02 02:02:19,146 - DEBUG - VN ctest-fvn-93214152 is not present in Agent 10.0.0.33
2025-10-02 02:02:19,157 - DEBUG - VN ctest-fvn-93214152 is not present in Agent 10.0.0.130
2025-10-02 02:02:19,157 - INFO - Validated that VN ctest-fvn-93214152 is not in any agent
2025-10-02 02:02:19,184 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-fvn-93214152 info
2025-10-02 02:02:20,450 - DEBUG - No XMPP flaps were noticed during the test
2025-10-02 02:02:20,450 - INFO - END TEST : test_floating_ip : PASSED[0:03:01]
2025-10-02 02:02:20,450 - INFO - --------------------------------------------------------------------------------
2025-10-02 02:02:21,225 - INFO - Deleted project: ctest-FloatingipBasicTestSanity-90634719, ID : 5055f687-15f4-46f4-9cdd-e17d31c0a69e