2025-07-16 14:56:03,182 - INFO - Domain Default found not creating
2025-07-16 14:56:03,339 - INFO - Project ctest-TestRoutersBasic-92189318 not found, creating it
2025-07-16 14:56:03,799 - INFO - Created Project:ctest-TestRoutersBasic-92189318, ID : 537f4b76-f389-4d73-b054-c4b3cb125d39
2025-07-16 14:56:05,303 - INFO - ================================================================================
2025-07-16 14:56:05,303 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2025-07-16 14:56:05,303 - 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-07-16 14:56:05,572 - DEBUG - Nothing to compare xmpp stats {'10.0.0.241': {'10.20.0.129': '0'}} with
2025-07-16 14:56:05,572 - INFO - Initial checks done. Running the testcase now
2025-07-16 14:56:05,572 - INFO -
2025-07-16 14:56:06,291 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-92189318
2025-07-16 14:56:06,385 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-92189318
2025-07-16 14:56:06,712 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92189318', 'default']}
2025-07-16 14:56:07,031 - DEBUG - Response for create_network : {'network': {'id': '91ac5fa4-28cf-4920-af70-0cca40ff11eb', 'name': 'ctest-vn-52126333', 'tenant_id': '537f4b76f3894d73b054c4b3cb125d39', 'project_id': '537f4b76f3894d73b054c4b3cb125d39', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92189318', 'ctest-vn-52126333'], 'port_security_enabled': True, 'description': ''}}
2025-07-16 14:56:07,203 - DEBUG - Response for create_subnet : {'subnet': {'id': '7b8d948c-e406-423a-b4e3-5f0c8d3022e4', 'name': '', 'tenant_id': '537f4b76f3894d73b054c4b3cb125d39', 'network_id': '91ac5fa4-28cf-4920-af70-0cca40ff11eb', 'ip_version': 4, 'cidr': '206.217.227.128/26', 'allocation_pools': [{'start': '206.217.227.130', 'end': '206.217.227.190'}], 'gateway_ip': '206.217.227.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '206.217.227.130', 'tags': [], 'project_id': '537f4b76f3894d73b054c4b3cb125d39'}}
2025-07-16 14:56:07,223 - INFO - Created VN ctest-vn-52126333
2025-07-16 14:56:07,277 - DEBUG - VN ctest-vn-52126333 UUID is 91ac5fa4-28cf-4920-af70-0cca40ff11eb
2025-07-16 14:56:07,601 - DEBUG - Response for create_network : {'network': {'id': '610d31f3-8bdf-42f7-8e76-bfeb48b08307', 'name': 'ctest-ext_vn-35574047', 'tenant_id': '537f4b76f3894d73b054c4b3cb125d39', 'project_id': '537f4b76f3894d73b054c4b3cb125d39', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92189318', 'ctest-ext_vn-35574047'], 'port_security_enabled': True, 'description': ''}}
2025-07-16 14:56:07,832 - DEBUG - Response for create_subnet : {'subnet': {'id': '039d4d32-622b-4c81-bff4-dedec8754b34', 'name': '', 'tenant_id': '537f4b76f3894d73b054c4b3cb125d39', 'network_id': '610d31f3-8bdf-42f7-8e76-bfeb48b08307', 'ip_version': 4, 'cidr': '66.40.200.64/26', 'allocation_pools': [{'start': '66.40.200.66', 'end': '66.40.200.126'}], 'gateway_ip': '66.40.200.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '66.40.200.66', 'tags': [], 'project_id': '537f4b76f3894d73b054c4b3cb125d39'}}
2025-07-16 14:56:07,855 - INFO - Created VN ctest-ext_vn-35574047
2025-07-16 14:56:07,909 - DEBUG - VN ctest-ext_vn-35574047 UUID is 610d31f3-8bdf-42f7-8e76-bfeb48b08307
2025-07-16 14:56:08,122 - DEBUG - Services list from nova: [, , ]
2025-07-16 14:56:09,270 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3644-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3644-1)
2025-07-16 14:56:10,413 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3644-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3644-1)
2025-07-16 14:56:10,500 - INFO - Setting gateway for router de260eea-cdf3-4dcd-84e7-3cd8f9ebebb2 to network 610d31f3-8bdf-42f7-8e76-bfeb48b08307
2025-07-16 14:56:10,587 - INFO - Adding interface with subnet_id 7b8d948c-e406-423a-b4e3-5f0c8d3022e4, port_id None to router de260eea-cdf3-4dcd-84e7-3cd8f9ebebb2
2025-07-16 14:56:11,065 - INFO - Waiting for VM ctest-TestRoutersBasic-92189318-62952878 to be up..
2025-07-16 14:56:11,291 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-07-16 14:56:16,369 - DEBUG - VM is in ACTIVE state now
2025-07-16 14:56:16,369 - INFO - VM name : ctest-TestRoutersBasic-92189318-62952878
2025-07-16 14:56:16,440 - DEBUG - VM ctest-TestRoutersBasic-92189318-62952878 ID is 6727afbf-9c21-4ac1-8cfa-5e4b61a8cba0
2025-07-16 14:56:16,458 - DEBUG - VM ctest-TestRoutersBasic-92189318-62952878 launched on Node cn-jenkins-deploy-platform-ansible-os-3644-1
2025-07-16 14:56:16,529 - DEBUG - Requesting: http://10.0.0.241:8082/virtual-machine/6727afbf-9c21-4ac1-8cfa-5e4b61a8cba0
2025-07-16 14:56:16,836 - DEBUG - Requesting: http://10.0.0.241:8082/virtual-machine/6727afbf-9c21-4ac1-8cfa-5e4b61a8cba0
2025-07-16 14:56:16,865 - DEBUG - Requesting: http://10.0.0.241:8082/virtual-machine-interface/cfc7c91b-23ba-48ce-93e4-361f4001a0a7
2025-07-16 14:56:20,120 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1011ms')
2025-07-16 14:56:20,120 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-92189318-62952878 failed!
2025-07-16 14:56:20,181 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-92189318:ctest-vn-52126333 is 206.217.227.129 and allocation pool is NOT set
2025-07-16 14:56:22,248 - 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=2.62 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.422 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.422/1.520/2.618/1.098 ms')
2025-07-16 14:56:22,248 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-92189318-62952878 passed
2025-07-16 14:56:22,425 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-16 14:56:22,425 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-92189318-62952878, IP 206.217.227.131, Port 22
2025-07-16 14:56:22,577 - DEBUG - VM ctest-TestRoutersBasic-92189318-62952878 is ready for SSH connections
2025-07-16 14:56:22,577 - INFO - Waiting for VM ctest-TestRoutersBasic-92189318-08058713 to be up..
2025-07-16 14:56:22,677 - DEBUG - VM is in ACTIVE state now
2025-07-16 14:56:22,677 - INFO - VM name : ctest-TestRoutersBasic-92189318-08058713
2025-07-16 14:56:22,765 - DEBUG - VM ctest-TestRoutersBasic-92189318-08058713 ID is f4213101-266a-49a8-8147-2a26cf092e34
2025-07-16 14:56:22,765 - DEBUG - VM ctest-TestRoutersBasic-92189318-08058713 launched on Node cn-jenkins-deploy-platform-ansible-os-3644-1
2025-07-16 14:56:22,847 - DEBUG - Requesting: http://10.0.0.241:8082/virtual-machine/f4213101-266a-49a8-8147-2a26cf092e34
2025-07-16 14:56:22,857 - DEBUG - Requesting: http://10.0.0.241:8082/virtual-machine-interface/0591db93-9af0-4d5f-a54b-229f8f241159
2025-07-16 14:56:24,098 - 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.93 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.429 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 0.429/1.681/2.933/1.252 ms')
2025-07-16 14:56:24,098 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-92189318-08058713 passed
2025-07-16 14:56:24,249 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-16 14:56:24,249 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-92189318-08058713, IP 66.40.200.67, Port 22
2025-07-16 14:56:24,414 - DEBUG - VM ctest-TestRoutersBasic-92189318-08058713 is ready for SSH connections
2025-07-16 14:56:24,415 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-16 14:56:24,415 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 66.40.200.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.241, gateway password: c0ntrail123
2025-07-16 14:56:24,415 - DEBUG - ping -s 56 -c 3 -W 1 66.40.200.67
2025-07-16 14:56:28,089 - DEBUG - PING 66.40.200.67 (66.40.200.67): 56 data bytes
64 bytes from 66.40.200.67: seq=0 ttl=62 time=4.455 ms
64 bytes from 66.40.200.67: seq=1 ttl=62 time=0.883 ms
64 bytes from 66.40.200.67: seq=2 ttl=62 time=1.082 ms
--- 66.40.200.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.883/2.140/4.455 ms
2025-07-16 14:56:28,090 - INFO - Ping to IP 66.40.200.67 from VM ctest-TestRoutersBasic-92189318-62952878 passed
2025-07-16 14:56:28,090 - INFO - Deleting interface with subnet_id 7b8d948c-e406-423a-b4e3-5f0c8d3022e4, port_id None from router de260eea-cdf3-4dcd-84e7-3cd8f9ebebb2
2025-07-16 14:56:28,291 - INFO - Deleting VM ctest-TestRoutersBasic-92189318-08058713
2025-07-16 14:56:28,370 - INFO - Deleting VM ctest-TestRoutersBasic-92189318-62952878
2025-07-16 14:56:28,450 - INFO - Deleting VN ctest-ext_vn-35574047
2025-07-16 14:56:28,534 - DEBUG - VN 610d31f3-8bdf-42f7-8e76-bfeb48b08307 still in use: Unable to complete operation on network 610d31f3-8bdf-42f7-8e76-bfeb48b08307. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-c84f93dd-28c1-48cd-b9a6-188bc2d0a657']
2025-07-16 14:56:28,534 - WARNING - Deleting VN ctest-ext_vn-35574047 failed..Will retry
2025-07-16 14:56:30,647 - DEBUG - Response for deleting network ()
2025-07-16 14:56:30,647 - INFO - Deleting VN ctest-vn-52126333
2025-07-16 14:56:30,754 - DEBUG - Response for deleting network ()
2025-07-16 14:56:31,015 - DEBUG - No XMPP flaps were noticed during the test
2025-07-16 14:56:31,015 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:26]
2025-07-16 14:56:31,015 - INFO - --------------------------------------------------------------------------------
2025-07-16 14:56:31,706 - INFO - Deleted project: ctest-TestRoutersBasic-92189318, ID : 537f4b76-f389-4d73-b054-c4b3cb125d39