2025-10-13 01:59:50,886 - INFO - Domain Default found not creating
2025-10-13 01:59:51,031 - INFO - Project ctest-TestRoutersBasic-49567074 not found, creating it
2025-10-13 01:59:51,467 - INFO - Created Project:ctest-TestRoutersBasic-49567074, ID : 00b05e22-393b-40b1-aba4-8f2df735b2ed 
2025-10-13 01:59:52,859 - INFO - ================================================================================
2025-10-13 01:59:52,859 - INFO - STARTING TEST    : test_basic_snat_behavior_without_external_connectivity
2025-10-13 01:59:52,859 - 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-10-13 01:59:53,120 - DEBUG - Nothing to compare xmpp stats {'10.0.0.38': {'10.20.0.25': '0'}} with
2025-10-13 01:59:53,120 - INFO - Initial checks done. Running the testcase now
2025-10-13 01:59:53,121 - INFO - 
2025-10-13 01:59:53,813 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-49567074
2025-10-13 01:59:53,908 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-49567074
2025-10-13 01:59:54,224 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-49567074', 'default']}
2025-10-13 01:59:54,500 - DEBUG - Response for create_network : {'network': {'id': 'cd2bc0eb-78cd-4624-8eab-3bc51724eafa', 'name': 'ctest-vn-76301616', 'tenant_id': '00b05e22393b40b1aba48f2df735b2ed', 'project_id': '00b05e22393b40b1aba48f2df735b2ed', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-49567074', 'ctest-vn-76301616'], 'port_security_enabled': True, 'description': ''}}
2025-10-13 01:59:54,671 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b91760b0-165b-485d-8442-6b044a606099', 'name': '', 'tenant_id': '00b05e22393b40b1aba48f2df735b2ed', 'network_id': 'cd2bc0eb-78cd-4624-8eab-3bc51724eafa', 'ip_version': 4, 'cidr': '70.254.112.0/26', 'allocation_pools': [{'start': '70.254.112.2', 'end': '70.254.112.62'}], 'gateway_ip': '70.254.112.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '70.254.112.2', 'tags': [], 'project_id': '00b05e22393b40b1aba48f2df735b2ed'}}
2025-10-13 01:59:54,689 - INFO - Created VN ctest-vn-76301616
2025-10-13 01:59:54,740 - DEBUG - VN ctest-vn-76301616 UUID is cd2bc0eb-78cd-4624-8eab-3bc51724eafa
2025-10-13 01:59:55,043 - DEBUG - Response for create_network : {'network': {'id': '7fdc729f-9d86-4f7e-8ea0-9566f3fc757c', 'name': 'ctest-ext_vn-42950712', 'tenant_id': '00b05e22393b40b1aba48f2df735b2ed', 'project_id': '00b05e22393b40b1aba48f2df735b2ed', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-49567074', 'ctest-ext_vn-42950712'], 'port_security_enabled': True, 'description': ''}}
2025-10-13 01:59:55,241 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd1b424ef-c865-4c1b-af6b-3d315e03b071', 'name': '', 'tenant_id': '00b05e22393b40b1aba48f2df735b2ed', 'network_id': '7fdc729f-9d86-4f7e-8ea0-9566f3fc757c', 'ip_version': 4, 'cidr': '186.184.44.64/26', 'allocation_pools': [{'start': '186.184.44.66', 'end': '186.184.44.126'}], 'gateway_ip': '186.184.44.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '186.184.44.66', 'tags': [], 'project_id': '00b05e22393b40b1aba48f2df735b2ed'}}
2025-10-13 01:59:55,257 - INFO - Created VN ctest-ext_vn-42950712
2025-10-13 01:59:55,308 - DEBUG - VN ctest-ext_vn-42950712 UUID is 7fdc729f-9d86-4f7e-8ea0-9566f3fc757c
2025-10-13 01:59:55,466 - DEBUG - Services list from nova: [, , ]
2025-10-13 01:59:56,493 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4295-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4295-1)
2025-10-13 01:59:57,607 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4295-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4295-1)
2025-10-13 01:59:57,669 - INFO - Setting gateway for router ebe8c397-5235-49ca-b531-96b9a3220858 to network 7fdc729f-9d86-4f7e-8ea0-9566f3fc757c 
2025-10-13 01:59:57,735 - INFO - Adding interface with subnet_id b91760b0-165b-485d-8442-6b044a606099, port_id None to router ebe8c397-5235-49ca-b531-96b9a3220858
2025-10-13 01:59:58,104 - INFO - Waiting for VM ctest-TestRoutersBasic-49567074-95214721 to be up..
2025-10-13 01:59:58,279 - DEBUG - VM  is still in BUILD state, Expected: ACTIVE
2025-10-13 02:00:03,369 - DEBUG - VM  is in ACTIVE state now
2025-10-13 02:00:03,369 - INFO - VM name : ctest-TestRoutersBasic-49567074-95214721
2025-10-13 02:00:03,447 - DEBUG - VM ctest-TestRoutersBasic-49567074-95214721 ID is eb963286-3e52-40e9-b3ab-9051f7450885
2025-10-13 02:00:03,468 - DEBUG - VM ctest-TestRoutersBasic-49567074-95214721 launched on Node cn-jenkins-deploy-platform-ansible-os-4295-1
2025-10-13 02:00:03,546 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/eb963286-3e52-40e9-b3ab-9051f7450885
2025-10-13 02:00:03,847 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/eb963286-3e52-40e9-b3ab-9051f7450885
2025-10-13 02:00:03,878 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/0b907796-0359-4bac-941e-becf8bff08e8
2025-10-13 02:00:07,122 - 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 1002ms')
2025-10-13 02:00:07,122 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-49567074-95214721 failed!
2025-10-13 02:00:07,176 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-49567074:ctest-vn-76301616 is 70.254.112.1 and allocation pool is NOT set
2025-10-13 02:00:09,241 - 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=3.67 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.535 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.535/2.102/3.670/1.567 ms')
2025-10-13 02:00:09,241 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-49567074-95214721 passed
2025-10-13 02:00:09,392 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 02:00:09,393 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-49567074-95214721, IP 70.254.112.3, Port 22
2025-10-13 02:00:09,566 - DEBUG - VM ctest-TestRoutersBasic-49567074-95214721 is ready for SSH connections
2025-10-13 02:00:09,566 - INFO - Waiting for VM ctest-TestRoutersBasic-49567074-83428135 to be up..
2025-10-13 02:00:09,661 - DEBUG - VM  is in ACTIVE state now
2025-10-13 02:00:09,661 - INFO - VM name : ctest-TestRoutersBasic-49567074-83428135
2025-10-13 02:00:09,738 - DEBUG - VM ctest-TestRoutersBasic-49567074-83428135 ID is 6ff8d24c-592b-4ca7-8b53-457ea8bc875a
2025-10-13 02:00:09,738 - DEBUG - VM ctest-TestRoutersBasic-49567074-83428135 launched on Node cn-jenkins-deploy-platform-ansible-os-4295-1
2025-10-13 02:00:09,818 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/6ff8d24c-592b-4ca7-8b53-457ea8bc875a
2025-10-13 02:00:09,827 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/15eb3fee-4a18-43a8-b944-d78976113fdb
2025-10-13 02:00:11,076 - 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.77 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.886 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.886/2.328/3.771/1.442 ms')
2025-10-13 02:00:11,076 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-49567074-83428135 passed
2025-10-13 02:00:11,228 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 02:00:11,228 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-49567074-83428135, IP 186.184.44.67, Port 22
2025-10-13 02:00:11,397 - DEBUG - VM ctest-TestRoutersBasic-49567074-83428135 is ready for SSH connections
2025-10-13 02:00:11,397 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 02:00:11,398 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1  186.184.44.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123
2025-10-13 02:00:11,398 - DEBUG - ping -s 56 -c 3 -W 1  186.184.44.67
2025-10-13 02:00:15,122 - DEBUG - PING 186.184.44.67 (186.184.44.67): 56 data bytes
64 bytes from 186.184.44.67: seq=0 ttl=62 time=8.229 ms
64 bytes from 186.184.44.67: seq=1 ttl=62 time=0.758 ms
64 bytes from 186.184.44.67: seq=2 ttl=62 time=1.005 ms
--- 186.184.44.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.758/3.330/8.229 ms
2025-10-13 02:00:15,122 - INFO - Ping to IP 186.184.44.67 from VM ctest-TestRoutersBasic-49567074-95214721 passed
2025-10-13 02:00:15,122 - INFO - Deleting interface with subnet_id b91760b0-165b-485d-8442-6b044a606099, port_id None from router ebe8c397-5235-49ca-b531-96b9a3220858
2025-10-13 02:00:15,315 - INFO - Deleting VM ctest-TestRoutersBasic-49567074-83428135
2025-10-13 02:00:15,389 - INFO - Deleting VM ctest-TestRoutersBasic-49567074-95214721
2025-10-13 02:00:15,481 - INFO - Deleting VN ctest-ext_vn-42950712 
2025-10-13 02:00:15,561 - DEBUG - VN 7fdc729f-9d86-4f7e-8ea0-9566f3fc757c still in use: Unable to complete operation on network 7fdc729f-9d86-4f7e-8ea0-9566f3fc757c. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-159d357f-2b7b-4bcb-b986-e9dc6cf2c8fe']
2025-10-13 02:00:15,561 - WARNING - Deleting VN ctest-ext_vn-42950712 failed..Will retry
2025-10-13 02:00:17,675 - DEBUG - Response for deleting network ()
2025-10-13 02:00:17,675 - INFO - Deleting VN ctest-vn-76301616 
2025-10-13 02:00:17,764 - DEBUG - Response for deleting network ()
2025-10-13 02:00:18,018 - DEBUG - No XMPP flaps were noticed during the test
2025-10-13 02:00:18,018 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:26]
2025-10-13 02:00:18,018 - INFO - --------------------------------------------------------------------------------
2025-10-13 02:00:18,682 - INFO - Deleted project: ctest-TestRoutersBasic-49567074, ID : 00b05e22-393b-40b1-aba4-8f2df735b2ed