2025-10-27 17:33:01,064 - INFO - Domain Default found not creating
2025-10-27 17:33:01,226 - INFO - Project ctest-TestRoutersBasic-67007446 not found, creating it
2025-10-27 17:33:01,701 - INFO - Created Project:ctest-TestRoutersBasic-67007446, ID : a7199fb3-a51e-41b8-a895-5defbeae8dec 
2025-10-27 17:33:03,193 - INFO - ================================================================================
2025-10-27 17:33:03,194 - INFO - STARTING TEST    : test_basic_snat_behavior_without_external_connectivity
2025-10-27 17:33:03,194 - 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-27 17:33:03,447 - DEBUG - Nothing to compare xmpp stats {'10.0.0.242': {'10.20.0.17': '0'}} with
2025-10-27 17:33:03,447 - INFO - Initial checks done. Running the testcase now
2025-10-27 17:33:03,447 - INFO - 
2025-10-27 17:33:04,157 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-67007446
2025-10-27 17:33:04,257 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-67007446
2025-10-27 17:33:04,589 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-67007446', 'default']}
2025-10-27 17:33:04,905 - DEBUG - Response for create_network : {'network': {'id': 'cd0bbf9b-a1e0-413b-823c-008136fb5c00', 'name': 'ctest-vn-89152141', 'tenant_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'project_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-67007446', 'ctest-vn-89152141'], 'port_security_enabled': True, 'description': ''}}
2025-10-27 17:33:05,125 - DEBUG - Response for create_subnet : {'subnet': {'id': '5f501189-cdac-497b-926a-fdd4e5d09484', 'name': '', 'tenant_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'network_id': 'cd0bbf9b-a1e0-413b-823c-008136fb5c00', 'ip_version': 4, 'cidr': '2.162.81.128/26', 'allocation_pools': [{'start': '2.162.81.130', 'end': '2.162.81.190'}], 'gateway_ip': '2.162.81.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '2.162.81.130', 'tags': [], 'project_id': 'a7199fb3a51e41b8a8955defbeae8dec'}}
2025-10-27 17:33:05,143 - INFO - Created VN ctest-vn-89152141
2025-10-27 17:33:05,193 - DEBUG - VN ctest-vn-89152141 UUID is cd0bbf9b-a1e0-413b-823c-008136fb5c00
2025-10-27 17:33:05,507 - DEBUG - Response for create_network : {'network': {'id': '58f50b50-969d-4ab1-9908-4dcd19475863', 'name': 'ctest-ext_vn-18040455', 'tenant_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'project_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-67007446', 'ctest-ext_vn-18040455'], 'port_security_enabled': True, 'description': ''}}
2025-10-27 17:33:05,693 - DEBUG - Response for create_subnet : {'subnet': {'id': '22ae6a85-7ceb-491b-85bd-34dd3c6cd46d', 'name': '', 'tenant_id': 'a7199fb3a51e41b8a8955defbeae8dec', 'network_id': '58f50b50-969d-4ab1-9908-4dcd19475863', 'ip_version': 4, 'cidr': '89.249.59.128/26', 'allocation_pools': [{'start': '89.249.59.130', 'end': '89.249.59.190'}], 'gateway_ip': '89.249.59.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '89.249.59.130', 'tags': [], 'project_id': 'a7199fb3a51e41b8a8955defbeae8dec'}}
2025-10-27 17:33:05,711 - INFO - Created VN ctest-ext_vn-18040455
2025-10-27 17:33:05,761 - DEBUG - VN ctest-ext_vn-18040455 UUID is 58f50b50-969d-4ab1-9908-4dcd19475863
2025-10-27 17:33:05,944 - DEBUG - Services list from nova: [, , ]
2025-10-27 17:33:06,990 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4509-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4509-1)
2025-10-27 17:33:08,212 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4509-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4509-1)
2025-10-27 17:33:08,318 - INFO - Setting gateway for router c67101cd-124b-48d2-bc7d-23ea04a7ac7e to network 58f50b50-969d-4ab1-9908-4dcd19475863 
2025-10-27 17:33:08,444 - INFO - Adding interface with subnet_id 5f501189-cdac-497b-926a-fdd4e5d09484, port_id None to router c67101cd-124b-48d2-bc7d-23ea04a7ac7e
2025-10-27 17:33:08,863 - INFO - Waiting for VM ctest-TestRoutersBasic-67007446-00191269 to be up..
2025-10-27 17:33:09,032 - DEBUG - VM  is still in BUILD state, Expected: ACTIVE
2025-10-27 17:33:14,107 - DEBUG - VM  is in ACTIVE state now
2025-10-27 17:33:14,107 - INFO - VM name : ctest-TestRoutersBasic-67007446-00191269
2025-10-27 17:33:14,182 - DEBUG - VM ctest-TestRoutersBasic-67007446-00191269 ID is 5e3c4d66-3a25-4e91-aa2f-856ceca2e548
2025-10-27 17:33:14,200 - DEBUG - VM ctest-TestRoutersBasic-67007446-00191269 launched on Node cn-jenkins-deploy-platform-ansible-os-4509-1
2025-10-27 17:33:14,292 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/5e3c4d66-3a25-4e91-aa2f-856ceca2e548
2025-10-27 17:33:14,590 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/5e3c4d66-3a25-4e91-aa2f-856ceca2e548
2025-10-27 17:33:14,622 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine-interface/fa02670a-b8f0-4a4d-9997-cfc790b3f07b
2025-10-27 17:33:17,883 - 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 1022ms')
2025-10-27 17:33:17,883 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-67007446-00191269 failed!
2025-10-27 17:33:17,937 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-67007446:ctest-vn-89152141 is 2.162.81.129 and allocation pool is NOT set
2025-10-27 17:33:20,000 - 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=2.76 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.54 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 2.543/2.652/2.762/0.109 ms')
2025-10-27 17:33:20,000 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-67007446-00191269 passed
2025-10-27 17:33:20,161 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-27 17:33:20,161 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-67007446-00191269, IP 2.162.81.131, Port 22
2025-10-27 17:33:20,340 - DEBUG - VM ctest-TestRoutersBasic-67007446-00191269 is ready for SSH connections
2025-10-27 17:33:20,340 - INFO - Waiting for VM ctest-TestRoutersBasic-67007446-92230234 to be up..
2025-10-27 17:33:20,426 - DEBUG - VM  is in ACTIVE state now
2025-10-27 17:33:20,426 - INFO - VM name : ctest-TestRoutersBasic-67007446-92230234
2025-10-27 17:33:20,504 - DEBUG - VM ctest-TestRoutersBasic-67007446-92230234 ID is b146ccc0-0ab6-4589-a830-85ad61e7a99e
2025-10-27 17:33:20,504 - DEBUG - VM ctest-TestRoutersBasic-67007446-92230234 launched on Node cn-jenkins-deploy-platform-ansible-os-4509-1
2025-10-27 17:33:20,591 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/b146ccc0-0ab6-4589-a830-85ad61e7a99e
2025-10-27 17:33:20,601 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine-interface/a77654cd-9ec3-4013-9f24-067661d20362
2025-10-27 17:33:21,850 - 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.88 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.629 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.629/1.756/2.883/1.127 ms')
2025-10-27 17:33:21,850 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-67007446-92230234 passed
2025-10-27 17:33:22,001 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-27 17:33:22,001 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-67007446-92230234, IP 89.249.59.131, Port 22
2025-10-27 17:33:22,157 - DEBUG - VM ctest-TestRoutersBasic-67007446-92230234 is ready for SSH connections
2025-10-27 17:33:22,157 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-27 17:33:22,157 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1  89.249.59.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123
2025-10-27 17:33:22,157 - DEBUG - ping -s 56 -c 3 -W 1  89.249.59.131
2025-10-27 17:33:25,872 - DEBUG - PING 89.249.59.131 (89.249.59.131): 56 data bytes
64 bytes from 89.249.59.131: seq=0 ttl=62 time=4.873 ms
64 bytes from 89.249.59.131: seq=1 ttl=62 time=0.889 ms
64 bytes from 89.249.59.131: seq=2 ttl=62 time=0.994 ms
--- 89.249.59.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.889/2.252/4.873 ms
2025-10-27 17:33:25,872 - INFO - Ping to IP 89.249.59.131 from VM ctest-TestRoutersBasic-67007446-00191269 passed
2025-10-27 17:33:25,872 - INFO - Deleting interface with subnet_id 5f501189-cdac-497b-926a-fdd4e5d09484, port_id None from router c67101cd-124b-48d2-bc7d-23ea04a7ac7e
2025-10-27 17:33:26,069 - INFO - Deleting VM ctest-TestRoutersBasic-67007446-92230234
2025-10-27 17:33:26,171 - INFO - Deleting VM ctest-TestRoutersBasic-67007446-00191269
2025-10-27 17:33:26,243 - INFO - Deleting VN ctest-ext_vn-18040455 
2025-10-27 17:33:26,322 - DEBUG - VN 58f50b50-969d-4ab1-9908-4dcd19475863 still in use: Unable to complete operation on network 58f50b50-969d-4ab1-9908-4dcd19475863. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-c21c50b7-413d-4db2-ba3f-514111cef340']
2025-10-27 17:33:26,322 - WARNING - Deleting VN ctest-ext_vn-18040455 failed..Will retry
2025-10-27 17:33:28,428 - DEBUG - Response for deleting network ()
2025-10-27 17:33:28,428 - INFO - Deleting VN ctest-vn-89152141 
2025-10-27 17:33:28,531 - DEBUG - Response for deleting network ()
2025-10-27 17:33:28,787 - DEBUG - No XMPP flaps were noticed during the test
2025-10-27 17:33:28,787 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:25]
2025-10-27 17:33:28,787 - INFO - --------------------------------------------------------------------------------
2025-10-27 17:33:29,473 - INFO - Deleted project: ctest-TestRoutersBasic-67007446, ID : a7199fb3-a51e-41b8-a895-5defbeae8dec