2025-03-24 16:33:14,680 - INFO - Domain Default found not creating
2025-03-24 16:33:14,819 - INFO - Project ctest-TestRoutersBasic-66956594 not found, creating it
2025-03-24 16:33:15,306 - INFO - Created Project:ctest-TestRoutersBasic-66956594, ID : 9b9ba4de-c1c0-4055-b158-29cfb7e8e688
2025-03-24 16:33:16,739 - INFO - ================================================================================
2025-03-24 16:33:16,739 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2025-03-24 16:33:16,739 - 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-03-24 16:33:16,993 - DEBUG - Nothing to compare xmpp stats {'10.0.0.31': {'10.20.0.18': '0'}} with
2025-03-24 16:33:16,994 - INFO - Initial checks done. Running the testcase now
2025-03-24 16:33:16,994 - INFO -
2025-03-24 16:33:17,716 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-66956594
2025-03-24 16:33:17,815 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-66956594
2025-03-24 16:33:18,146 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-66956594', 'default']}
2025-03-24 16:33:18,443 - DEBUG - Response for create_network : {'network': {'id': '336d0112-62a4-42e7-a01e-66ab93eea770', 'name': 'ctest-vn-02826659', 'tenant_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'project_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-66956594', 'ctest-vn-02826659'], 'port_security_enabled': True, 'description': ''}}
2025-03-24 16:33:18,615 - DEBUG - Response for create_subnet : {'subnet': {'id': '37b01b44-c79c-425c-8782-4d57a1d7cfe7', 'name': '', 'tenant_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'network_id': '336d0112-62a4-42e7-a01e-66ab93eea770', 'ip_version': 4, 'cidr': '197.250.235.128/26', 'allocation_pools': [{'start': '197.250.235.130', 'end': '197.250.235.190'}], 'gateway_ip': '197.250.235.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '197.250.235.130', 'tags': [], 'project_id': '9b9ba4dec1c04055b15829cfb7e8e688'}}
2025-03-24 16:33:18,634 - INFO - Created VN ctest-vn-02826659
2025-03-24 16:33:18,686 - DEBUG - VN ctest-vn-02826659 UUID is 336d0112-62a4-42e7-a01e-66ab93eea770
2025-03-24 16:33:19,055 - DEBUG - Response for create_network : {'network': {'id': 'bc2b4b43-0ed1-408c-8a12-07e4b250ef41', 'name': 'ctest-ext_vn-35209597', 'tenant_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'project_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-66956594', 'ctest-ext_vn-35209597'], 'port_security_enabled': True, 'description': ''}}
2025-03-24 16:33:19,241 - DEBUG - Response for create_subnet : {'subnet': {'id': '0b7fcbf1-a39c-4bef-833c-ed6f49cddc7c', 'name': '', 'tenant_id': '9b9ba4dec1c04055b15829cfb7e8e688', 'network_id': 'bc2b4b43-0ed1-408c-8a12-07e4b250ef41', 'ip_version': 4, 'cidr': '90.252.202.192/26', 'allocation_pools': [{'start': '90.252.202.194', 'end': '90.252.202.254'}], 'gateway_ip': '90.252.202.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '90.252.202.194', 'tags': [], 'project_id': '9b9ba4dec1c04055b15829cfb7e8e688'}}
2025-03-24 16:33:19,263 - INFO - Created VN ctest-ext_vn-35209597
2025-03-24 16:33:19,318 - DEBUG - VN ctest-ext_vn-35209597 UUID is bc2b4b43-0ed1-408c-8a12-07e4b250ef41
2025-03-24 16:33:19,496 - DEBUG - Services list from nova: [, , ]
2025-03-24 16:33:20,492 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-2943-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-2943-1)
2025-03-24 16:33:21,700 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-2943-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-2943-1)
2025-03-24 16:33:21,775 - INFO - Setting gateway for router d55d6b62-c799-4e6e-adb8-ba08fe0f56dd to network bc2b4b43-0ed1-408c-8a12-07e4b250ef41
2025-03-24 16:33:21,874 - INFO - Adding interface with subnet_id 37b01b44-c79c-425c-8782-4d57a1d7cfe7, port_id None to router d55d6b62-c799-4e6e-adb8-ba08fe0f56dd
2025-03-24 16:33:22,340 - INFO - Waiting for VM ctest-TestRoutersBasic-66956594-24931811 to be up..
2025-03-24 16:33:22,555 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-03-24 16:33:27,637 - DEBUG - VM is in ACTIVE state now
2025-03-24 16:33:27,637 - INFO - VM name : ctest-TestRoutersBasic-66956594-24931811
2025-03-24 16:33:27,727 - DEBUG - VM ctest-TestRoutersBasic-66956594-24931811 ID is b6bf893b-ec3f-4d70-98d8-dd68a82c38c4
2025-03-24 16:33:27,753 - DEBUG - VM ctest-TestRoutersBasic-66956594-24931811 launched on Node cn-jenkins-deploy-platform-ansible-os-2943-1
2025-03-24 16:33:27,858 - DEBUG - Requesting: http://10.0.0.31:8082/virtual-machine/b6bf893b-ec3f-4d70-98d8-dd68a82c38c4
2025-03-24 16:33:28,161 - DEBUG - Requesting: http://10.0.0.31:8082/virtual-machine/b6bf893b-ec3f-4d70-98d8-dd68a82c38c4
2025-03-24 16:33:28,202 - DEBUG - Requesting: http://10.0.0.31:8082/virtual-machine-interface/0c4aed83-c1c5-4cdb-ab01-5a4058b4f0a3
2025-03-24 16:33:31,445 - 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 1003ms')
2025-03-24 16:33:31,445 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-66956594-24931811 failed!
2025-03-24 16:33:31,502 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-66956594:ctest-vn-02826659 is 197.250.235.129 and allocation pool is NOT set
2025-03-24 16:33:33,567 - 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=4.04 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.07 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 = 1.069/2.553/4.038/1.484 ms')
2025-03-24 16:33:33,567 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-66956594-24931811 passed
2025-03-24 16:33:33,718 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-03-24 16:33:33,719 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-66956594-24931811, IP 197.250.235.131, Port 22
2025-03-24 16:33:33,778 - DEBUG - Error on ssh to cirros@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-03-24 16:33:33,855 - DEBUG - VM ctest-TestRoutersBasic-66956594-24931811 is NOT ready for SSH connections, VM status: ACTIVE
2025-03-24 16:33:38,856 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-03-24 16:33:38,856 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-66956594-24931811, IP 197.250.235.131, Port 22
2025-03-24 16:33:39,025 - DEBUG - VM ctest-TestRoutersBasic-66956594-24931811 is ready for SSH connections
2025-03-24 16:33:39,025 - INFO - Waiting for VM ctest-TestRoutersBasic-66956594-98119773 to be up..
2025-03-24 16:33:39,105 - DEBUG - VM is in ACTIVE state now
2025-03-24 16:33:39,105 - INFO - VM name : ctest-TestRoutersBasic-66956594-98119773
2025-03-24 16:33:39,187 - DEBUG - VM ctest-TestRoutersBasic-66956594-98119773 ID is fa222193-11b9-4ff5-9564-2f603809247b
2025-03-24 16:33:39,187 - DEBUG - VM ctest-TestRoutersBasic-66956594-98119773 launched on Node cn-jenkins-deploy-platform-ansible-os-2943-1
2025-03-24 16:33:39,266 - DEBUG - Requesting: http://10.0.0.31:8082/virtual-machine/fa222193-11b9-4ff5-9564-2f603809247b
2025-03-24 16:33:39,275 - DEBUG - Requesting: http://10.0.0.31:8082/virtual-machine-interface/c0edd00e-c9d5-47c6-a85a-aeb94fe0beb0
2025-03-24 16:33:40,521 - 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.510 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.510/1.721/2.933/1.211 ms')
2025-03-24 16:33:40,522 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-66956594-98119773 passed
2025-03-24 16:33:40,678 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-03-24 16:33:40,679 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-66956594-98119773, IP 90.252.202.195, Port 22
2025-03-24 16:33:40,835 - DEBUG - VM ctest-TestRoutersBasic-66956594-98119773 is ready for SSH connections
2025-03-24 16:33:40,835 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-03-24 16:33:40,835 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 90.252.202.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.31, gateway password: c0ntrail123
2025-03-24 16:33:40,835 - DEBUG - ping -s 56 -c 3 -W 1 90.252.202.195
2025-03-24 16:33:44,549 - DEBUG - PING 90.252.202.195 (90.252.202.195): 56 data bytes
64 bytes from 90.252.202.195: seq=0 ttl=62 time=4.205 ms
64 bytes from 90.252.202.195: seq=1 ttl=62 time=0.910 ms
64 bytes from 90.252.202.195: seq=2 ttl=62 time=0.774 ms
--- 90.252.202.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.774/1.963/4.205 ms
2025-03-24 16:33:44,549 - INFO - Ping to IP 90.252.202.195 from VM ctest-TestRoutersBasic-66956594-24931811 passed
2025-03-24 16:33:44,549 - INFO - Deleting interface with subnet_id 37b01b44-c79c-425c-8782-4d57a1d7cfe7, port_id None from router d55d6b62-c799-4e6e-adb8-ba08fe0f56dd
2025-03-24 16:33:44,755 - INFO - Deleting VM ctest-TestRoutersBasic-66956594-98119773
2025-03-24 16:33:44,819 - INFO - Deleting VM ctest-TestRoutersBasic-66956594-24931811
2025-03-24 16:33:44,907 - INFO - Deleting VN ctest-ext_vn-35209597
2025-03-24 16:33:44,995 - DEBUG - VN bc2b4b43-0ed1-408c-8a12-07e4b250ef41 still in use: Unable to complete operation on network bc2b4b43-0ed1-408c-8a12-07e4b250ef41. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-b1cb69cf-0a54-4f9e-b0d1-27f3b4720700']
2025-03-24 16:33:44,995 - WARNING - Deleting VN ctest-ext_vn-35209597 failed..Will retry
2025-03-24 16:33:47,112 - DEBUG - Response for deleting network ()
2025-03-24 16:33:47,112 - INFO - Deleting VN ctest-vn-02826659
2025-03-24 16:33:47,210 - DEBUG - Response for deleting network ()
2025-03-24 16:33:47,468 - DEBUG - No XMPP flaps were noticed during the test
2025-03-24 16:33:47,468 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:31]
2025-03-24 16:33:47,468 - INFO - --------------------------------------------------------------------------------
2025-03-24 16:33:48,211 - INFO - Deleted project: ctest-TestRoutersBasic-66956594, ID : 9b9ba4de-c1c0-4055-b158-29cfb7e8e688