2026-10-07 19:57:45,503 - INFO - Domain Default found not creating
2026-10-07 19:57:45,676 - INFO - Project ctest-TestRoutersBasic-35698745 not found, creating it
2026-10-07 19:57:46,155 - INFO - Created Project:ctest-TestRoutersBasic-35698745, ID : d8eec2b5-a98b-4062-86f4-c142b9e51d0d
2026-10-07 19:57:47,989 - INFO - ================================================================================
2026-10-07 19:57:47,989 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2026-10-07 19:57:47,989 - 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-10-07 19:57:48,247 - DEBUG - Nothing to compare xmpp stats {'10.0.0.38': {'10.20.0.17': '0'}} with
2026-10-07 19:57:48,247 - INFO - Initial checks done. Running the testcase now
2026-10-07 19:57:48,247 - INFO -
2026-10-07 19:57:49,140 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-35698745
2026-10-07 19:57:49,240 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-35698745
2026-10-07 19:57:49,571 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-35698745', 'default']}
2026-10-07 19:57:49,894 - DEBUG - Response for create_network : {'network': {'id': '77bf5d27-376a-45ce-a166-df7568c147d8', 'name': 'ctest-vn-66162459', 'tenant_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'project_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-35698745', 'ctest-vn-66162459'], 'port_security_enabled': True, 'description': ''}}
2026-10-07 19:57:50,059 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f5fcda6a-8006-4e24-809f-81d721955e3a', 'name': '', 'tenant_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'network_id': '77bf5d27-376a-45ce-a166-df7568c147d8', 'ip_version': 4, 'cidr': '150.43.66.192/26', 'allocation_pools': [{'start': '150.43.66.194', 'end': '150.43.66.254'}], 'gateway_ip': '150.43.66.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '150.43.66.194', 'tags': [], 'project_id': 'd8eec2b5a98b406286f4c142b9e51d0d'}}
2026-10-07 19:57:50,078 - INFO - Created VN ctest-vn-66162459
2026-10-07 19:57:50,132 - DEBUG - VN ctest-vn-66162459 UUID is 77bf5d27-376a-45ce-a166-df7568c147d8
2026-10-07 19:57:50,456 - DEBUG - Response for create_network : {'network': {'id': '15a317f2-31c3-4283-9ff3-1b118579934f', 'name': 'ctest-ext_vn-56479573', 'tenant_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'project_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-35698745', 'ctest-ext_vn-56479573'], 'port_security_enabled': True, 'description': ''}}
2026-10-07 19:57:50,641 - DEBUG - Response for create_subnet : {'subnet': {'id': '520cfb5c-f606-4a8b-a6a4-219a9ad59820', 'name': '', 'tenant_id': 'd8eec2b5a98b406286f4c142b9e51d0d', 'network_id': '15a317f2-31c3-4283-9ff3-1b118579934f', 'ip_version': 4, 'cidr': '162.8.242.0/26', 'allocation_pools': [{'start': '162.8.242.2', 'end': '162.8.242.62'}], 'gateway_ip': '162.8.242.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '162.8.242.2', 'tags': [], 'project_id': 'd8eec2b5a98b406286f4c142b9e51d0d'}}
2026-10-07 19:57:50,659 - INFO - Created VN ctest-ext_vn-56479573
2026-10-07 19:57:50,712 - DEBUG - VN ctest-ext_vn-56479573 UUID is 15a317f2-31c3-4283-9ff3-1b118579934f
2026-10-07 19:57:50,878 - DEBUG - Services list from nova: [, , ]
2026-10-07 19:57:51,244 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6355-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6355-1)
2026-10-07 19:57:51,629 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6355-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6355-1)
2026-10-07 19:57:51,698 - INFO - Setting gateway for router 9c6f40b7-d4d2-4c38-b084-863fb96f0487 to network 15a317f2-31c3-4283-9ff3-1b118579934f
2026-10-07 19:57:51,756 - INFO - Adding interface with subnet_id f5fcda6a-8006-4e24-809f-81d721955e3a, port_id None to router 9c6f40b7-d4d2-4c38-b084-863fb96f0487
2026-10-07 19:57:51,982 - INFO - Waiting for VM ctest-TestRoutersBasic-35698745-28028424 to be up..
2026-10-07 19:57:52,051 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:57:57,139 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:02,229 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:07,316 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:12,464 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:17,551 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:22,640 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:27,728 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 19:58:32,853 - DEBUG - VM is in ACTIVE state now
2026-10-07 19:58:32,854 - INFO - VM name : ctest-TestRoutersBasic-35698745-28028424
2026-10-07 19:58:32,977 - DEBUG - VM ctest-TestRoutersBasic-35698745-28028424 ID is 24a9fa5a-a805-4d67-b8e7-d7c48727c493
2026-10-07 19:58:32,999 - DEBUG - VM ctest-TestRoutersBasic-35698745-28028424 launched on Node cn-jenkins-deploy-platform-ansible-os-6355-1
2026-10-07 19:58:33,094 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/24a9fa5a-a805-4d67-b8e7-d7c48727c493
2026-10-07 19:58:33,462 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/24a9fa5a-a805-4d67-b8e7-d7c48727c493
2026-10-07 19:58:33,495 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/588e8961-c699-48c6-85e3-14c1bba14264
2026-10-07 19:58:36,752 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=5.42 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1009ms\r\nrtt min/avg/max/mdev = 5.415/5.415/5.415/0.000 ms')
2026-10-07 19:58:36,752 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestRoutersBasic-35698745-28028424 passed
2026-10-07 19:58:36,903 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 19:58:36,904 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-35698745-28028424, IP 150.43.66.195, Port 22
2026-10-07 19:58:37,073 - DEBUG - VM ctest-TestRoutersBasic-35698745-28028424 is ready for SSH connections
2026-10-07 19:58:37,073 - INFO - Waiting for VM ctest-TestRoutersBasic-35698745-89091376 to be up..
2026-10-07 19:58:37,160 - DEBUG - VM is in ACTIVE state now
2026-10-07 19:58:37,160 - INFO - VM name : ctest-TestRoutersBasic-35698745-89091376
2026-10-07 19:58:37,247 - DEBUG - VM ctest-TestRoutersBasic-35698745-89091376 ID is 1582fa8e-1554-4c83-a699-308e9b2345f9
2026-10-07 19:58:37,247 - DEBUG - VM ctest-TestRoutersBasic-35698745-89091376 launched on Node cn-jenkins-deploy-platform-ansible-os-6355-1
2026-10-07 19:58:37,332 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/1582fa8e-1554-4c83-a699-308e9b2345f9
2026-10-07 19:58:37,342 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/6d0d5506-f5b2-4a71-a15f-a84492233094
2026-10-07 19:58:38,585 - DEBUG - (True, 'PING 169.254.0.6 (169.254.0.6) 56(84) bytes of data.\r\n64 bytes from 169.254.0.6: icmp_seq=1 ttl=63 time=11.8 ms\r\n64 bytes from 169.254.0.6: icmp_seq=2 ttl=63 time=3.69 ms\r\n\r\n--- 169.254.0.6 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 3.689/7.746/11.804/4.057 ms')
2026-10-07 19:58:38,585 - INFO - Ping to Metadata IP 169.254.0.6 of VM ctest-TestRoutersBasic-35698745-89091376 passed
2026-10-07 19:58:38,740 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 19:58:38,740 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-35698745-89091376, IP 162.8.242.4, Port 22
2026-10-07 19:58:38,806 - DEBUG - Error on ssh to cirros@169.254.0.6:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.6/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.6/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.6/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-07 19:58:38,883 - DEBUG - VM ctest-TestRoutersBasic-35698745-89091376 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-07 19:58:43,884 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 19:58:43,885 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-35698745-89091376, IP 162.8.242.4, Port 22
2026-10-07 19:58:44,053 - DEBUG - VM ctest-TestRoutersBasic-35698745-89091376 is ready for SSH connections
2026-10-07 19:58:44,053 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 19:58:44,053 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 162.8.242.4, host_string: cirros@169.254.0.5, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123
2026-10-07 19:58:44,053 - DEBUG - ping -s 56 -c 3 -W 1 162.8.242.4
2026-10-07 19:58:47,043 - DEBUG - PING 162.8.242.4 (162.8.242.4): 56 data bytes
64 bytes from 162.8.242.4: seq=0 ttl=62 time=6.020 ms
64 bytes from 162.8.242.4: seq=1 ttl=62 time=0.886 ms
64 bytes from 162.8.242.4: seq=2 ttl=62 time=1.276 ms
--- 162.8.242.4 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.886/2.727/6.020 ms
2026-10-07 19:58:47,043 - INFO - Ping to IP 162.8.242.4 from VM ctest-TestRoutersBasic-35698745-28028424 passed
2026-10-07 19:58:47,043 - INFO - Deleting interface with subnet_id f5fcda6a-8006-4e24-809f-81d721955e3a, port_id None from router 9c6f40b7-d4d2-4c38-b084-863fb96f0487
2026-10-07 19:58:47,287 - INFO - Deleting VM ctest-TestRoutersBasic-35698745-89091376
2026-10-07 19:58:47,381 - INFO - Deleting VM ctest-TestRoutersBasic-35698745-28028424
2026-10-07 19:58:47,463 - INFO - Deleting VN ctest-ext_vn-56479573
2026-10-07 19:58:47,539 - DEBUG - VN 15a317f2-31c3-4283-9ff3-1b118579934f still in use: Unable to complete operation on network 15a317f2-31c3-4283-9ff3-1b118579934f. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-04359af7-bcc3-427d-8df0-8df424509fad']
2026-10-07 19:58:47,540 - WARNING - Deleting VN ctest-ext_vn-56479573 failed..Will retry
2026-10-07 19:58:49,699 - DEBUG - Response for deleting network ()
2026-10-07 19:58:49,699 - INFO - Deleting VN ctest-vn-66162459
2026-10-07 19:58:49,802 - DEBUG - Response for deleting network ()
2026-10-07 19:58:50,061 - DEBUG - No XMPP flaps were noticed during the test
2026-10-07 19:58:50,061 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:01:03]
2026-10-07 19:58:50,061 - INFO - --------------------------------------------------------------------------------
2026-10-07 19:58:50,870 - INFO - Deleted project: ctest-TestRoutersBasic-35698745, ID : d8eec2b5-a98b-4062-86f4-c142b9e51d0d