2026-04-25 21:46:00,674 - INFO - Domain Default found not creating
2026-04-25 21:46:00,896 - INFO - Project ctest-TestRoutersBasic-25159944 not found, creating it
2026-04-25 21:46:01,434 - INFO - Created Project:ctest-TestRoutersBasic-25159944, ID : 971fcadd-5c9e-46ef-9b9a-92c9d807d2e8
2026-04-25 21:46:03,002 - INFO - ================================================================================
2026-04-25 21:46:03,002 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2026-04-25 21:46:03,002 - 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
2026-04-25 21:46:03,269 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with
2026-04-25 21:46:03,269 - INFO - Initial checks done. Running the testcase now
2026-04-25 21:46:03,269 - INFO -
2026-04-25 21:46:04,006 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-25159944
2026-04-25 21:46:04,100 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-25159944
2026-04-25 21:46:04,424 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-25159944', 'default']}
2026-04-25 21:46:04,714 - DEBUG - Response for create_network : {'network': {'id': '7b21904e-a143-4fa7-b6d9-737eeddc9fb2', 'name': 'ctest-vn-26321764', 'tenant_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'project_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-25159944', 'ctest-vn-26321764'], 'port_security_enabled': True, 'description': ''}}
2026-04-25 21:46:04,939 - DEBUG - Response for create_subnet : {'subnet': {'id': '50896d9d-7325-4abe-9152-b83d0543c100', 'name': '', 'tenant_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'network_id': '7b21904e-a143-4fa7-b6d9-737eeddc9fb2', 'ip_version': 4, 'cidr': '132.112.63.128/26', 'allocation_pools': [{'start': '132.112.63.130', 'end': '132.112.63.190'}], 'gateway_ip': '132.112.63.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '132.112.63.130', 'tags': [], 'project_id': '971fcadd5c9e46ef9b9a92c9d807d2e8'}}
2026-04-25 21:46:04,957 - INFO - Created VN ctest-vn-26321764
2026-04-25 21:46:05,008 - DEBUG - VN ctest-vn-26321764 UUID is 7b21904e-a143-4fa7-b6d9-737eeddc9fb2
2026-04-25 21:46:05,309 - DEBUG - Response for create_network : {'network': {'id': 'e390348c-c476-4e81-b674-2a4973ef88b2', 'name': 'ctest-ext_vn-76997603', 'tenant_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'project_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-25159944', 'ctest-ext_vn-76997603'], 'port_security_enabled': True, 'description': ''}}
2026-04-25 21:46:05,507 - DEBUG - Response for create_subnet : {'subnet': {'id': '737574bf-9f02-4e0e-a40e-309df6ce1ab7', 'name': '', 'tenant_id': '971fcadd5c9e46ef9b9a92c9d807d2e8', 'network_id': 'e390348c-c476-4e81-b674-2a4973ef88b2', 'ip_version': 4, 'cidr': '33.207.213.192/26', 'allocation_pools': [{'start': '33.207.213.194', 'end': '33.207.213.254'}], 'gateway_ip': '33.207.213.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '33.207.213.194', 'tags': [], 'project_id': '971fcadd5c9e46ef9b9a92c9d807d2e8'}}
2026-04-25 21:46:05,530 - INFO - Created VN ctest-ext_vn-76997603
2026-04-25 21:46:05,584 - DEBUG - VN ctest-ext_vn-76997603 UUID is e390348c-c476-4e81-b674-2a4973ef88b2
2026-04-25 21:46:05,792 - DEBUG - Services list from nova: [, , ]
2026-04-25 21:46:06,848 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5686-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5686-1)
2026-04-25 21:46:08,007 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5686-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5686-1)
2026-04-25 21:46:08,084 - INFO - Setting gateway for router 05f6ec00-bc90-46da-8822-3098c27c997a to network e390348c-c476-4e81-b674-2a4973ef88b2
2026-04-25 21:46:08,156 - INFO - Adding interface with subnet_id 50896d9d-7325-4abe-9152-b83d0543c100, port_id None to router 05f6ec00-bc90-46da-8822-3098c27c997a
2026-04-25 21:46:08,471 - INFO - Waiting for VM ctest-TestRoutersBasic-25159944-27808125 to be up..
2026-04-25 21:46:08,588 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-04-25 21:46:13,667 - DEBUG - VM is in ACTIVE state now
2026-04-25 21:46:13,667 - INFO - VM name : ctest-TestRoutersBasic-25159944-27808125
2026-04-25 21:46:13,739 - DEBUG - VM ctest-TestRoutersBasic-25159944-27808125 ID is f13f305b-d7a2-4215-905b-5cca4cf5e282
2026-04-25 21:46:13,759 - DEBUG - VM ctest-TestRoutersBasic-25159944-27808125 launched on Node cn-jenkins-deploy-platform-ansible-os-5686-1
2026-04-25 21:46:13,830 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/f13f305b-d7a2-4215-905b-5cca4cf5e282
2026-04-25 21:46:14,127 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/f13f305b-d7a2-4215-905b-5cca4cf5e282
2026-04-25 21:46:14,161 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/22a0a175-4c75-4f50-975f-493034ee110e
2026-04-25 21:46:17,407 - 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 1006ms')
2026-04-25 21:46:17,407 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-25159944-27808125 failed!
2026-04-25 21:46:17,460 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-25159944:ctest-vn-26321764 is 132.112.63.129 and allocation pool is NOT set
2026-04-25 21:46:19,524 - 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=5.01 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.09 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 2.086/3.549/5.013/1.463 ms')
2026-04-25 21:46:19,524 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-25159944-27808125 passed
2026-04-25 21:46:19,628 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-04-25 21:46:19,628 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-25159944-27808125, IP 132.112.63.131, Port 22
2026-04-25 21:46:19,784 - DEBUG - VM ctest-TestRoutersBasic-25159944-27808125 is ready for SSH connections
2026-04-25 21:46:19,784 - INFO - Waiting for VM ctest-TestRoutersBasic-25159944-80870574 to be up..
2026-04-25 21:46:19,868 - DEBUG - VM is in ACTIVE state now
2026-04-25 21:46:19,868 - INFO - VM name : ctest-TestRoutersBasic-25159944-80870574
2026-04-25 21:46:19,960 - DEBUG - VM ctest-TestRoutersBasic-25159944-80870574 ID is 635b541c-956d-49c4-87fd-3dc7163c15ba
2026-04-25 21:46:19,960 - DEBUG - VM ctest-TestRoutersBasic-25159944-80870574 launched on Node cn-jenkins-deploy-platform-ansible-os-5686-1
2026-04-25 21:46:20,055 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/635b541c-956d-49c4-87fd-3dc7163c15ba
2026-04-25 21:46:20,065 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/ebf1eb0c-7e58-4584-8580-26fae1d5054b
2026-04-25 21:46:21,306 - 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=5.92 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=3.16 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 = 3.156/4.540/5.924/1.384 ms')
2026-04-25 21:46:21,306 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-25159944-80870574 passed
2026-04-25 21:46:21,460 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-04-25 21:46:21,461 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-25159944-80870574, IP 33.207.213.195, Port 22
2026-04-25 21:46:21,526 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-04-25 21:46:21,615 - DEBUG - VM ctest-TestRoutersBasic-25159944-80870574 is NOT ready for SSH connections, VM status: ACTIVE
2026-04-25 21:46:26,616 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-04-25 21:46:26,616 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-25159944-80870574, IP 33.207.213.195, Port 22
2026-04-25 21:46:26,780 - DEBUG - VM ctest-TestRoutersBasic-25159944-80870574 is ready for SSH connections
2026-04-25 21:46:26,780 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-04-25 21:46:26,780 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 33.207.213.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-04-25 21:46:26,780 - DEBUG - ping -s 56 -c 3 -W 1 33.207.213.195
2026-04-25 21:46:30,525 - DEBUG - PING 33.207.213.195 (33.207.213.195): 56 data bytes
64 bytes from 33.207.213.195: seq=0 ttl=62 time=6.880 ms
64 bytes from 33.207.213.195: seq=1 ttl=62 time=1.187 ms
64 bytes from 33.207.213.195: seq=2 ttl=62 time=1.381 ms
--- 33.207.213.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.187/3.149/6.880 ms
2026-04-25 21:46:30,525 - INFO - Ping to IP 33.207.213.195 from VM ctest-TestRoutersBasic-25159944-27808125 passed
2026-04-25 21:46:30,525 - INFO - Deleting interface with subnet_id 50896d9d-7325-4abe-9152-b83d0543c100, port_id None from router 05f6ec00-bc90-46da-8822-3098c27c997a
2026-04-25 21:46:30,703 - INFO - Deleting VM ctest-TestRoutersBasic-25159944-80870574
2026-04-25 21:46:30,796 - INFO - Deleting VM ctest-TestRoutersBasic-25159944-27808125
2026-04-25 21:46:30,885 - INFO - Deleting VN ctest-ext_vn-76997603
2026-04-25 21:46:30,964 - DEBUG - VN e390348c-c476-4e81-b674-2a4973ef88b2 still in use: Unable to complete operation on network e390348c-c476-4e81-b674-2a4973ef88b2. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-c80b0910-76bd-4240-9334-0a3c35589ac5']
2026-04-25 21:46:30,964 - WARNING - Deleting VN ctest-ext_vn-76997603 failed..Will retry
2026-04-25 21:46:33,076 - DEBUG - Response for deleting network ()
2026-04-25 21:46:33,076 - INFO - Deleting VN ctest-vn-26321764
2026-04-25 21:46:33,177 - DEBUG - Response for deleting network ()
2026-04-25 21:46:33,429 - DEBUG - No XMPP flaps were noticed during the test
2026-04-25 21:46:33,429 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:30]
2026-04-25 21:46:33,429 - INFO - --------------------------------------------------------------------------------
2026-04-25 21:46:34,114 - INFO - Deleted project: ctest-TestRoutersBasic-25159944, ID : 971fcadd-5c9e-46ef-9b9a-92c9d807d2e8