2025-09-18 21:37:57,952 - INFO - Domain Default found not creating
2025-09-18 21:37:58,078 - INFO - Project ctest-TestRoutersBasic-74685163 not found, creating it
2025-09-18 21:37:58,504 - INFO - Created Project:ctest-TestRoutersBasic-74685163, ID : 0e436907-c884-4678-82ee-0bfed8990bb6
2025-09-18 21:37:59,835 - INFO - ================================================================================
2025-09-18 21:37:59,835 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2025-09-18 21:37:59,835 - 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-09-18 21:38:00,086 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.17': '0'}} with
2025-09-18 21:38:00,086 - INFO - Initial checks done. Running the testcase now
2025-09-18 21:38:00,086 - INFO -
2025-09-18 21:38:00,771 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-74685163
2025-09-18 21:38:00,870 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-74685163
2025-09-18 21:38:01,185 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-74685163', 'default']}
2025-09-18 21:38:01,461 - DEBUG - Response for create_network : {'network': {'id': '2a2b50ce-0330-42fd-b671-8b6e1527a34c', 'name': 'ctest-vn-06948928', 'tenant_id': '0e436907c884467882ee0bfed8990bb6', 'project_id': '0e436907c884467882ee0bfed8990bb6', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-74685163', 'ctest-vn-06948928'], 'port_security_enabled': True, 'description': ''}}
2025-09-18 21:38:01,607 - DEBUG - Response for create_subnet : {'subnet': {'id': '66f2426f-0c53-433a-8b59-aed6cfd9be74', 'name': '', 'tenant_id': '0e436907c884467882ee0bfed8990bb6', 'network_id': '2a2b50ce-0330-42fd-b671-8b6e1527a34c', 'ip_version': 4, 'cidr': '136.160.254.64/26', 'allocation_pools': [{'start': '136.160.254.66', 'end': '136.160.254.126'}], 'gateway_ip': '136.160.254.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '136.160.254.66', 'tags': [], 'project_id': '0e436907c884467882ee0bfed8990bb6'}}
2025-09-18 21:38:01,623 - INFO - Created VN ctest-vn-06948928
2025-09-18 21:38:01,674 - DEBUG - VN ctest-vn-06948928 UUID is 2a2b50ce-0330-42fd-b671-8b6e1527a34c
2025-09-18 21:38:02,000 - DEBUG - Response for create_network : {'network': {'id': 'c5feb1e0-a8a2-4702-a6e9-73de4eb66f86', 'name': 'ctest-ext_vn-58167349', 'tenant_id': '0e436907c884467882ee0bfed8990bb6', 'project_id': '0e436907c884467882ee0bfed8990bb6', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-74685163', 'ctest-ext_vn-58167349'], 'port_security_enabled': True, 'description': ''}}
2025-09-18 21:38:02,144 - DEBUG - Response for create_subnet : {'subnet': {'id': 'de93035d-cb70-4065-8801-aa9c43550774', 'name': '', 'tenant_id': '0e436907c884467882ee0bfed8990bb6', 'network_id': 'c5feb1e0-a8a2-4702-a6e9-73de4eb66f86', 'ip_version': 4, 'cidr': '139.29.49.192/26', 'allocation_pools': [{'start': '139.29.49.194', 'end': '139.29.49.254'}], 'gateway_ip': '139.29.49.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '139.29.49.194', 'tags': [], 'project_id': '0e436907c884467882ee0bfed8990bb6'}}
2025-09-18 21:38:02,160 - INFO - Created VN ctest-ext_vn-58167349
2025-09-18 21:38:02,209 - DEBUG - VN ctest-ext_vn-58167349 UUID is c5feb1e0-a8a2-4702-a6e9-73de4eb66f86
2025-09-18 21:38:02,401 - DEBUG - Services list from nova: [, , ]
2025-09-18 21:38:03,370 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4142-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4142-1)
2025-09-18 21:38:04,507 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4142-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4142-1)
2025-09-18 21:38:04,587 - INFO - Setting gateway for router 11be743f-2112-4fb8-9672-80635c9b605d to network c5feb1e0-a8a2-4702-a6e9-73de4eb66f86
2025-09-18 21:38:04,635 - INFO - Adding interface with subnet_id 66f2426f-0c53-433a-8b59-aed6cfd9be74, port_id None to router 11be743f-2112-4fb8-9672-80635c9b605d
2025-09-18 21:38:04,937 - INFO - Waiting for VM ctest-TestRoutersBasic-74685163-17880979 to be up..
2025-09-18 21:38:05,053 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-18 21:38:10,119 - DEBUG - VM is in ACTIVE state now
2025-09-18 21:38:10,119 - INFO - VM name : ctest-TestRoutersBasic-74685163-17880979
2025-09-18 21:38:10,187 - DEBUG - VM ctest-TestRoutersBasic-74685163-17880979 ID is 1e3f5361-57ac-4a8c-bf18-716f40351f7d
2025-09-18 21:38:10,205 - DEBUG - VM ctest-TestRoutersBasic-74685163-17880979 launched on Node cn-jenkins-deploy-platform-ansible-os-4142-1
2025-09-18 21:38:10,269 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/1e3f5361-57ac-4a8c-bf18-716f40351f7d
2025-09-18 21:38:10,561 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/1e3f5361-57ac-4a8c-bf18-716f40351f7d
2025-09-18 21:38:10,590 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/0f77fbdb-5c9d-4751-9b9f-9bd2537b13d1
2025-09-18 21:38:13,827 - 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 1012ms')
2025-09-18 21:38:13,828 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-74685163-17880979 failed!
2025-09-18 21:38:13,885 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-74685163:ctest-vn-06948928 is 136.160.254.65 and allocation pool is NOT set
2025-09-18 21:38:15,948 - 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.71 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.382 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 = 0.382/1.545/2.709/1.163 ms')
2025-09-18 21:38:15,948 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-74685163-17880979 passed
2025-09-18 21:38:16,102 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:38:16,102 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-74685163-17880979, IP 136.160.254.67, Port 22
2025-09-18 21:38:16,265 - DEBUG - VM ctest-TestRoutersBasic-74685163-17880979 is ready for SSH connections
2025-09-18 21:38:16,265 - INFO - Waiting for VM ctest-TestRoutersBasic-74685163-34728903 to be up..
2025-09-18 21:38:16,332 - DEBUG - VM is in ACTIVE state now
2025-09-18 21:38:16,332 - INFO - VM name : ctest-TestRoutersBasic-74685163-34728903
2025-09-18 21:38:16,397 - DEBUG - VM ctest-TestRoutersBasic-74685163-34728903 ID is 539a253a-f1dc-4650-b005-00e5a44e92d8
2025-09-18 21:38:16,397 - DEBUG - VM ctest-TestRoutersBasic-74685163-34728903 launched on Node cn-jenkins-deploy-platform-ansible-os-4142-1
2025-09-18 21:38:16,461 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/539a253a-f1dc-4650-b005-00e5a44e92d8
2025-09-18 21:38:16,468 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/ca76c5f7-947d-439d-aa1b-0e42e451e8f9
2025-09-18 21:38:17,704 - 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.96 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.320 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.320/1.638/2.957/1.318 ms')
2025-09-18 21:38:17,705 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-74685163-34728903 passed
2025-09-18 21:38:17,854 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:38:17,854 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-74685163-34728903, IP 139.29.49.195, Port 22
2025-09-18 21:38:18,021 - DEBUG - VM ctest-TestRoutersBasic-74685163-34728903 is ready for SSH connections
2025-09-18 21:38:18,021 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:38:18,021 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 139.29.49.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:38:18,022 - DEBUG - ping -s 56 -c 3 -W 1 139.29.49.195
2025-09-18 21:38:21,701 - DEBUG - PING 139.29.49.195 (139.29.49.195): 56 data bytes
64 bytes from 139.29.49.195: seq=0 ttl=62 time=6.211 ms
64 bytes from 139.29.49.195: seq=1 ttl=62 time=1.028 ms
64 bytes from 139.29.49.195: seq=2 ttl=62 time=0.781 ms
--- 139.29.49.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.781/2.673/6.211 ms
2025-09-18 21:38:21,702 - INFO - Ping to IP 139.29.49.195 from VM ctest-TestRoutersBasic-74685163-17880979 passed
2025-09-18 21:38:21,702 - INFO - Deleting interface with subnet_id 66f2426f-0c53-433a-8b59-aed6cfd9be74, port_id None from router 11be743f-2112-4fb8-9672-80635c9b605d
2025-09-18 21:38:21,858 - INFO - Deleting VM ctest-TestRoutersBasic-74685163-34728903
2025-09-18 21:38:21,919 - INFO - Deleting VM ctest-TestRoutersBasic-74685163-17880979
2025-09-18 21:38:21,994 - INFO - Deleting VN ctest-ext_vn-58167349
2025-09-18 21:38:22,048 - DEBUG - VN c5feb1e0-a8a2-4702-a6e9-73de4eb66f86 still in use: Unable to complete operation on network c5feb1e0-a8a2-4702-a6e9-73de4eb66f86. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-83ec30ce-735f-428c-a196-9f1186a7c2fc']
2025-09-18 21:38:22,048 - WARNING - Deleting VN ctest-ext_vn-58167349 failed..Will retry
2025-09-18 21:38:24,138 - DEBUG - Response for deleting network ()
2025-09-18 21:38:24,139 - INFO - Deleting VN ctest-vn-06948928
2025-09-18 21:38:24,223 - DEBUG - Response for deleting network ()
2025-09-18 21:38:24,477 - DEBUG - No XMPP flaps were noticed during the test
2025-09-18 21:38:24,477 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:25]
2025-09-18 21:38:24,477 - INFO - --------------------------------------------------------------------------------
2025-09-18 21:38:25,117 - INFO - Deleted project: ctest-TestRoutersBasic-74685163, ID : 0e436907-c884-4678-82ee-0bfed8990bb6