2026-09-28 02:55:03,763 - INFO - Domain Default found not creating
2026-09-28 02:55:04,059 - INFO - Project ctest-TestRoutersBasic-17634747 not found, creating it
2026-09-28 02:55:04,744 - INFO - Created Project:ctest-TestRoutersBasic-17634747, ID : 71496061-bca0-43c3-b752-8ce9720adb38
2026-09-28 02:55:06,827 - INFO - ================================================================================
2026-09-28 02:55:06,827 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2026-09-28 02:55:06,827 - 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-28 02:55:08,169 - DEBUG - Nothing to compare xmpp stats {'10.0.0.38': {'10.20.0.254': '0', '10.20.0.25': '0'}, '10.0.0.162': {'10.20.0.25': '0', '10.20.0.254': '0'}} with
2026-09-28 02:55:08,170 - INFO - Initial checks done. Running the testcase now
2026-09-28 02:55:08,170 - INFO -
2026-09-28 02:55:09,122 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-17634747
2026-09-28 02:55:09,189 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-17634747
2026-09-28 02:55:09,537 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-17634747', 'default']}
2026-09-28 02:55:10,064 - DEBUG - Response for create_network : {'network': {'id': 'b3731909-49ea-4bc3-8286-7a043401be0c', 'name': 'ctest-vn-90761878', 'tenant_id': '71496061bca043c3b7528ce9720adb38', 'project_id': '71496061bca043c3b7528ce9720adb38', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-17634747', 'ctest-vn-90761878'], 'port_security_enabled': True, 'description': ''}}
2026-09-28 02:55:10,437 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd9ab8f9c-1daf-4b32-9921-4770e11467cd', 'name': '', 'tenant_id': '71496061bca043c3b7528ce9720adb38', 'network_id': 'b3731909-49ea-4bc3-8286-7a043401be0c', 'ip_version': 4, 'cidr': '54.220.227.64/26', 'allocation_pools': [{'start': '54.220.227.66', 'end': '54.220.227.126'}], 'gateway_ip': '54.220.227.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '54.220.227.66', 'tags': [], 'project_id': '71496061bca043c3b7528ce9720adb38'}}
2026-09-28 02:55:10,466 - INFO - Created VN ctest-vn-90761878
2026-09-28 02:55:10,484 - DEBUG - VN ctest-vn-90761878 UUID is b3731909-49ea-4bc3-8286-7a043401be0c
2026-09-28 02:55:10,970 - DEBUG - Response for create_network : {'network': {'id': '5e92d374-273c-45e4-99e8-4a0f906cac89', 'name': 'ctest-ext_vn-01452686', 'tenant_id': '71496061bca043c3b7528ce9720adb38', 'project_id': '71496061bca043c3b7528ce9720adb38', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-17634747', 'ctest-ext_vn-01452686'], 'port_security_enabled': True, 'description': ''}}
2026-09-28 02:55:11,226 - DEBUG - Response for create_subnet : {'subnet': {'id': '1659edab-4bf0-4368-a57e-ed706b848dc8', 'name': '', 'tenant_id': '71496061bca043c3b7528ce9720adb38', 'network_id': '5e92d374-273c-45e4-99e8-4a0f906cac89', 'ip_version': 4, 'cidr': '109.189.37.192/26', 'allocation_pools': [{'start': '109.189.37.194', 'end': '109.189.37.254'}], 'gateway_ip': '109.189.37.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '109.189.37.194', 'tags': [], 'project_id': '71496061bca043c3b7528ce9720adb38'}}
2026-09-28 02:55:11,250 - INFO - Created VN ctest-ext_vn-01452686
2026-09-28 02:55:11,266 - DEBUG - VN ctest-ext_vn-01452686 UUID is 5e92d374-273c-45e4-99e8-4a0f906cac89
2026-09-28 02:55:11,453 - DEBUG - Services list from nova: [, , , ]
2026-09-28 02:55:12,026 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6324-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6324-2)
2026-09-28 02:55:12,625 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6324-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6324-1)
2026-09-28 02:55:12,763 - INFO - Setting gateway for router 475bc331-6a05-4804-acf2-ac8f8e97bfd4 to network 5e92d374-273c-45e4-99e8-4a0f906cac89
2026-09-28 02:55:12,877 - INFO - Adding interface with subnet_id d9ab8f9c-1daf-4b32-9921-4770e11467cd, port_id None to router 475bc331-6a05-4804-acf2-ac8f8e97bfd4
2026-09-28 02:55:13,466 - INFO - Waiting for VM ctest-TestRoutersBasic-17634747-71519646 to be up..
2026-09-28 02:55:13,558 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:18,676 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:23,787 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:28,918 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:34,041 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:39,171 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-09-28 02:55:44,277 - DEBUG - VM is in ACTIVE state now
2026-09-28 02:55:44,277 - INFO - VM name : ctest-TestRoutersBasic-17634747-71519646
2026-09-28 02:55:44,394 - DEBUG - VM ctest-TestRoutersBasic-17634747-71519646 ID is 4f2e0ada-e873-412b-8dd8-295878529acb
2026-09-28 02:55:44,429 - DEBUG - VM ctest-TestRoutersBasic-17634747-71519646 launched on Node an-jenkins-deploy-platform-ansible-os-6324-2
2026-09-28 02:55:44,542 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/4f2e0ada-e873-412b-8dd8-295878529acb
2026-09-28 02:55:45,372 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/4f2e0ada-e873-412b-8dd8-295878529acb
2026-09-28 02:55:45,429 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/bf746842-8b89-43e6-959e-9628decbc826
2026-09-28 02:55:46,611 - 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=4.64 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.632 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.632/2.635/4.638/2.003 ms')
2026-09-28 02:55:46,612 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestRoutersBasic-17634747-71519646 passed
2026-09-28 02:55:46,694 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-28 02:55:46,694 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-17634747-71519646, IP 54.220.227.67, Port 22
2026-09-28 02:55:46,858 - DEBUG - VM ctest-TestRoutersBasic-17634747-71519646 is ready for SSH connections
2026-09-28 02:55:46,858 - INFO - Waiting for VM ctest-TestRoutersBasic-17634747-73093144 to be up..
2026-09-28 02:55:46,960 - DEBUG - VM is in ACTIVE state now
2026-09-28 02:55:46,961 - INFO - VM name : ctest-TestRoutersBasic-17634747-73093144
2026-09-28 02:55:47,066 - DEBUG - VM ctest-TestRoutersBasic-17634747-73093144 ID is fce4684e-02c9-46dd-aa2a-3b4853e40b2c
2026-09-28 02:55:47,067 - DEBUG - VM ctest-TestRoutersBasic-17634747-73093144 launched on Node an-jenkins-deploy-platform-ansible-os-6324-1
2026-09-28 02:55:47,163 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/fce4684e-02c9-46dd-aa2a-3b4853e40b2c
2026-09-28 02:55:47,176 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/6fa23994-93ef-46e4-aebd-7bf8c98b57cd
2026-09-28 02:55:48,354 - 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.60 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=1.34 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 = 1.342/3.969/6.597/2.627 ms')
2026-09-28 02:55:48,354 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestRoutersBasic-17634747-73093144 passed
2026-09-28 02:55:48,437 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-28 02:55:48,437 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-17634747-73093144, IP 109.189.37.196, Port 22
2026-09-28 02:55:48,615 - DEBUG - VM ctest-TestRoutersBasic-17634747-73093144 is ready for SSH connections
2026-09-28 02:55:48,616 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-09-28 02:55:48,616 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 109.189.37.196, host_string: cirros@169.254.0.5, password: cubswin:)gateway: ubuntu@10.0.0.162, gateway password: c0ntrail123
2026-09-28 02:55:48,616 - DEBUG - ping -s 56 -c 3 -W 1 109.189.37.196
2026-09-28 02:55:51,658 - DEBUG - PING 109.189.37.196 (109.189.37.196): 56 data bytes
64 bytes from 109.189.37.196: seq=0 ttl=62 time=11.328 ms
64 bytes from 109.189.37.196: seq=1 ttl=62 time=1.649 ms
64 bytes from 109.189.37.196: seq=2 ttl=62 time=1.565 ms
--- 109.189.37.196 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.565/4.847/11.328 ms
2026-09-28 02:55:51,658 - INFO - Ping to IP 109.189.37.196 from VM ctest-TestRoutersBasic-17634747-71519646 passed
2026-09-28 02:55:51,659 - INFO - Deleting interface with subnet_id d9ab8f9c-1daf-4b32-9921-4770e11467cd, port_id None from router 475bc331-6a05-4804-acf2-ac8f8e97bfd4
2026-09-28 02:55:52,161 - INFO - Deleting VM ctest-TestRoutersBasic-17634747-73093144
2026-09-28 02:55:52,347 - INFO - Deleting VM ctest-TestRoutersBasic-17634747-71519646
2026-09-28 02:55:52,563 - INFO - Deleting VN ctest-ext_vn-01452686
2026-09-28 02:55:52,712 - DEBUG - VN 5e92d374-273c-45e4-99e8-4a0f906cac89 still in use: Unable to complete operation on network 5e92d374-273c-45e4-99e8-4a0f906cac89. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-4b89b214-e9fc-4a1f-813e-47c631270a22']
2026-09-28 02:55:52,712 - WARNING - Deleting VN ctest-ext_vn-01452686 failed..Will retry
2026-09-28 02:55:55,037 - DEBUG - Response for deleting network ()
2026-09-28 02:55:55,038 - INFO - Deleting VN ctest-vn-90761878
2026-09-28 02:55:55,296 - DEBUG - Response for deleting network ()
2026-09-28 02:55:56,630 - DEBUG - No XMPP flaps were noticed during the test
2026-09-28 02:55:56,631 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:50]
2026-09-28 02:55:56,631 - INFO - --------------------------------------------------------------------------------
2026-09-28 02:55:57,579 - INFO - Deleted project: ctest-TestRoutersBasic-17634747, ID : 71496061-bca0-43c3-b752-8ce9720adb38