2026-09-17 09:01:54,571 - INFO - Domain Default found not creating
2026-09-17 09:01:54,813 - INFO - Project ctest-TestRoutersBasic-47938695 not found, creating it
2026-09-17 09:01:55,461 - INFO - Created Project:ctest-TestRoutersBasic-47938695, ID : d957037e-0664-4151-b3d5-88f39f8d9578
2026-09-17 09:01:57,378 - INFO - ================================================================================
2026-09-17 09:01:57,378 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2026-09-17 09:01:57,378 - 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-09-17 09:01:57,653 - DEBUG - Nothing to compare xmpp stats {'10.0.0.190': {'10.20.0.25': '0'}} with
2026-09-17 09:01:57,654 - INFO - Initial checks done. Running the testcase now
2026-09-17 09:01:57,654 - INFO -
2026-09-17 09:01:58,504 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-47938695
2026-09-17 09:01:58,606 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-47938695
2026-09-17 09:01:58,966 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-47938695', 'default']}
2026-09-17 09:01:59,526 - DEBUG - Response for create_network : {'network': {'id': 'f7677acd-5ae7-4b68-a79a-d4c880f118df', 'name': 'ctest-vn-19017381', 'tenant_id': 'd957037e06644151b3d588f39f8d9578', 'project_id': 'd957037e06644151b3d588f39f8d9578', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-47938695', 'ctest-vn-19017381'], 'port_security_enabled': True, 'description': ''}}
2026-09-17 09:01:59,865 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b4110a1e-33ca-4bf2-976d-192dbce570b2', 'name': '', 'tenant_id': 'd957037e06644151b3d588f39f8d9578', 'network_id': 'f7677acd-5ae7-4b68-a79a-d4c880f118df', 'ip_version': 4, 'cidr': '43.167.81.0/26', 'allocation_pools': [{'start': '43.167.81.2', 'end': '43.167.81.62'}], 'gateway_ip': '43.167.81.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '43.167.81.2', 'tags': [], 'project_id': 'd957037e06644151b3d588f39f8d9578'}}
2026-09-17 09:01:59,889 - INFO - Created VN ctest-vn-19017381
2026-09-17 09:01:59,950 - DEBUG - VN ctest-vn-19017381 UUID is f7677acd-5ae7-4b68-a79a-d4c880f118df
2026-09-17 09:02:00,360 - DEBUG - Response for create_network : {'network': {'id': '64527753-4e1d-43eb-8166-7d16b7bf7c4e', 'name': 'ctest-ext_vn-31262241', 'tenant_id': 'd957037e06644151b3d588f39f8d9578', 'project_id': 'd957037e06644151b3d588f39f8d9578', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-47938695', 'ctest-ext_vn-31262241'], 'port_security_enabled': True, 'description': ''}}
2026-09-17 09:02:00,552 - DEBUG - Response for create_subnet : {'subnet': {'id': '83b2b5a5-f5c3-459a-b902-5018dbc59508', 'name': '', 'tenant_id': 'd957037e06644151b3d588f39f8d9578', 'network_id': '64527753-4e1d-43eb-8166-7d16b7bf7c4e', 'ip_version': 4, 'cidr': '200.66.83.64/26', 'allocation_pools': [{'start': '200.66.83.66', 'end': '200.66.83.126'}], 'gateway_ip': '200.66.83.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '200.66.83.66', 'tags': [], 'project_id': 'd957037e06644151b3d588f39f8d9578'}}
2026-09-17 09:02:00,568 - INFO - Created VN ctest-ext_vn-31262241
2026-09-17 09:02:00,622 - DEBUG - VN ctest-ext_vn-31262241 UUID is 64527753-4e1d-43eb-8166-7d16b7bf7c4e
2026-09-17 09:02:00,811 - DEBUG - Services list from nova: [, , ]
2026-09-17 09:02:01,182 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6297-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6297-1)
2026-09-17 09:02:01,581 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6297-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6297-1)
2026-09-17 09:02:01,685 - INFO - Setting gateway for router cc6debc2-19c6-4a90-85a0-5564d4fabede to network 64527753-4e1d-43eb-8166-7d16b7bf7c4e
2026-09-17 09:02:01,755 - INFO - Adding interface with subnet_id b4110a1e-33ca-4bf2-976d-192dbce570b2, port_id None to router cc6debc2-19c6-4a90-85a0-5564d4fabede
2026-09-17 09:02:02,149 - INFO - Waiting for VM ctest-TestRoutersBasic-47938695-99699056 to be up..
2026-09-17 09:02:02,228 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:07,403 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:12,495 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:17,591 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:22,677 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:27,757 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:32,858 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:37,956 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-17 09:02:43,058 - DEBUG - VM is in ACTIVE state now
2026-09-17 09:02:43,059 - INFO - VM name : ctest-TestRoutersBasic-47938695-99699056
2026-09-17 09:02:43,161 - DEBUG - VM ctest-TestRoutersBasic-47938695-99699056 ID is dc3224a2-7961-4eb2-b427-6df4cf580dae
2026-09-17 09:02:43,197 - DEBUG - VM ctest-TestRoutersBasic-47938695-99699056 launched on Node cn-jenkins-deploy-platform-ansible-os-6297-1
2026-09-17 09:02:43,291 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/dc3224a2-7961-4eb2-b427-6df4cf580dae
2026-09-17 09:02:43,625 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/dc3224a2-7961-4eb2-b427-6df4cf580dae
2026-09-17 09:02:43,667 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine-interface/ca97bf83-ebb2-4bae-a0ee-b5cc05469aa8
2026-09-17 09:02:46,942 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1032ms')
2026-09-17 09:02:46,942 - DEBUG - Ping to Metadata IP 169.254.0.5 of VM ctest-TestRoutersBasic-47938695-99699056 failed!
2026-09-17 09:02:47,002 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-47938695:ctest-vn-19017381 is 43.167.81.1 and allocation pool is NOT set
2026-09-17 09:02:49,072 - 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=1 ttl=63 time=6.65 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=2.71 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.712/4.681/6.650/1.969 ms')
2026-09-17 09:02:49,072 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestRoutersBasic-47938695-99699056 passed
2026-09-17 09:02:49,226 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-17 09:02:49,226 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-47938695-99699056, IP 43.167.81.3, Port 22
2026-09-17 09:02:49,293 - DEBUG - Error on ssh to cirros@169.254.0.5:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.5/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.5/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.5/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-09-17 09:02:49,380 - DEBUG - VM ctest-TestRoutersBasic-47938695-99699056 is NOT ready for SSH connections, VM status: ACTIVE
2026-09-17 09:02:54,380 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-17 09:02:54,380 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-47938695-99699056, IP 43.167.81.3, Port 22
2026-09-17 09:02:54,545 - DEBUG - VM ctest-TestRoutersBasic-47938695-99699056 is ready for SSH connections
2026-09-17 09:02:54,545 - INFO - Waiting for VM ctest-TestRoutersBasic-47938695-32891893 to be up..
2026-09-17 09:02:54,638 - DEBUG - VM is in ACTIVE state now
2026-09-17 09:02:54,638 - INFO - VM name : ctest-TestRoutersBasic-47938695-32891893
2026-09-17 09:02:54,727 - DEBUG - VM ctest-TestRoutersBasic-47938695-32891893 ID is 1cf68753-6895-45d1-a3cc-7fac1cbc73d8
2026-09-17 09:02:54,728 - DEBUG - VM ctest-TestRoutersBasic-47938695-32891893 launched on Node cn-jenkins-deploy-platform-ansible-os-6297-1
2026-09-17 09:02:54,806 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/1cf68753-6895-45d1-a3cc-7fac1cbc73d8
2026-09-17 09:02:54,816 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine-interface/c59f0dcb-f4db-4e68-8129-1908e11909ac
2026-09-17 09:02:56,061 - 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=3.76 ms\r\n64 bytes from 169.254.0.6: icmp_seq=2 ttl=63 time=0.566 ms\r\n\r\n--- 169.254.0.6 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.566/2.163/3.761/1.597 ms')
2026-09-17 09:02:56,061 - INFO - Ping to Metadata IP 169.254.0.6 of VM ctest-TestRoutersBasic-47938695-32891893 passed
2026-09-17 09:02:56,214 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-17 09:02:56,214 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-47938695-32891893, IP 200.66.83.68, Port 22
2026-09-17 09:02:56,384 - DEBUG - VM ctest-TestRoutersBasic-47938695-32891893 is ready for SSH connections
2026-09-17 09:02:56,384 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-17 09:02:56,385 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 200.66.83.68, host_string: cirros@169.254.0.5, password: cubswin:)gateway: ubuntu@10.0.0.190, gateway password: c0ntrail123
2026-09-17 09:02:56,385 - DEBUG - ping -s 56 -c 3 -W 1 200.66.83.68
2026-09-17 09:02:59,499 - DEBUG - PING 200.66.83.68 (200.66.83.68): 56 data bytes
64 bytes from 200.66.83.68: seq=0 ttl=62 time=6.066 ms
64 bytes from 200.66.83.68: seq=1 ttl=62 time=1.643 ms
64 bytes from 200.66.83.68: seq=2 ttl=62 time=1.142 ms
--- 200.66.83.68 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.142/2.950/6.066 ms
2026-09-17 09:02:59,500 - INFO - Ping to IP 200.66.83.68 from VM ctest-TestRoutersBasic-47938695-99699056 passed
2026-09-17 09:02:59,500 - INFO - Deleting interface with subnet_id b4110a1e-33ca-4bf2-976d-192dbce570b2, port_id None from router cc6debc2-19c6-4a90-85a0-5564d4fabede
2026-09-17 09:02:59,794 - INFO - Deleting VM ctest-TestRoutersBasic-47938695-32891893
2026-09-17 09:02:59,870 - INFO - Deleting VM ctest-TestRoutersBasic-47938695-99699056
2026-09-17 09:02:59,971 - INFO - Deleting VN ctest-ext_vn-31262241
2026-09-17 09:03:00,061 - DEBUG - VN 64527753-4e1d-43eb-8166-7d16b7bf7c4e still in use: Unable to complete operation on network 64527753-4e1d-43eb-8166-7d16b7bf7c4e. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-aefc8da8-9244-4d77-84d7-34891c66ed8f']
2026-09-17 09:03:00,061 - WARNING - Deleting VN ctest-ext_vn-31262241 failed..Will retry
2026-09-17 09:03:02,293 - DEBUG - Response for deleting network ()
2026-09-17 09:03:02,294 - INFO - Deleting VN ctest-vn-19017381
2026-09-17 09:03:02,436 - DEBUG - Response for deleting network ()
2026-09-17 09:03:02,712 - DEBUG - No XMPP flaps were noticed during the test
2026-09-17 09:03:02,712 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:01:05]
2026-09-17 09:03:02,712 - INFO - --------------------------------------------------------------------------------
2026-09-17 09:03:03,526 - INFO - Deleted project: ctest-TestRoutersBasic-47938695, ID : d957037e-0664-4151-b3d5-88f39f8d9578