2025-04-28 02:04:10,509 - INFO - Domain Default found not creating
2025-04-28 02:04:10,647 - INFO - Project ctest-TestRoutersBasic-76644782 not found, creating it
2025-04-28 02:04:11,113 - INFO - Created Project:ctest-TestRoutersBasic-76644782, ID : 4e875dd8-10bb-48ca-aa37-4216bf0809dd
2025-04-28 02:04:12,498 - INFO - ================================================================================
2025-04-28 02:04:12,498 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2025-04-28 02:04:12,498 - INFO - TEST DESCRIPTION : Create an external network, a router
set router-gateway to external network
launch a private network and attach it to router
validate left vm pinging right vm through Snat
2025-04-28 02:04:12,760 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.14': '0'}} with
2025-04-28 02:04:12,760 - INFO - Initial checks done. Running the testcase now
2025-04-28 02:04:12,760 - INFO -
2025-04-28 02:04:13,443 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-76644782
2025-04-28 02:04:13,543 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-76644782
2025-04-28 02:04:13,867 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-76644782', 'default']}
2025-04-28 02:04:14,148 - DEBUG - Response for create_network : {'network': {'id': 'fc912928-c19b-4d19-8f44-6fbf4063dd56', 'name': 'ctest-vn-82800107', 'tenant_id': '4e875dd810bb48caaa374216bf0809dd', 'project_id': '4e875dd810bb48caaa374216bf0809dd', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-76644782', 'ctest-vn-82800107'], 'port_security_enabled': True, 'description': ''}}
2025-04-28 02:04:14,307 - DEBUG - Response for create_subnet : {'subnet': {'id': '96f03a97-30cc-4de4-ae99-dce6c98abd68', 'name': '', 'tenant_id': '4e875dd810bb48caaa374216bf0809dd', 'network_id': 'fc912928-c19b-4d19-8f44-6fbf4063dd56', 'ip_version': 4, 'cidr': '86.11.142.128/26', 'allocation_pools': [{'start': '86.11.142.130', 'end': '86.11.142.190'}], 'gateway_ip': '86.11.142.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '86.11.142.130', 'tags': [], 'project_id': '4e875dd810bb48caaa374216bf0809dd'}}
2025-04-28 02:04:14,327 - INFO - Created VN ctest-vn-82800107
2025-04-28 02:04:14,384 - DEBUG - VN ctest-vn-82800107 UUID is fc912928-c19b-4d19-8f44-6fbf4063dd56
2025-04-28 02:04:14,724 - DEBUG - Response for create_network : {'network': {'id': '6ed5464e-e1a0-4c3a-8d18-09f92cc1931f', 'name': 'ctest-ext_vn-41126471', 'tenant_id': '4e875dd810bb48caaa374216bf0809dd', 'project_id': '4e875dd810bb48caaa374216bf0809dd', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-76644782', 'ctest-ext_vn-41126471'], 'port_security_enabled': True, 'description': ''}}
2025-04-28 02:04:14,927 - DEBUG - Response for create_subnet : {'subnet': {'id': '8fc7f527-83d2-49bc-8165-fab3643e61d9', 'name': '', 'tenant_id': '4e875dd810bb48caaa374216bf0809dd', 'network_id': '6ed5464e-e1a0-4c3a-8d18-09f92cc1931f', 'ip_version': 4, 'cidr': '120.60.142.192/26', 'allocation_pools': [{'start': '120.60.142.194', 'end': '120.60.142.254'}], 'gateway_ip': '120.60.142.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '120.60.142.194', 'tags': [], 'project_id': '4e875dd810bb48caaa374216bf0809dd'}}
2025-04-28 02:04:14,947 - INFO - Created VN ctest-ext_vn-41126471
2025-04-28 02:04:14,999 - DEBUG - VN ctest-ext_vn-41126471 UUID is 6ed5464e-e1a0-4c3a-8d18-09f92cc1931f
2025-04-28 02:04:15,166 - DEBUG - Services list from nova: [, , ]
2025-04-28 02:04:16,330 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3230-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3230-1)
2025-04-28 02:04:17,505 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3230-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3230-1)
2025-04-28 02:04:17,579 - INFO - Setting gateway for router 96ba92f4-b817-49b0-8eae-346ad0857151 to network 6ed5464e-e1a0-4c3a-8d18-09f92cc1931f
2025-04-28 02:04:17,676 - INFO - Adding interface with subnet_id 96f03a97-30cc-4de4-ae99-dce6c98abd68, port_id None to router 96ba92f4-b817-49b0-8eae-346ad0857151
2025-04-28 02:04:18,094 - INFO - Waiting for VM ctest-TestRoutersBasic-76644782-58670288 to be up..
2025-04-28 02:04:18,315 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-04-28 02:04:23,394 - DEBUG - VM is in ACTIVE state now
2025-04-28 02:04:23,394 - INFO - VM name : ctest-TestRoutersBasic-76644782-58670288
2025-04-28 02:04:23,466 - DEBUG - VM ctest-TestRoutersBasic-76644782-58670288 ID is 3a358bc5-b927-46c5-82a5-1509cf3083bd
2025-04-28 02:04:23,487 - DEBUG - VM ctest-TestRoutersBasic-76644782-58670288 launched on Node cn-jenkins-deploy-platform-ansible-os-3230-1
2025-04-28 02:04:23,561 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/3a358bc5-b927-46c5-82a5-1509cf3083bd
2025-04-28 02:04:23,854 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/3a358bc5-b927-46c5-82a5-1509cf3083bd
2025-04-28 02:04:23,884 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/2a1df559-406c-4ee8-ade3-fe5a1cdcc6eb
2025-04-28 02:04:27,160 - 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-04-28 02:04:27,161 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-76644782-58670288 failed!
2025-04-28 02:04:27,216 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-76644782:ctest-vn-82800107 is 86.11.142.129 and allocation pool is NOT set
2025-04-28 02:04:29,279 - 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.45 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.447 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.447/1.948/3.450/1.501 ms')
2025-04-28 02:04:29,279 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-76644782-58670288 passed
2025-04-28 02:04:29,439 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-04-28 02:04:29,439 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-76644782-58670288, IP 86.11.142.131, Port 22
2025-04-28 02:04:29,603 - DEBUG - VM ctest-TestRoutersBasic-76644782-58670288 is ready for SSH connections
2025-04-28 02:04:29,603 - INFO - Waiting for VM ctest-TestRoutersBasic-76644782-97090593 to be up..
2025-04-28 02:04:29,681 - DEBUG - VM is in ACTIVE state now
2025-04-28 02:04:29,682 - INFO - VM name : ctest-TestRoutersBasic-76644782-97090593
2025-04-28 02:04:29,757 - DEBUG - VM ctest-TestRoutersBasic-76644782-97090593 ID is 8e47dd87-8c61-46ad-b2cd-e09a8f2e679d
2025-04-28 02:04:29,757 - DEBUG - VM ctest-TestRoutersBasic-76644782-97090593 launched on Node cn-jenkins-deploy-platform-ansible-os-3230-1
2025-04-28 02:04:29,830 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/8e47dd87-8c61-46ad-b2cd-e09a8f2e679d
2025-04-28 02:04:29,839 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/e28b9f31-23b3-4b99-9875-faddc76eac96
2025-04-28 02:04:31,074 - 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=2.75 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.374 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.374/1.563/2.753/1.189 ms')
2025-04-28 02:04:31,074 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-76644782-97090593 passed
2025-04-28 02:04:31,227 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-04-28 02:04:31,228 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-76644782-97090593, IP 120.60.142.195, Port 22
2025-04-28 02:04:31,383 - DEBUG - VM ctest-TestRoutersBasic-76644782-97090593 is ready for SSH connections
2025-04-28 02:04:31,384 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-04-28 02:04:31,384 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 120.60.142.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-04-28 02:04:31,384 - DEBUG - ping -s 56 -c 3 -W 1 120.60.142.195
2025-04-28 02:04:35,332 - DEBUG - PING 120.60.142.195 (120.60.142.195): 56 data bytes
64 bytes from 120.60.142.195: seq=0 ttl=62 time=4.813 ms
64 bytes from 120.60.142.195: seq=1 ttl=62 time=1.018 ms
64 bytes from 120.60.142.195: seq=2 ttl=62 time=0.771 ms
--- 120.60.142.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.771/2.200/4.813 ms
2025-04-28 02:04:35,332 - INFO - Ping to IP 120.60.142.195 from VM ctest-TestRoutersBasic-76644782-58670288 passed
2025-04-28 02:04:35,332 - INFO - Deleting interface with subnet_id 96f03a97-30cc-4de4-ae99-dce6c98abd68, port_id None from router 96ba92f4-b817-49b0-8eae-346ad0857151
2025-04-28 02:04:35,532 - INFO - Deleting VM ctest-TestRoutersBasic-76644782-97090593
2025-04-28 02:04:35,605 - INFO - Deleting VM ctest-TestRoutersBasic-76644782-58670288
2025-04-28 02:04:35,698 - INFO - Deleting VN ctest-ext_vn-41126471
2025-04-28 02:04:35,769 - DEBUG - VN 6ed5464e-e1a0-4c3a-8d18-09f92cc1931f still in use: Unable to complete operation on network 6ed5464e-e1a0-4c3a-8d18-09f92cc1931f. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-efb50544-1db4-4415-a5b4-8de562fabb70']
2025-04-28 02:04:35,769 - WARNING - Deleting VN ctest-ext_vn-41126471 failed..Will retry
2025-04-28 02:04:37,870 - DEBUG - Response for deleting network ()
2025-04-28 02:04:37,870 - INFO - Deleting VN ctest-vn-82800107
2025-04-28 02:04:37,976 - DEBUG - Response for deleting network ()
2025-04-28 02:04:38,230 - DEBUG - No XMPP flaps were noticed during the test
2025-04-28 02:04:38,230 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:26]
2025-04-28 02:04:38,230 - INFO - --------------------------------------------------------------------------------
2025-04-28 02:04:38,910 - INFO - Deleted project: ctest-TestRoutersBasic-76644782, ID : 4e875dd8-10bb-48ca-aa37-4216bf0809dd