2025-10-13 20:56:02,662 - INFO - Domain Default found not creating
2025-10-13 20:56:02,794 - INFO - Project ctest-TestRoutersBasic-04094725 not found, creating it
2025-10-13 20:56:03,227 - INFO - Created Project:ctest-TestRoutersBasic-04094725, ID : a8c80145-9326-42e1-a29f-567ee031c9ed 
2025-10-13 20:56:04,571 - INFO - ================================================================================
2025-10-13 20:56:04,571 - INFO - STARTING TEST    : test_basic_snat_behavior_without_external_connectivity
2025-10-13 20:56:04,571 - 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 20:56:04,831 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.254': '0'}} with
2025-10-13 20:56:04,831 - INFO - Initial checks done. Running the testcase now
2025-10-13 20:56:04,831 - INFO - 
2025-10-13 20:56:05,515 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-04094725
2025-10-13 20:56:05,611 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-04094725
2025-10-13 20:56:05,922 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-04094725', 'default']}
2025-10-13 20:56:06,200 - DEBUG - Response for create_network : {'network': {'id': '385833df-be64-4d34-880b-fe61c9acc904', 'name': 'ctest-vn-55249645', 'tenant_id': 'a8c80145932642e1a29f567ee031c9ed', 'project_id': 'a8c80145932642e1a29f567ee031c9ed', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-04094725', 'ctest-vn-55249645'], 'port_security_enabled': True, 'description': ''}}
2025-10-13 20:56:06,389 - DEBUG - Response for create_subnet : {'subnet': {'id': '60a9506a-bda5-4871-86dd-a58e6c1aaba5', 'name': '', 'tenant_id': 'a8c80145932642e1a29f567ee031c9ed', 'network_id': '385833df-be64-4d34-880b-fe61c9acc904', 'ip_version': 4, 'cidr': '205.163.165.128/26', 'allocation_pools': [{'start': '205.163.165.130', 'end': '205.163.165.190'}], 'gateway_ip': '205.163.165.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '205.163.165.130', 'tags': [], 'project_id': 'a8c80145932642e1a29f567ee031c9ed'}}
2025-10-13 20:56:06,405 - INFO - Created VN ctest-vn-55249645
2025-10-13 20:56:06,454 - DEBUG - VN ctest-vn-55249645 UUID is 385833df-be64-4d34-880b-fe61c9acc904
2025-10-13 20:56:06,786 - DEBUG - Response for create_network : {'network': {'id': '0d968827-4862-452e-9c01-7b4d74c5d467', 'name': 'ctest-ext_vn-48106911', 'tenant_id': 'a8c80145932642e1a29f567ee031c9ed', 'project_id': 'a8c80145932642e1a29f567ee031c9ed', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-04094725', 'ctest-ext_vn-48106911'], 'port_security_enabled': True, 'description': ''}}
2025-10-13 20:56:06,949 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f7fb6ca0-230e-4123-8ed5-9e166e16336f', 'name': '', 'tenant_id': 'a8c80145932642e1a29f567ee031c9ed', 'network_id': '0d968827-4862-452e-9c01-7b4d74c5d467', 'ip_version': 4, 'cidr': '22.158.221.0/26', 'allocation_pools': [{'start': '22.158.221.2', 'end': '22.158.221.62'}], 'gateway_ip': '22.158.221.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '22.158.221.2', 'tags': [], 'project_id': 'a8c80145932642e1a29f567ee031c9ed'}}
2025-10-13 20:56:06,965 - INFO - Created VN ctest-ext_vn-48106911
2025-10-13 20:56:07,014 - DEBUG - VN ctest-ext_vn-48106911 UUID is 0d968827-4862-452e-9c01-7b4d74c5d467
2025-10-13 20:56:07,212 - DEBUG - Services list from nova: [, , ]
2025-10-13 20:56:08,203 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4310-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4310-1)
2025-10-13 20:56:09,282 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4310-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4310-1)
2025-10-13 20:56:09,339 - INFO - Setting gateway for router fcc6f0c0-cf65-4efd-b4cb-bc521305e3cf to network 0d968827-4862-452e-9c01-7b4d74c5d467 
2025-10-13 20:56:09,392 - INFO - Adding interface with subnet_id 60a9506a-bda5-4871-86dd-a58e6c1aaba5, port_id None to router fcc6f0c0-cf65-4efd-b4cb-bc521305e3cf
2025-10-13 20:56:09,750 - INFO - Waiting for VM ctest-TestRoutersBasic-04094725-43636725 to be up..
2025-10-13 20:56:09,880 - DEBUG - VM  is still in BUILD state, Expected: ACTIVE
2025-10-13 20:56:14,948 - DEBUG - VM  is in ACTIVE state now
2025-10-13 20:56:14,948 - INFO - VM name : ctest-TestRoutersBasic-04094725-43636725
2025-10-13 20:56:15,012 - DEBUG - VM ctest-TestRoutersBasic-04094725-43636725 ID is f6275e0c-c432-4ca5-9fe9-9d69a3615b2d
2025-10-13 20:56:15,035 - DEBUG - VM ctest-TestRoutersBasic-04094725-43636725 launched on Node cn-jenkins-deploy-platform-ansible-os-4310-1
2025-10-13 20:56:15,107 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/f6275e0c-c432-4ca5-9fe9-9d69a3615b2d
2025-10-13 20:56:15,401 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/f6275e0c-c432-4ca5-9fe9-9d69a3615b2d
2025-10-13 20:56:15,430 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/c15affe9-bba3-4ce5-9ec4-49d57ac40463
2025-10-13 20:56:18,688 - 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 1027ms')
2025-10-13 20:56:18,688 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-04094725-43636725 failed!
2025-10-13 20:56:18,742 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-04094725:ctest-vn-55249645 is 205.163.165.129 and allocation pool is NOT set
2025-10-13 20:56:20,806 - 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.27 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.479 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.479/1.872/3.266/1.393 ms')
2025-10-13 20:56:20,806 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-04094725-43636725 passed
2025-10-13 20:56:20,955 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 20:56:20,955 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-04094725-43636725, IP 205.163.165.131, Port 22
2025-10-13 20:56:21,127 - DEBUG - VM ctest-TestRoutersBasic-04094725-43636725 is ready for SSH connections
2025-10-13 20:56:21,127 - INFO - Waiting for VM ctest-TestRoutersBasic-04094725-38214228 to be up..
2025-10-13 20:56:21,193 - DEBUG - VM  is in ACTIVE state now
2025-10-13 20:56:21,193 - INFO - VM name : ctest-TestRoutersBasic-04094725-38214228
2025-10-13 20:56:21,257 - DEBUG - VM ctest-TestRoutersBasic-04094725-38214228 ID is db2255fa-7a50-4be9-a25b-7944c94bdad6
2025-10-13 20:56:21,258 - DEBUG - VM ctest-TestRoutersBasic-04094725-38214228 launched on Node cn-jenkins-deploy-platform-ansible-os-4310-1
2025-10-13 20:56:21,323 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/db2255fa-7a50-4be9-a25b-7944c94bdad6
2025-10-13 20:56:21,330 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/59814b3e-ae87-43e6-b9f9-1a5c9bb73200
2025-10-13 20:56:22,563 - 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=2.93 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.360 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.360/1.644/2.929/1.284 ms')
2025-10-13 20:56:22,563 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-04094725-38214228 passed
2025-10-13 20:56:22,714 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 20:56:22,715 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-04094725-38214228, IP 22.158.221.3, Port 22
2025-10-13 20:56:22,880 - DEBUG - VM ctest-TestRoutersBasic-04094725-38214228 is ready for SSH connections
2025-10-13 20:56:22,880 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-13 20:56:22,880 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1  22.158.221.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-10-13 20:56:22,880 - DEBUG - ping -s 56 -c 3 -W 1  22.158.221.3
2025-10-13 20:56:26,569 - DEBUG - PING 22.158.221.3 (22.158.221.3): 56 data bytes
64 bytes from 22.158.221.3: seq=0 ttl=62 time=6.008 ms
64 bytes from 22.158.221.3: seq=1 ttl=62 time=0.793 ms
64 bytes from 22.158.221.3: seq=2 ttl=62 time=0.808 ms
--- 22.158.221.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.793/2.536/6.008 ms
2025-10-13 20:56:26,569 - INFO - Ping to IP 22.158.221.3 from VM ctest-TestRoutersBasic-04094725-43636725 passed
2025-10-13 20:56:26,569 - INFO - Deleting interface with subnet_id 60a9506a-bda5-4871-86dd-a58e6c1aaba5, port_id None from router fcc6f0c0-cf65-4efd-b4cb-bc521305e3cf
2025-10-13 20:56:26,732 - INFO - Deleting VM ctest-TestRoutersBasic-04094725-38214228
2025-10-13 20:56:26,796 - INFO - Deleting VM ctest-TestRoutersBasic-04094725-43636725
2025-10-13 20:56:26,867 - INFO - Deleting VN ctest-ext_vn-48106911 
2025-10-13 20:56:26,922 - DEBUG - VN 0d968827-4862-452e-9c01-7b4d74c5d467 still in use: Unable to complete operation on network 0d968827-4862-452e-9c01-7b4d74c5d467. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-c0ac029e-b054-45fa-bef1-1e1f02f22657']
2025-10-13 20:56:26,922 - WARNING - Deleting VN ctest-ext_vn-48106911 failed..Will retry
2025-10-13 20:56:29,004 - DEBUG - Response for deleting network ()
2025-10-13 20:56:29,004 - INFO - Deleting VN ctest-vn-55249645 
2025-10-13 20:56:29,092 - DEBUG - Response for deleting network ()
2025-10-13 20:56:29,343 - DEBUG - No XMPP flaps were noticed during the test
2025-10-13 20:56:29,343 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:25]
2025-10-13 20:56:29,343 - INFO - --------------------------------------------------------------------------------
2025-10-13 20:56:29,985 - INFO - Deleted project: ctest-TestRoutersBasic-04094725, ID : a8c80145-9326-42e1-a29f-567ee031c9ed