2026-03-26 02:25:51,742 - INFO - Domain Default found not creating
2026-03-26 02:25:51,919 - INFO - Project ctest-FloatingipBasicTestSanity-95265265 not found, creating it
2026-03-26 02:25:52,442 - INFO - Created Project:ctest-FloatingipBasicTestSanity-95265265, ID : d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:25:54,207 - INFO - ================================================================================
2026-03-26 02:25:54,207 - INFO - STARTING TEST : test_floating_ip
2026-03-26 02:25:54,207 - 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.
2026-03-26 02:25:54,835 - DEBUG - Nothing to compare xmpp stats {'10.0.0.38': {'10.20.0.18': '0', '10.20.0.14': '0'}, '10.0.0.23': {'10.20.0.254': '0', '10.20.0.18': '0'}} with
2026-03-26 02:25:54,836 - INFO - Initial checks done. Running the testcase now
2026-03-26 02:25:54,836 - INFO -
2026-03-26 02:25:54,862 - DEBUG - Services list from nova: [, , , ]
2026-03-26 02:25:54,862 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-5545-2', 'an-jenkins-deploy-platform-ansible-os-5545-1']}
2026-03-26 02:25:55,546 - DEBUG - Response for create_network : {'network': {'id': 'cd93fd86-f793-46b0-9f3d-7fab7435889d', 'name': 'ctest-fvn-93219450', 'tenant_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'project_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-95265265', 'ctest-fvn-93219450'], 'port_security_enabled': True, 'description': ''}}
2026-03-26 02:25:55,848 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a9293282-f929-498f-9c51-160867011b7f', 'name': '', 'tenant_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'network_id': 'cd93fd86-f793-46b0-9f3d-7fab7435889d', 'ip_version': 4, 'cidr': '162.157.242.192/26', 'allocation_pools': [{'start': '162.157.242.194', 'end': '162.157.242.254'}], 'gateway_ip': '162.157.242.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '162.157.242.194', 'tags': [], 'project_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a'}}
2026-03-26 02:25:55,871 - INFO - Created VN ctest-fvn-93219450
2026-03-26 02:25:55,899 - DEBUG - VN ctest-fvn-93219450 UUID is cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:55,978 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:25:56,314 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:25:56,345 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:25:56,361 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:25:56,462 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,476 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,486 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:25:56,496 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:25:56,504 - DEBUG - Requesting: http://10.0.0.240:8082/route-target/4af63a30-0586-42b7-9580-69a4f2f5c0ca
2026-03-26 02:25:56,512 - DEBUG - Route Targets: ['target:64512:8000004']
2026-03-26 02:25:56,513 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,522 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:25:56,540 - INFO - Verified VN network id 9 for VN cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,541 - INFO - Verifications in API Server for VN ctest-fvn-93219450 passed
2026-03-26 02:25:56,541 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,555 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:25:56,563 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:25:56,572 - DEBUG - Requesting: http://10.0.0.240:8082/route-target/4af63a30-0586-42b7-9580-69a4f2f5c0ca
2026-03-26 02:25:56,587 - DEBUG - Control-node 10.0.0.240 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14813462355472762544', 'uuid-lslong': '11474467799975692445'}, 'enable': 'true', 'created': '2026-03-26T02:25:55', 'last-modified': '2026-03-26T02:25:55', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.809174'}
2026-03-26 02:25:56,593 - DEBUG - Route Targets: ['target:64512:8000004']
2026-03-26 02:25:56,604 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14813462355472762544', 'uuid-lslong': '11474467799975692445'}, 'enable': 'true', 'created': '2026-03-26T02:25:55', 'last-modified': '2026-03-26T02:25:55', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.818876'}
2026-03-26 02:25:56,610 - DEBUG - Route Targets: ['target:64512:8000004']
2026-03-26 02:25:56,615 - DEBUG - Control-node 10.0.0.65 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14813462355472762544', 'uuid-lslong': '11474467799975692445'}, 'enable': 'true', 'created': '2026-03-26T02:25:55', 'last-modified': '2026-03-26T02:25:55', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.834298'}
2026-03-26 02:25:56,621 - DEBUG - Route Targets: ['target:64512:8000004']
2026-03-26 02:25:56,621 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-fvn-93219450 passed
2026-03-26 02:25:56,621 - DEBUG - ====Verifying policy data for ctest-fvn-93219450 in API_Server ======
2026-03-26 02:25:56,621 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:25:56,628 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:25:56,643 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:25:56,744 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:25:56,754 - DEBUG - =>VN ctest-fvn-93219450 has no policy to be verified
2026-03-26 02:25:56,754 - DEBUG - Verifying the vn in opserver
2026-03-26 02:25:56,754 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450 virtual network link through opserver 10.0.0.240
2026-03-26 02:25:56,755 - DEBUG - Requesting: http://10.0.0.240:8081/analytics/uves/virtual-networks
2026-03-26 02:25:57,106 - DEBUG - Requesting: http://10.0.0.240:8081/analytics/uves/virtual-networks
2026-03-26 02:25:57,180 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'href': 'http://10.0.0.240:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450?flat'}
2026-03-26 02:25:57,180 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450 virtual network link through opserver 10.0.0.22
2026-03-26 02:25:57,180 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2026-03-26 02:25:57,525 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2026-03-26 02:25:57,585 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450?flat'}
2026-03-26 02:25:57,585 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450 virtual network link through opserver 10.0.0.65
2026-03-26 02:25:57,585 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2026-03-26 02:25:57,931 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2026-03-26 02:25:58,005 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450?flat'}
2026-03-26 02:25:58,005 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450 is found in opserver
2026-03-26 02:25:58,030 - DEBUG - Do not have enough data to verify VN in agent
2026-03-26 02:25:58,048 - DEBUG - VRF ids for VN ctest-fvn-93219450: {}
2026-03-26 02:25:58,335 - DEBUG - Response for create_network : {'network': {'id': '765c22fc-44a0-4b8a-afd0-0191a3dcfd23', 'name': 'ctest-vn1-59970954', 'tenant_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'project_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-95265265', 'ctest-vn1-59970954'], 'port_security_enabled': True, 'description': ''}}
2026-03-26 02:25:58,576 - DEBUG - Response for create_subnet : {'subnet': {'id': '35ce3442-a74a-45dd-84bb-2cd534c35891', 'name': '', 'tenant_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a', 'network_id': '765c22fc-44a0-4b8a-afd0-0191a3dcfd23', 'ip_version': 4, 'cidr': '16.168.121.0/26', 'allocation_pools': [{'start': '16.168.121.2', 'end': '16.168.121.62'}], 'gateway_ip': '16.168.121.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '16.168.121.2', 'tags': [], 'project_id': 'd34a1ccf14c040c6a88b59f2ab0c9f7a'}}
2026-03-26 02:25:58,602 - INFO - Created VN ctest-vn1-59970954
2026-03-26 02:25:58,615 - DEBUG - VN ctest-vn1-59970954 UUID is 765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,693 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:25:58,699 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:25:58,710 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:25:58,798 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,811 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,822 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:25:58,832 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:25:58,839 - DEBUG - Requesting: http://10.0.0.240:8082/route-target/60225541-db95-4b56-9a59-785d0f1f07bf
2026-03-26 02:25:58,847 - DEBUG - Route Targets: ['target:64512:8000006']
2026-03-26 02:25:58,847 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,856 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:25:58,874 - INFO - Verified VN network id 10 for VN 765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,874 - INFO - Verifications in API Server for VN ctest-vn1-59970954 passed
2026-03-26 02:25:58,874 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:58,884 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:25:58,892 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:25:58,899 - DEBUG - Requesting: http://10.0.0.240:8082/route-target/60225541-db95-4b56-9a59-785d0f1f07bf
2026-03-26 02:25:58,914 - DEBUG - Control-node 10.0.0.240 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8528730261211335562', 'uuid-lslong': '12668627476824259875'}, 'enable': 'true', 'created': '2026-03-26T02:25:58', 'last-modified': '2026-03-26T02:25:58', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.392130'}
2026-03-26 02:25:58,920 - DEBUG - Route Targets: ['target:64512:8000006']
2026-03-26 02:25:58,926 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8528730261211335562', 'uuid-lslong': '12668627476824259875'}, 'enable': 'true', 'created': '2026-03-26T02:25:58', 'last-modified': '2026-03-26T02:25:58', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.403950'}
2026-03-26 02:25:58,932 - DEBUG - Route Targets: ['target:64512:8000006']
2026-03-26 02:25:58,938 - DEBUG - Control-node 10.0.0.65 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-95265265', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8528730261211335562', 'uuid-lslong': '12668627476824259875'}, 'enable': 'true', 'created': '2026-03-26T02:25:58', 'last-modified': '2026-03-26T02:25:58', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.419750'}
2026-03-26 02:25:58,944 - DEBUG - Route Targets: ['target:64512:8000006']
2026-03-26 02:25:58,944 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-59970954 passed
2026-03-26 02:25:58,945 - DEBUG - ====Verifying policy data for ctest-vn1-59970954 in API_Server ======
2026-03-26 02:25:58,945 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:25:58,951 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:25:58,963 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:25:59,055 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/765c22fc-44a0-4b8a-afd0-0191a3dcfd23
2026-03-26 02:25:59,066 - DEBUG - =>VN ctest-vn1-59970954 has no policy to be verified
2026-03-26 02:25:59,066 - DEBUG - Verifying the vn in opserver
2026-03-26 02:25:59,066 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 virtual network link through opserver 10.0.0.240
2026-03-26 02:25:59,066 - DEBUG - Requesting: http://10.0.0.240:8081/analytics/uves/virtual-networks
2026-03-26 02:25:59,137 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'href': 'http://10.0.0.240:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954?flat'}
2026-03-26 02:25:59,138 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 virtual network link through opserver 10.0.0.22
2026-03-26 02:25:59,138 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2026-03-26 02:25:59,203 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954?flat'}
2026-03-26 02:25:59,204 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 virtual network link through opserver 10.0.0.65
2026-03-26 02:25:59,204 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2026-03-26 02:25:59,268 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954?flat'}
2026-03-26 02:25:59,269 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is found in opserver
2026-03-26 02:25:59,290 - DEBUG - Do not have enough data to verify VN in agent
2026-03-26 02:25:59,301 - DEBUG - VRF ids for VN ctest-vn1-59970954: {}
2026-03-26 02:25:59,366 - DEBUG - Image by name ubuntu not found
2026-03-26 02:25:59,366 - DEBUG - Installing image ubuntu
2026-03-26 02:25:59,366 - 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'"}
2026-03-26 02:25:59,367 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic.vmdk.gz
2026-03-26 02:25:59,367 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic.vmdk.gz
2026-03-26 02:25:59,379 - 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
2026-03-26 02:26:04,564 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-traffic.vmdk.gz
2026-03-26 02:26:04,564 - DEBUG - Unzip image
2026-03-26 02:26:04,564 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-traffic.vmdk.gz
2026-03-26 02:26:22,829 - DEBUG - Try to create image in user context
2026-03-26 02:26:34,574 - DEBUG - Image has been created in user context
2026-03-26 02:26:34,574 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-traffic.vmdk
2026-03-26 02:26:34,764 - DEBUG - Downloaded image has been removed
2026-03-26 02:26:34,783 - DEBUG - Uploaded image status = active
2026-03-26 02:26:35,966 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5545-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5545-2)
2026-03-26 02:26:37,741 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5545-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5545-1)
2026-03-26 02:26:37,976 - INFO - Creating Floating IP pool ctest-some-pool-52997813 in API Server
2026-03-26 02:26:38,256 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:26:38,274 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:26:38,316 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:26:38,432 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:26:38,455 - DEBUG - Requesting: http://10.0.0.240:8082/floating-ip-pool/5a509d36-9628-47d7-949b-6aec6506d12e
2026-03-26 02:26:38,466 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:26:38,482 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:26:38,505 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:26:38,687 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-network/cd93fd86-f793-46b0-9f3d-7fab7435889d
2026-03-26 02:26:38,711 - DEBUG - FIP Pool ctest-some-pool-52997813 found in API Server
2026-03-26 02:26:38,711 - INFO - Verification for FIP pool ctest-some-pool-52997813 in API Server passed
2026-03-26 02:26:38,739 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-52997813 information
2026-03-26 02:26:38,760 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-52997813 information
2026-03-26 02:26:38,784 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-52997813 information
2026-03-26 02:26:38,784 - INFO - Verification for FIP pool ctest-some-pool-52997813 in Control-node passed
2026-03-26 02:26:38,784 - INFO - Waiting for VM ctest-vn1_vm1_name-44849686 to be up..
2026-03-26 02:26:38,943 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:26:44,099 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:26:49,244 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:26:54,409 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:26:59,568 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:04,734 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:09,825 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:14,915 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:20,021 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:25,109 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:30,203 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:35,319 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:40,418 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:45,512 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-03-26 02:27:50,605 - DEBUG - VM is in ACTIVE state now
2026-03-26 02:27:50,605 - INFO - VM name : ctest-vn1_vm1_name-44849686
2026-03-26 02:27:50,686 - DEBUG - VM ctest-vn1_vm1_name-44849686 ID is a0687bae-e376-42e0-afe8-56f529bad5d3
2026-03-26 02:27:50,711 - DEBUG - VM ctest-vn1_vm1_name-44849686 launched on Node an-jenkins-deploy-platform-ansible-os-5545-2
2026-03-26 02:27:50,795 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/a0687bae-e376-42e0-afe8-56f529bad5d3
2026-03-26 02:27:51,138 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/a0687bae-e376-42e0-afe8-56f529bad5d3
2026-03-26 02:27:51,184 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/9aa488ba-05c4-4f27-a168-abdbbb2d4c32
2026-03-26 02:27:54,343 - 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 1034ms')
2026-03-26 02:27:54,343 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:27:54,356 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:27:58,408 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1030ms')
2026-03-26 02:27:58,408 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:27:58,424 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:02,464 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1025ms')
2026-03-26 02:28:02,464 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:02,480 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:06,536 - 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')
2026-03-26 02:28:06,537 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:06,550 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:10,597 - 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')
2026-03-26 02:28:10,598 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:10,619 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:14,656 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms')
2026-03-26 02:28:14,656 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:14,672 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:18,688 - 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 1002ms')
2026-03-26 02:28:18,688 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:18,702 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:22,720 - 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 1002ms')
2026-03-26 02:28:22,720 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 failed!
2026-03-26 02:28:22,735 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-vn1-59970954 is 16.168.121.1 and allocation pool is NOT set
2026-03-26 02:28:26,754 - 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=3.99 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1003ms\r\nrtt min/avg/max/mdev = 3.988/3.988/3.988/0.000 ms')
2026-03-26 02:28:26,754 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-44849686 passed
2026-03-26 02:28:26,825 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:26,825 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-44849686, IP 16.168.121.3, Port 22
2026-03-26 02:28:26,849 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-03-26 02:28:26,931 - DEBUG - VM ctest-vn1_vm1_name-44849686 is NOT ready for SSH connections, VM status: ACTIVE
2026-03-26 02:28:31,933 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:31,933 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-44849686, IP 16.168.121.3, Port 22
2026-03-26 02:28:31,957 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-03-26 02:28:32,046 - DEBUG - VM ctest-vn1_vm1_name-44849686 is NOT ready for SSH connections, VM status: ACTIVE
2026-03-26 02:28:37,047 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:37,047 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-44849686, IP 16.168.121.3, Port 22
2026-03-26 02:28:37,072 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-03-26 02:28:37,166 - DEBUG - VM ctest-vn1_vm1_name-44849686 is NOT ready for SSH connections, VM status: ACTIVE
2026-03-26 02:28:42,167 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:42,167 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-44849686, IP 16.168.121.3, Port 22
2026-03-26 02:28:42,183 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-03-26 02:28:42,270 - DEBUG - VM ctest-vn1_vm1_name-44849686 is NOT ready for SSH connections, VM status: ACTIVE
2026-03-26 02:28:47,270 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:47,270 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-44849686, IP 16.168.121.3, Port 22
2026-03-26 02:28:47,358 - DEBUG - VM ctest-vn1_vm1_name-44849686 is ready for SSH connections
2026-03-26 02:28:47,498 - DEBUG - Created Floating IP : ('162.157.242.196', '09f5ed8b-6138-45db-8011-07f54ca70b54')
2026-03-26 02:28:47,498 - DEBUG - Associating FIP 162.157.242.196 to a0687bae-e376-42e0-afe8-56f529bad5d3
2026-03-26 02:28:47,529 - DEBUG - Associating FIP ID 09f5ed8b-6138-45db-8011-07f54ca70b54 with Port ID 9aa488ba-05c4-4f27-a168-abdbbb2d4c32
2026-03-26 02:28:47,614 - INFO - Waiting for VM ctest-fvn_vm1_name-56750072 to be up..
2026-03-26 02:28:47,712 - DEBUG - VM is in ACTIVE state now
2026-03-26 02:28:47,712 - INFO - VM name : ctest-fvn_vm1_name-56750072
2026-03-26 02:28:47,798 - DEBUG - VM ctest-fvn_vm1_name-56750072 ID is 806a6179-4621-4c79-8f75-069e72a53ff4
2026-03-26 02:28:47,798 - DEBUG - VM ctest-fvn_vm1_name-56750072 launched on Node an-jenkins-deploy-platform-ansible-os-5545-1
2026-03-26 02:28:47,882 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/806a6179-4621-4c79-8f75-069e72a53ff4
2026-03-26 02:28:47,892 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/add8c16d-0e66-4cd6-8b6f-62b686884a3d
2026-03-26 02:28:49,006 - 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.12 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.51 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 1.505/2.312/3.120/0.807 ms')
2026-03-26 02:28:49,006 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-fvn_vm1_name-56750072 passed
2026-03-26 02:28:49,076 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:49,076 - DEBUG - Waiting to SSH to VM ctest-fvn_vm1_name-56750072, IP 162.157.242.195, Port 22
2026-03-26 02:28:49,159 - DEBUG - VM ctest-fvn_vm1_name-56750072 is ready for SSH connections
2026-03-26 02:28:49,339 - INFO - Route for FIP 162.157.242.196 is fine on Control-node 10.0.0.22
2026-03-26 02:28:49,349 - INFO - Route for FIP 162.157.242.196 is fine on Control-node 10.0.0.240
2026-03-26 02:28:49,359 - INFO - Route for FIP 162.157.242.196 is fine on Control-node 10.0.0.65
2026-03-26 02:28:49,359 - INFO - FIP 162.157.242.196 verification for passed on all Control-nodes
2026-03-26 02:28:49,359 - INFO - FIP ID 09f5ed8b-6138-45db-8011-07f54ca70b54(162.157.242.196) validation in Control node passed
2026-03-26 02:28:49,385 - DEBUG - agent_label query returned:{'nh': {'type': 'tunnel', 'ref_count': '15', 'valid': 'true', 'policy': 'disabled', 'sip': '10.20.0.249', 'dip': '10.20.0.241', 'vrf': 'default-domain:default-project:ip-fabric:__default__', 'mac': ['fa:16:3e:ee:32:37'], 'tunnel_type': 'MPLSoUDP', 'nh_index': '20', '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': '24', 'vxlan_id': '0', 'peer': '10.20.0.14', 'dest_vn_list': ['default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450'], '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': '24', '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}
2026-03-26 02:28:49,385 - DEBUG - Route for FIP IP 162.157.242.196 is present in agent 10.0.0.38
2026-03-26 02:28:49,385 - DEBUG - FIP 162.157.242.196 verification for VM ctest-vn1_vm1_name-44849686 in Agent 10.0.0.38 passed
2026-03-26 02:28:49,413 - DEBUG - agent_label query returned:{'nh': {'type': 'interface', 'ref_count': '40', 'valid': 'true', 'policy': 'enabled', 'itf': 'tap9aa488ba-05', 'mac': ['2:9a:a4:88:ba:5'], 'mcast': 'disabled', 'nh_index': '26', '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': '24', 'vxlan_id': '0', 'peer': '10.20.0.18', 'dest_vn_list': ['default-domain:ctest-FloatingipBasicTestSanity-95265265:ctest-fvn-93219450'], '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': '24', '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}
2026-03-26 02:28:49,413 - DEBUG - Route for FIP IP 162.157.242.196 is present in agent 10.0.0.23
2026-03-26 02:28:49,413 - DEBUG - FIP 162.157.242.196 verification for VM ctest-vn1_vm1_name-44849686 in Agent 10.0.0.23 passed
2026-03-26 02:28:49,413 - INFO - FIP ID 09f5ed8b-6138-45db-8011-07f54ca70b54(162.157.242.196) validation in agents passed
2026-03-26 02:28:49,413 - DEBUG - Requesting: http://10.0.0.240:8082/floating-ip/09f5ed8b-6138-45db-8011-07f54ca70b54
2026-03-26 02:28:49,430 - DEBUG - FIP 09f5ed8b-6138-45db-8011-07f54ca70b54 is present in API server
2026-03-26 02:28:49,430 - INFO - FIP ID 09f5ed8b-6138-45db-8011-07f54ca70b54(162.157.242.196) validation in API Server passed
2026-03-26 02:28:49,430 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-03-26 02:28:49,430 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 162.157.242.195, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.23, gateway password: c0ntrail123
2026-03-26 02:28:49,430 - DEBUG - ping -s 56 -c 3 -W 1 162.157.242.195
2026-03-26 02:29:07,395 - DEBUG - PING 162.157.242.195 (162.157.242.195) 56(84) bytes of data.
64 bytes from 162.157.242.195: icmp_req=1 ttl=64 time=9.62 ms
64 bytes from 162.157.242.195: icmp_req=2 ttl=64 time=1.11 ms
64 bytes from 162.157.242.195: icmp_req=3 ttl=64 time=1.07 ms
--- 162.157.242.195 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.070/3.935/9.620/4.020 ms
2026-03-26 02:29:07,395 - INFO - Ping to IP 162.157.242.195 from VM ctest-vn1_vm1_name-44849686 passed
2026-03-26 02:29:07,395 - DEBUG - Disassociating port from FIP ID : 09f5ed8b-6138-45db-8011-07f54ca70b54
2026-03-26 02:29:07,508 - DEBUG - Deleting FIP ID 09f5ed8b-6138-45db-8011-07f54ca70b54
2026-03-26 02:29:07,616 - INFO - Deleting the FIP pool ctest-some-pool-52997813
2026-03-26 02:29:07,753 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-52997813 information
2026-03-26 02:29:07,762 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-52997813 information
2026-03-26 02:29:07,770 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-52997813 information
2026-03-26 02:29:07,770 - INFO - Deleting VM ctest-fvn_vm1_name-56750072
2026-03-26 02:29:07,849 - INFO - Deleting VM ctest-vn1_vm1_name-44849686
2026-03-26 02:29:07,934 - INFO - Deleting VN ctest-vn1-59970954
2026-03-26 02:29:07,982 - DEBUG - VN 765c22fc-44a0-4b8a-afd0-0191a3dcfd23 still in use: Unable to complete operation on network 765c22fc-44a0-4b8a-afd0-0191a3dcfd23. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-51c854dc-5a69-4fa1-921f-f92914c0dec4']
2026-03-26 02:29:07,982 - WARNING - Deleting VN ctest-vn1-59970954 failed..Will retry
2026-03-26 02:29:10,153 - DEBUG - Response for deleting network ()
2026-03-26 02:29:10,153 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/a6e98de9-238d-40a3-9f9a-6cf6e659b1e5
2026-03-26 02:29:10,163 - DEBUG - Response Code: 404
2026-03-26 02:29:10,163 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:29:10,169 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:29:10,180 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:29:10,282 - INFO - Validated that VN ctest-vn1-59970954 is not found in API Server
2026-03-26 02:29:10,294 - DEBUG - VN ctest-vn1-59970954 is not present in Agent 10.0.0.38
2026-03-26 02:29:10,303 - DEBUG - VN ctest-vn1-59970954 is not present in Agent 10.0.0.23
2026-03-26 02:29:10,303 - INFO - Validated that VN ctest-vn1-59970954 is not in any agent
2026-03-26 02:29:10,338 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-59970954 info
2026-03-26 02:29:10,338 - INFO - Deleting VN ctest-fvn-93219450
2026-03-26 02:29:10,503 - DEBUG - Response for deleting network ()
2026-03-26 02:29:10,503 - DEBUG - Requesting: http://10.0.0.240:8082/routing-instance/6914b7e6-4380-4058-8c3b-2a38680f664e
2026-03-26 02:29:10,509 - DEBUG - Response Code: 404
2026-03-26 02:29:10,509 - DEBUG - Requesting: http://10.0.0.240:8082/domains
2026-03-26 02:29:10,516 - DEBUG - Requesting: http://10.0.0.240:8082/domain/b07ef41d-f358-4169-a694-2c6c20158c87
2026-03-26 02:29:10,573 - DEBUG - Requesting: http://10.0.0.240:8082/project/d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a
2026-03-26 02:29:10,666 - INFO - Validated that VN ctest-fvn-93219450 is not found in API Server
2026-03-26 02:29:10,676 - DEBUG - VN ctest-fvn-93219450 is not present in Agent 10.0.0.38
2026-03-26 02:29:10,685 - DEBUG - VN ctest-fvn-93219450 is not present in Agent 10.0.0.23
2026-03-26 02:29:10,685 - INFO - Validated that VN ctest-fvn-93219450 is not in any agent
2026-03-26 02:29:10,716 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-fvn-93219450 info
2026-03-26 02:29:12,013 - DEBUG - No XMPP flaps were noticed during the test
2026-03-26 02:29:12,013 - INFO - END TEST : test_floating_ip : PASSED[0:03:18]
2026-03-26 02:29:12,013 - INFO - --------------------------------------------------------------------------------
2026-03-26 02:29:12,829 - INFO - Deleted project: ctest-FloatingipBasicTestSanity-95265265, ID : d34a1ccf-14c0-40c6-a88b-59f2ab0c9f7a