2026-05-18 02:09:45,243 - INFO - Domain Default found not creating
2026-05-18 02:09:45,406 - INFO - Project ctest-TestRoutersBasic-92396033 not found, creating it
2026-05-18 02:09:45,861 - INFO - Created Project:ctest-TestRoutersBasic-92396033, ID : 5759b80a-497a-4fd2-9408-6ebb7017547d
2026-05-18 02:09:47,349 - INFO - ================================================================================
2026-05-18 02:09:47,349 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2026-05-18 02:09:47,349 - 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
2026-05-18 02:09:47,601 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.14': '0'}} with
2026-05-18 02:09:47,601 - INFO - Initial checks done. Running the testcase now
2026-05-18 02:09:47,601 - INFO -
2026-05-18 02:09:48,342 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-92396033
2026-05-18 02:09:48,437 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-92396033
2026-05-18 02:09:48,757 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92396033', 'default']}
2026-05-18 02:09:49,059 - DEBUG - Response for create_network : {'network': {'id': '23c0712f-c304-4bcf-8919-193344ae2e98', 'name': 'ctest-vn-82005619', 'tenant_id': '5759b80a497a4fd294086ebb7017547d', 'project_id': '5759b80a497a4fd294086ebb7017547d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92396033', 'ctest-vn-82005619'], 'port_security_enabled': True, 'description': ''}}
2026-05-18 02:09:49,258 - DEBUG - Response for create_subnet : {'subnet': {'id': 'e53cf551-9c61-4cd5-9396-6a7b1606ac83', 'name': '', 'tenant_id': '5759b80a497a4fd294086ebb7017547d', 'network_id': '23c0712f-c304-4bcf-8919-193344ae2e98', 'ip_version': 4, 'cidr': '111.236.184.0/26', 'allocation_pools': [{'start': '111.236.184.2', 'end': '111.236.184.62'}], 'gateway_ip': '111.236.184.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '111.236.184.2', 'tags': [], 'project_id': '5759b80a497a4fd294086ebb7017547d'}}
2026-05-18 02:09:49,279 - INFO - Created VN ctest-vn-82005619
2026-05-18 02:09:49,329 - DEBUG - VN ctest-vn-82005619 UUID is 23c0712f-c304-4bcf-8919-193344ae2e98
2026-05-18 02:09:49,627 - DEBUG - Response for create_network : {'network': {'id': '50b5823b-7bbb-4b63-8428-0f8166d10ccb', 'name': 'ctest-ext_vn-63522430', 'tenant_id': '5759b80a497a4fd294086ebb7017547d', 'project_id': '5759b80a497a4fd294086ebb7017547d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-92396033', 'ctest-ext_vn-63522430'], 'port_security_enabled': True, 'description': ''}}
2026-05-18 02:09:49,816 - DEBUG - Response for create_subnet : {'subnet': {'id': '41e2557e-bbbc-4405-b9d9-c39979d797dc', 'name': '', 'tenant_id': '5759b80a497a4fd294086ebb7017547d', 'network_id': '50b5823b-7bbb-4b63-8428-0f8166d10ccb', 'ip_version': 4, 'cidr': '222.63.95.0/26', 'allocation_pools': [{'start': '222.63.95.2', 'end': '222.63.95.62'}], 'gateway_ip': '222.63.95.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '222.63.95.2', 'tags': [], 'project_id': '5759b80a497a4fd294086ebb7017547d'}}
2026-05-18 02:09:49,835 - INFO - Created VN ctest-ext_vn-63522430
2026-05-18 02:09:49,885 - DEBUG - VN ctest-ext_vn-63522430 UUID is 50b5823b-7bbb-4b63-8428-0f8166d10ccb
2026-05-18 02:09:50,048 - DEBUG - Services list from nova: [, , ]
2026-05-18 02:09:51,074 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5791-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5791-1)
2026-05-18 02:09:52,220 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5791-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5791-1)
2026-05-18 02:09:52,293 - INFO - Setting gateway for router 09b02ed6-9aab-41c9-a923-6ec05d1c12d6 to network 50b5823b-7bbb-4b63-8428-0f8166d10ccb
2026-05-18 02:09:52,370 - INFO - Adding interface with subnet_id e53cf551-9c61-4cd5-9396-6a7b1606ac83, port_id None to router 09b02ed6-9aab-41c9-a923-6ec05d1c12d6
2026-05-18 02:09:52,798 - INFO - Waiting for VM ctest-TestRoutersBasic-92396033-25931263 to be up..
2026-05-18 02:09:52,938 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-05-18 02:09:58,015 - DEBUG - VM is in ACTIVE state now
2026-05-18 02:09:58,016 - INFO - VM name : ctest-TestRoutersBasic-92396033-25931263
2026-05-18 02:09:58,098 - DEBUG - VM ctest-TestRoutersBasic-92396033-25931263 ID is 2898eaa1-4a14-47dc-b462-be21a8cc227d
2026-05-18 02:09:58,116 - DEBUG - VM ctest-TestRoutersBasic-92396033-25931263 launched on Node cn-jenkins-deploy-platform-ansible-os-5791-1
2026-05-18 02:09:58,194 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/2898eaa1-4a14-47dc-b462-be21a8cc227d
2026-05-18 02:09:58,489 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/2898eaa1-4a14-47dc-b462-be21a8cc227d
2026-05-18 02:09:58,544 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/7d4be6a0-571a-48e3-8190-586485c634a7
2026-05-18 02:10:01,854 - 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')
2026-05-18 02:10:01,854 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-92396033-25931263 failed!
2026-05-18 02:10:01,909 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-92396033:ctest-vn-82005619 is 111.236.184.1 and allocation pool is NOT set
2026-05-18 02:10:03,975 - 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.13 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.94 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 = 2.943/3.535/4.127/0.592 ms')
2026-05-18 02:10:03,975 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-92396033-25931263 passed
2026-05-18 02:10:04,133 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-18 02:10:04,133 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-92396033-25931263, IP 111.236.184.3, Port 22
2026-05-18 02:10:04,188 - 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': ''}
2026-05-18 02:10:04,272 - DEBUG - VM ctest-TestRoutersBasic-92396033-25931263 is NOT ready for SSH connections, VM status: ACTIVE
2026-05-18 02:10:09,273 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-18 02:10:09,273 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-92396033-25931263, IP 111.236.184.3, Port 22
2026-05-18 02:10:09,433 - DEBUG - VM ctest-TestRoutersBasic-92396033-25931263 is ready for SSH connections
2026-05-18 02:10:09,433 - INFO - Waiting for VM ctest-TestRoutersBasic-92396033-41005692 to be up..
2026-05-18 02:10:09,514 - DEBUG - VM is in ACTIVE state now
2026-05-18 02:10:09,514 - INFO - VM name : ctest-TestRoutersBasic-92396033-41005692
2026-05-18 02:10:09,593 - DEBUG - VM ctest-TestRoutersBasic-92396033-41005692 ID is 346ddcb4-50cd-4a38-8829-7b04f3a8f1f3
2026-05-18 02:10:09,593 - DEBUG - VM ctest-TestRoutersBasic-92396033-41005692 launched on Node cn-jenkins-deploy-platform-ansible-os-5791-1
2026-05-18 02:10:09,667 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/346ddcb4-50cd-4a38-8829-7b04f3a8f1f3
2026-05-18 02:10:09,674 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/29c9e60d-2d1e-46d4-8f27-ffcc11887eb6
2026-05-18 02:10:10,906 - 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.02 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.378 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.378/1.700/3.022/1.322 ms')
2026-05-18 02:10:10,906 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-92396033-41005692 passed
2026-05-18 02:10:11,057 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-18 02:10:11,057 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-92396033-41005692, IP 222.63.95.3, Port 22
2026-05-18 02:10:11,212 - DEBUG - VM ctest-TestRoutersBasic-92396033-41005692 is ready for SSH connections
2026-05-18 02:10:11,212 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-18 02:10:11,212 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 222.63.95.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123
2026-05-18 02:10:11,213 - DEBUG - ping -s 56 -c 3 -W 1 222.63.95.3
2026-05-18 02:10:14,937 - DEBUG - PING 222.63.95.3 (222.63.95.3): 56 data bytes
64 bytes from 222.63.95.3: seq=0 ttl=62 time=7.188 ms
64 bytes from 222.63.95.3: seq=1 ttl=62 time=0.902 ms
64 bytes from 222.63.95.3: seq=2 ttl=62 time=0.903 ms
--- 222.63.95.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.902/2.997/7.188 ms
2026-05-18 02:10:14,938 - INFO - Ping to IP 222.63.95.3 from VM ctest-TestRoutersBasic-92396033-25931263 passed
2026-05-18 02:10:14,938 - INFO - Deleting interface with subnet_id e53cf551-9c61-4cd5-9396-6a7b1606ac83, port_id None from router 09b02ed6-9aab-41c9-a923-6ec05d1c12d6
2026-05-18 02:10:15,118 - INFO - Deleting VM ctest-TestRoutersBasic-92396033-41005692
2026-05-18 02:10:15,191 - INFO - Deleting VM ctest-TestRoutersBasic-92396033-25931263
2026-05-18 02:10:15,277 - INFO - Deleting VN ctest-ext_vn-63522430
2026-05-18 02:10:15,352 - DEBUG - VN 50b5823b-7bbb-4b63-8428-0f8166d10ccb still in use: Unable to complete operation on network 50b5823b-7bbb-4b63-8428-0f8166d10ccb. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-5362f7f7-93a2-44e9-bc41-7136793f9ba1']
2026-05-18 02:10:15,352 - WARNING - Deleting VN ctest-ext_vn-63522430 failed..Will retry
2026-05-18 02:10:17,471 - DEBUG - Response for deleting network ()
2026-05-18 02:10:17,471 - INFO - Deleting VN ctest-vn-82005619
2026-05-18 02:10:17,602 - DEBUG - Response for deleting network ()
2026-05-18 02:10:17,857 - DEBUG - No XMPP flaps were noticed during the test
2026-05-18 02:10:17,857 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:30]
2026-05-18 02:10:17,858 - INFO - --------------------------------------------------------------------------------
2026-05-18 02:10:18,554 - INFO - Deleted project: ctest-TestRoutersBasic-92396033, ID : 5759b80a-497a-4fd2-9408-6ebb7017547d