2025-11-24 17:42:09,718 - INFO - Domain Default found not creating
2025-11-24 17:42:09,897 - INFO - Project ctest-FloatingipBasicTestSanity-53988673 not found, creating it
2025-11-24 17:42:10,381 - INFO - Created Project:ctest-FloatingipBasicTestSanity-53988673, ID : 95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:12,009 - INFO - Using existing project ['default-domain', 'admin'](222e316b-9bfa-46ae-8384-6fdbcb28dc1e)
2025-11-24 17:42:12,841 - INFO - Adding rules to the default security group in Project admin
2025-11-24 17:42:13,175 - INFO - ================================================================================
2025-11-24 17:42:13,175 - INFO - STARTING TEST : test_floating_ip
2025-11-24 17:42:13,175 - 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-11-24 17:42:13,319 - DEBUG - Nothing to compare xmpp stats {'10.0.0.57': {'10.20.0.130': '0'}} with
2025-11-24 17:42:13,319 - INFO - Initial checks done. Running the testcase now
2025-11-24 17:42:13,319 - INFO -
2025-11-24 17:42:13,346 - DEBUG - Services list from nova: [, , ]
2025-11-24 17:42:13,346 - DEBUG - Hosts: {'nova': ['cn-jenkins-deploy-platform-ansible-os-4811-1']}
2025-11-24 17:42:13,952 - DEBUG - Response for create_network : {'network': {'id': '316e0d92-b70b-4f1f-a16d-81acb6b102dd', 'name': 'ctest-fvn-52858623', 'tenant_id': '95529840e3cc4134923f871dad335be9', 'project_id': '95529840e3cc4134923f871dad335be9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-53988673', 'ctest-fvn-52858623'], 'port_security_enabled': True, 'description': ''}}
2025-11-24 17:42:14,143 - DEBUG - Response for create_subnet : {'subnet': {'id': '19dcd3fe-9700-4f01-913d-9cfe61868e62', 'name': '', 'tenant_id': '95529840e3cc4134923f871dad335be9', 'network_id': '316e0d92-b70b-4f1f-a16d-81acb6b102dd', 'ip_version': 4, 'cidr': '71.102.144.64/26', 'allocation_pools': [{'start': '71.102.144.66', 'end': '71.102.144.126'}], 'gateway_ip': '71.102.144.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '71.102.144.66', 'tags': [], 'project_id': '95529840e3cc4134923f871dad335be9'}}
2025-11-24 17:42:14,161 - INFO - Created VN ctest-fvn-52858623
2025-11-24 17:42:14,213 - DEBUG - VN ctest-fvn-52858623 UUID is 316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,330 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:14,664 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:14,713 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:14,729 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:14,809 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,824 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,837 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:14,846 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:14,856 - DEBUG - Requesting: http://10.0.0.57:8082/route-target/9ee38c98-0c5f-483e-a828-c7ed25ec940b
2025-11-24 17:42:14,866 - DEBUG - Route Targets: ['target:64512:8000004']
2025-11-24 17:42:14,866 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,877 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:14,896 - INFO - Verified VN network id 6 for VN 316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,897 - INFO - Verifications in API Server for VN ctest-fvn-52858623 passed
2025-11-24 17:42:14,897 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:14,912 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:14,923 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:14,932 - DEBUG - Requesting: http://10.0.0.57:8082/route-target/9ee38c98-0c5f-483e-a828-c7ed25ec940b
2025-11-24 17:42:14,949 - DEBUG - Control-node 10.0.0.57 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-53988673', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '3561799279083999007', 'uuid-lslong': '11632095991367271133'}, 'enable': 'true', 'created': '2025-11-24T17:42:13', 'last-modified': '2025-11-24T17:42:14', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.841837'}
2025-11-24 17:42:14,957 - DEBUG - Route Targets: ['target:64512:8000004']
2025-11-24 17:42:14,957 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-fvn-52858623 passed
2025-11-24 17:42:14,957 - DEBUG - ====Verifying policy data for ctest-fvn-52858623 in API_Server ======
2025-11-24 17:42:14,957 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:14,965 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:14,976 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:15,079 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:15,092 - DEBUG - =>VN ctest-fvn-52858623 has no policy to be verified
2025-11-24 17:42:15,092 - DEBUG - Verifying the vn in opserver
2025-11-24 17:42:15,092 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623 virtual network link through opserver 10.0.0.57
2025-11-24 17:42:15,092 - DEBUG - Requesting: http://10.0.0.57:8081/analytics/uves/virtual-networks
2025-11-24 17:42:15,453 - DEBUG - Requesting: http://10.0.0.57:8081/analytics/uves/virtual-networks
2025-11-24 17:42:15,535 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623', 'href': 'http://10.0.0.57:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623?flat'}
2025-11-24 17:42:15,535 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623 is found in opserver
2025-11-24 17:42:15,546 - DEBUG - Do not have enough data to verify VN in agent
2025-11-24 17:42:15,551 - DEBUG - VRF ids for VN ctest-fvn-52858623: {}
2025-11-24 17:42:15,741 - DEBUG - Response for create_network : {'network': {'id': 'dc50955d-f19e-42dd-a80c-d0f736ce2b0b', 'name': 'ctest-vn1-36881456', 'tenant_id': '95529840e3cc4134923f871dad335be9', 'project_id': '95529840e3cc4134923f871dad335be9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-FloatingipBasicTestSanity-53988673', 'ctest-vn1-36881456'], 'port_security_enabled': True, 'description': ''}}
2025-11-24 17:42:15,900 - DEBUG - Response for create_subnet : {'subnet': {'id': 'fb0c03c5-6ef6-44f1-bd71-bf135af0a1d6', 'name': '', 'tenant_id': '95529840e3cc4134923f871dad335be9', 'network_id': 'dc50955d-f19e-42dd-a80c-d0f736ce2b0b', 'ip_version': 4, 'cidr': '120.189.36.128/26', 'allocation_pools': [{'start': '120.189.36.130', 'end': '120.189.36.190'}], 'gateway_ip': '120.189.36.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '120.189.36.130', 'tags': [], 'project_id': '95529840e3cc4134923f871dad335be9'}}
2025-11-24 17:42:15,921 - INFO - Created VN ctest-vn1-36881456
2025-11-24 17:42:15,973 - DEBUG - VN ctest-vn1-36881456 UUID is dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,080 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:16,085 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:16,095 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:16,170 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,180 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,189 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:16,196 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:16,203 - DEBUG - Requesting: http://10.0.0.57:8082/route-target/37f6fa0f-06c1-4c13-9de2-81c01125c402
2025-11-24 17:42:16,209 - DEBUG - Route Targets: ['target:64512:8000005']
2025-11-24 17:42:16,209 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,219 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:16,232 - INFO - Verified VN network id 7 for VN dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,232 - INFO - Verifications in API Server for VN ctest-vn1-36881456 passed
2025-11-24 17:42:16,232 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,241 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:16,248 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:16,254 - DEBUG - Requesting: http://10.0.0.57:8082/route-target/37f6fa0f-06c1-4c13-9de2-81c01125c402
2025-11-24 17:42:16,269 - DEBUG - Control-node 10.0.0.57 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-FloatingipBasicTestSanity-53988673', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '15875352917199176413', 'uuid-lslong': '12109283258287401739'}, 'enable': 'true', 'created': '2025-11-24T17:42:15', 'last-modified': '2025-11-24T17:42:15', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.400710'}
2025-11-24 17:42:16,275 - DEBUG - Route Targets: ['target:64512:8000005']
2025-11-24 17:42:16,275 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-36881456 passed
2025-11-24 17:42:16,275 - DEBUG - ====Verifying policy data for ctest-vn1-36881456 in API_Server ======
2025-11-24 17:42:16,275 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:16,281 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:16,292 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:16,373 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/dc50955d-f19e-42dd-a80c-d0f736ce2b0b
2025-11-24 17:42:16,384 - DEBUG - =>VN ctest-vn1-36881456 has no policy to be verified
2025-11-24 17:42:16,384 - DEBUG - Verifying the vn in opserver
2025-11-24 17:42:16,384 - DEBUG - Verifying the default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456 virtual network link through opserver 10.0.0.57
2025-11-24 17:42:16,384 - DEBUG - Requesting: http://10.0.0.57:8081/analytics/uves/virtual-networks
2025-11-24 17:42:16,395 - DEBUG - vn link and name as {'name': 'default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456', 'href': 'http://10.0.0.57:8081/analytics/uves/virtual-network/default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456?flat'}
2025-11-24 17:42:16,396 - INFO - Validated that VN default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456 is found in opserver
2025-11-24 17:42:16,405 - DEBUG - Do not have enough data to verify VN in agent
2025-11-24 17:42:16,409 - DEBUG - VRF ids for VN ctest-vn1-36881456: {}
2025-11-24 17:42:17,569 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4811-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4811-1)
2025-11-24 17:42:19,162 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4811-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4811-1)
2025-11-24 17:42:19,361 - INFO - Creating Floating IP pool ctest-some-pool-52407673 in API Server
2025-11-24 17:42:19,621 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:19,629 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:19,640 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:19,753 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:19,774 - DEBUG - Requesting: http://10.0.0.57:8082/floating-ip-pool/0e6a7c7a-73eb-44bc-8c3a-e1e9d09518b9
2025-11-24 17:42:19,786 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:19,795 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:19,811 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:19,922 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-network/316e0d92-b70b-4f1f-a16d-81acb6b102dd
2025-11-24 17:42:19,942 - DEBUG - FIP Pool ctest-some-pool-52407673 found in API Server
2025-11-24 17:42:19,942 - INFO - Verification for FIP pool ctest-some-pool-52407673 in API Server passed
2025-11-24 17:42:19,955 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-52407673 information
2025-11-24 17:42:19,955 - INFO - Verification for FIP pool ctest-some-pool-52407673 in Control-node passed
2025-11-24 17:42:19,955 - INFO - Waiting for VM ctest-vn1_vm1_name-68053404 to be up..
2025-11-24 17:42:20,044 - DEBUG - VM is in ACTIVE state now
2025-11-24 17:42:20,044 - INFO - VM name : ctest-vn1_vm1_name-68053404
2025-11-24 17:42:20,132 - DEBUG - VM ctest-vn1_vm1_name-68053404 ID is 372d0de7-5c25-497f-80c1-f41907961a97
2025-11-24 17:42:20,152 - DEBUG - VM ctest-vn1_vm1_name-68053404 launched on Node cn-jenkins-deploy-platform-ansible-os-4811-1
2025-11-24 17:42:20,233 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-machine/372d0de7-5c25-497f-80c1-f41907961a97
2025-11-24 17:42:20,242 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-machine-interface/f02c402e-fcb4-4332-8a90-3caec63cf041
2025-11-24 17:42:23,466 - 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-11-24 17:42:23,467 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-68053404 failed!
2025-11-24 17:42:23,521 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456 is 120.189.36.129 and allocation pool is NOT set
2025-11-24 17:42:27,565 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms')
2025-11-24 17:42:27,565 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-68053404 failed!
2025-11-24 17:42:27,625 - DEBUG - Gateway for vn default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-vn1-36881456 is 120.189.36.129 and allocation pool is NOT set
2025-11-24 17:42:29,649 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=4.77 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.05 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.051/3.411/4.771/1.360 ms')
2025-11-24 17:42:29,650 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-68053404 passed
2025-11-24 17:42:29,797 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-24 17:42:29,797 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-68053404, IP 120.189.36.131, Port 22
2025-11-24 17:42:29,811 - 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-11-24 17:42:29,896 - DEBUG - VM ctest-vn1_vm1_name-68053404 is NOT ready for SSH connections, VM status: ACTIVE
2025-11-24 17:42:34,898 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-24 17:42:34,898 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-68053404, IP 120.189.36.131, Port 22
2025-11-24 17:42:34,970 - DEBUG - VM ctest-vn1_vm1_name-68053404 is ready for SSH connections
2025-11-24 17:42:35,048 - DEBUG - Created Floating IP : ('71.102.144.68', 'c39ba7c9-d028-4119-9344-e9bc6a9f7d31')
2025-11-24 17:42:35,048 - DEBUG - Associating FIP 71.102.144.68 to 372d0de7-5c25-497f-80c1-f41907961a97
2025-11-24 17:42:35,074 - DEBUG - Associating FIP ID c39ba7c9-d028-4119-9344-e9bc6a9f7d31 with Port ID f02c402e-fcb4-4332-8a90-3caec63cf041
2025-11-24 17:42:35,127 - INFO - Waiting for VM ctest-fvn_vm1_name-55000519 to be up..
2025-11-24 17:42:35,203 - DEBUG - VM is in ACTIVE state now
2025-11-24 17:42:35,203 - INFO - VM name : ctest-fvn_vm1_name-55000519
2025-11-24 17:42:35,277 - DEBUG - VM ctest-fvn_vm1_name-55000519 ID is d2a608e0-d567-42f6-9b73-25dde281634c
2025-11-24 17:42:35,278 - DEBUG - VM ctest-fvn_vm1_name-55000519 launched on Node cn-jenkins-deploy-platform-ansible-os-4811-1
2025-11-24 17:42:35,364 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-machine/d2a608e0-d567-42f6-9b73-25dde281634c
2025-11-24 17:42:35,374 - DEBUG - Requesting: http://10.0.0.57:8082/virtual-machine-interface/10e32e51-d1a3-4ed7-b92f-ac800b31dfe6
2025-11-24 17:42:36,577 - 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.28 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.418 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.418/1.850/3.282/1.432 ms')
2025-11-24 17:42:36,577 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-fvn_vm1_name-55000519 passed
2025-11-24 17:42:36,729 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-24 17:42:36,729 - DEBUG - Waiting to SSH to VM ctest-fvn_vm1_name-55000519, IP 71.102.144.67, Port 22
2025-11-24 17:42:36,798 - DEBUG - VM ctest-fvn_vm1_name-55000519 is ready for SSH connections
2025-11-24 17:42:36,929 - INFO - FIP 71.102.144.68 verification for passed on all Control-nodes
2025-11-24 17:42:36,929 - INFO - FIP ID c39ba7c9-d028-4119-9344-e9bc6a9f7d31(71.102.144.68) validation in Control node passed
2025-11-24 17:42:36,948 - DEBUG - agent_label query returned:{'nh': {'type': 'interface', 'ref_count': '14', 'valid': 'true', 'policy': 'enabled', 'itf': 'tapf02c402e-fc', 'mac': ['2:f0:2c:40:2e:fc'], 'mcast': 'disabled', 'nh_index': '21', '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.130', 'dest_vn_list': ['default-domain:ctest-FloatingipBasicTestSanity-53988673:ctest-fvn-52858623'], 'unresolved': 'false', 'sg_list': ['8000004'], '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-11-24 17:42:36,948 - DEBUG - Route for FIP IP 71.102.144.68 is present in agent 10.0.0.57
2025-11-24 17:42:36,948 - DEBUG - FIP 71.102.144.68 verification for VM ctest-vn1_vm1_name-68053404 in Agent 10.0.0.57 passed
2025-11-24 17:42:36,948 - INFO - FIP ID c39ba7c9-d028-4119-9344-e9bc6a9f7d31(71.102.144.68) validation in agents passed
2025-11-24 17:42:36,948 - DEBUG - Requesting: http://10.0.0.57:8082/floating-ip/c39ba7c9-d028-4119-9344-e9bc6a9f7d31
2025-11-24 17:42:36,957 - DEBUG - FIP c39ba7c9-d028-4119-9344-e9bc6a9f7d31 is present in API server
2025-11-24 17:42:36,957 - INFO - FIP ID c39ba7c9-d028-4119-9344-e9bc6a9f7d31(71.102.144.68) validation in API Server passed
2025-11-24 17:42:36,957 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-24 17:42:36,957 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 71.102.144.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.57, gateway password: c0ntrail123
2025-11-24 17:42:36,958 - DEBUG - ping -s 56 -c 3 -W 1 71.102.144.67
2025-11-24 17:42:40,023 - DEBUG - PING 71.102.144.67 (71.102.144.67): 56 data bytes
64 bytes from 71.102.144.67: seq=0 ttl=63 time=6.926 ms
64 bytes from 71.102.144.67: seq=1 ttl=63 time=0.924 ms
64 bytes from 71.102.144.67: seq=2 ttl=63 time=1.300 ms
--- 71.102.144.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.924/3.050/6.926 ms
2025-11-24 17:42:40,024 - INFO - Ping to IP 71.102.144.67 from VM ctest-vn1_vm1_name-68053404 passed
2025-11-24 17:42:40,024 - DEBUG - Disassociating port from FIP ID : c39ba7c9-d028-4119-9344-e9bc6a9f7d31
2025-11-24 17:42:40,068 - DEBUG - Deleting FIP ID c39ba7c9-d028-4119-9344-e9bc6a9f7d31
2025-11-24 17:42:40,136 - INFO - Deleting the FIP pool ctest-some-pool-52407673
2025-11-24 17:42:40,243 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-52407673 information
2025-11-24 17:42:40,243 - INFO - Deleting VM ctest-fvn_vm1_name-55000519
2025-11-24 17:42:40,313 - INFO - Deleting VM ctest-vn1_vm1_name-68053404
2025-11-24 17:42:40,387 - INFO - Deleting VN ctest-vn1-36881456
2025-11-24 17:42:40,436 - DEBUG - VN dc50955d-f19e-42dd-a80c-d0f736ce2b0b still in use: Unable to complete operation on network dc50955d-f19e-42dd-a80c-d0f736ce2b0b. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-e066a02e-a1ec-421b-8899-eceb55c5ac9b']
2025-11-24 17:42:40,436 - WARNING - Deleting VN ctest-vn1-36881456 failed..Will retry
2025-11-24 17:42:42,553 - DEBUG - Response for deleting network ()
2025-11-24 17:42:42,553 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/56a4f472-8cee-4a61-a733-cf6cb693bb2f
2025-11-24 17:42:42,560 - DEBUG - Response Code: 404
2025-11-24 17:42:42,560 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:42,565 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:42,619 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:42,689 - INFO - Validated that VN ctest-vn1-36881456 is not found in API Server
2025-11-24 17:42:42,698 - DEBUG - VN ctest-vn1-36881456 is not present in Agent 10.0.0.57
2025-11-24 17:42:42,698 - INFO - Validated that VN ctest-vn1-36881456 is not in any agent
2025-11-24 17:42:42,711 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-36881456 info
2025-11-24 17:42:42,711 - INFO - Deleting VN ctest-fvn-52858623
2025-11-24 17:42:42,810 - DEBUG - Response for deleting network ()
2025-11-24 17:42:42,810 - DEBUG - Requesting: http://10.0.0.57:8082/routing-instance/c09a9be1-0186-49b5-9d08-72332c1b4162
2025-11-24 17:42:42,818 - DEBUG - Response Code: 404
2025-11-24 17:42:42,819 - DEBUG - Requesting: http://10.0.0.57:8082/domains
2025-11-24 17:42:42,824 - DEBUG - Requesting: http://10.0.0.57:8082/domain/cd2b91d1-5e8a-4e33-80e4-f7beee2b3706
2025-11-24 17:42:42,878 - DEBUG - Requesting: http://10.0.0.57:8082/project/95529840-e3cc-4134-923f-871dad335be9
2025-11-24 17:42:42,948 - INFO - Validated that VN ctest-fvn-52858623 is not found in API Server
2025-11-24 17:42:42,957 - DEBUG - VN ctest-fvn-52858623 is not present in Agent 10.0.0.57
2025-11-24 17:42:42,957 - INFO - Validated that VN ctest-fvn-52858623 is not in any agent
2025-11-24 17:42:42,970 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-fvn-52858623 info
2025-11-24 17:42:43,233 - DEBUG - No XMPP flaps were noticed during the test
2025-11-24 17:42:43,233 - INFO - END TEST : test_floating_ip : PASSED[0:00:30]
2025-11-24 17:42:43,233 - INFO - --------------------------------------------------------------------------------
2025-11-24 17:42:43,976 - INFO - Deleted project: ctest-FloatingipBasicTestSanity-53988673, ID : 95529840-e3cc-4134-923f-871dad335be9