2026-07-30 14:52:09,175 - INFO - Domain Default found not creating
2026-07-30 14:52:09,440 - INFO - Project ctest-TestRouters-54864994 not found, creating it
2026-07-30 14:52:10,005 - INFO - Created Project:ctest-TestRouters-54864994, ID : a3ca2e71-6b85-4b86-b8cf-1b3627fc0719
2026-07-30 14:52:11,919 - INFO - ================================================================================
2026-07-30 14:52:11,919 - INFO - STARTING TEST : test_basic_router_behavior
2026-07-30 14:52:11,919 - INFO - TEST DESCRIPTION : Validate a router is able to route packets between two VNs
Create a router
Create 2 VNs, and a VM in each
Add router port from each VN
Ping between VMs
2026-07-30 14:52:12,194 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with
2026-07-30 14:52:12,194 - INFO - Initial checks done. Running the testcase now
2026-07-30 14:52:12,194 - INFO -
2026-07-30 14:52:12,912 - DEBUG - Response for create_network : {'network': {'id': '5dc6ebb5-3216-470d-b458-f9fd9e5b39d3', 'name': 'ctest-vn1-71470285', 'tenant_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'project_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-54864994', 'ctest-vn1-71470285'], 'port_security_enabled': True, 'description': ''}}
2026-07-30 14:52:13,130 - DEBUG - Response for create_subnet : {'subnet': {'id': '0c058ef7-aad1-4bda-ac91-17e2ee0c7100', 'name': '', 'tenant_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'network_id': '5dc6ebb5-3216-470d-b458-f9fd9e5b39d3', 'ip_version': 4, 'cidr': '59.146.175.192/26', 'allocation_pools': [{'start': '59.146.175.194', 'end': '59.146.175.254'}], 'gateway_ip': '59.146.175.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '59.146.175.194', 'tags': [], 'project_id': 'a3ca2e716b854b86b8cf1b3627fc0719'}}
2026-07-30 14:52:13,151 - INFO - Created VN ctest-vn1-71470285
2026-07-30 14:52:13,207 - DEBUG - VN ctest-vn1-71470285 UUID is 5dc6ebb5-3216-470d-b458-f9fd9e5b39d3
2026-07-30 14:52:13,602 - DEBUG - Response for create_network : {'network': {'id': 'df8be42c-1878-49ad-a70a-6179d0707a80', 'name': 'ctest-vn2-73245750', 'tenant_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'project_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-54864994', 'ctest-vn2-73245750'], 'port_security_enabled': True, 'description': ''}}
2026-07-30 14:52:13,786 - DEBUG - Response for create_subnet : {'subnet': {'id': 'be9b1539-0426-47ad-9c35-8c3eff347ef3', 'name': '', 'tenant_id': 'a3ca2e716b854b86b8cf1b3627fc0719', 'network_id': 'df8be42c-1878-49ad-a70a-6179d0707a80', 'ip_version': 4, 'cidr': '175.126.211.192/26', 'allocation_pools': [{'start': '175.126.211.194', 'end': '175.126.211.254'}], 'gateway_ip': '175.126.211.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '175.126.211.194', 'tags': [], 'project_id': 'a3ca2e716b854b86b8cf1b3627fc0719'}}
2026-07-30 14:52:13,805 - INFO - Created VN ctest-vn2-73245750
2026-07-30 14:52:13,859 - DEBUG - VN ctest-vn2-73245750 UUID is df8be42c-1878-49ad-a70a-6179d0707a80
2026-07-30 14:52:14,306 - DEBUG - Services list from nova: [, , ]
2026-07-30 14:52:14,797 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6125-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6125-1)
2026-07-30 14:52:15,352 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6125-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6125-1)
2026-07-30 14:52:15,456 - INFO - Adding interface with subnet_id 0c058ef7-aad1-4bda-ac91-17e2ee0c7100, port_id None to router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:52:15,790 - INFO - Waiting for VM ctest-vn1-vm1-34876773 to be up..
2026-07-30 14:52:15,885 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:21,008 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:26,095 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:31,203 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:36,312 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:41,427 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:46,529 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:51,624 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-07-30 14:52:56,716 - DEBUG - VM is in ACTIVE state now
2026-07-30 14:52:56,716 - INFO - VM name : ctest-vn1-vm1-34876773
2026-07-30 14:52:56,805 - DEBUG - VM ctest-vn1-vm1-34876773 ID is d0f81fbf-6ca1-4c5a-a67d-4eb145a05d4f
2026-07-30 14:52:56,834 - DEBUG - VM ctest-vn1-vm1-34876773 launched on Node cn-jenkins-deploy-platform-ansible-os-6125-1
2026-07-30 14:52:56,934 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/d0f81fbf-6ca1-4c5a-a67d-4eb145a05d4f
2026-07-30 14:52:57,318 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/d0f81fbf-6ca1-4c5a-a67d-4eb145a05d4f
2026-07-30 14:52:57,355 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/7d764c02-0a7a-4a39-b92d-09eb463ea024
2026-07-30 14:53:00,619 - 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 1011ms')
2026-07-30 14:53:00,619 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-34876773 failed!
2026-07-30 14:53:00,679 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-54864994:ctest-vn1-71470285 is 59.146.175.193 and allocation pool is NOT set
2026-07-30 14:53:04,777 - 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=2 ttl=63 time=9.20 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1031ms\r\nrtt min/avg/max/mdev = 9.202/9.202/9.202/0.000 ms')
2026-07-30 14:53:04,777 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-34876773 passed
2026-07-30 14:53:04,935 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:04,935 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-34876773, IP 59.146.175.195, Port 22
2026-07-30 14:53:05,105 - DEBUG - VM ctest-vn1-vm1-34876773 is ready for SSH connections
2026-07-30 14:53:05,105 - INFO - Waiting for VM ctest-vn2-vm1-89378510 to be up..
2026-07-30 14:53:05,196 - DEBUG - VM is in ACTIVE state now
2026-07-30 14:53:05,196 - INFO - VM name : ctest-vn2-vm1-89378510
2026-07-30 14:53:05,282 - DEBUG - VM ctest-vn2-vm1-89378510 ID is dd60936f-4715-4e3c-b5a8-9612910d5127
2026-07-30 14:53:05,283 - DEBUG - VM ctest-vn2-vm1-89378510 launched on Node cn-jenkins-deploy-platform-ansible-os-6125-1
2026-07-30 14:53:05,370 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/dd60936f-4715-4e3c-b5a8-9612910d5127
2026-07-30 14:53:05,382 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/75621d06-9f07-46aa-a495-40814dd65978
2026-07-30 14:53:08,646 - 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=2 ttl=63 time=12.7 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1016ms\r\nrtt min/avg/max/mdev = 12.709/12.709/12.709/0.000 ms')
2026-07-30 14:53:08,646 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-89378510 passed
2026-07-30 14:53:08,799 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:08,799 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-89378510, IP 175.126.211.195, Port 22
2026-07-30 14:53:08,973 - DEBUG - VM ctest-vn2-vm1-89378510 is ready for SSH connections
2026-07-30 14:53:08,973 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:08,973 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 175.126.211.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-07-30 14:53:08,973 - DEBUG - ping -s 56 -c 3 -W 1 175.126.211.195
2026-07-30 14:53:14,120 - DEBUG - PING 175.126.211.195 (175.126.211.195): 56 data bytes
--- 175.126.211.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-07-30 14:53:14,120 - WARNING - Ping to IP 175.126.211.195 from VM ctest-vn1-vm1-34876773 failed
2026-07-30 14:53:14,120 - INFO - Adding interface with subnet_id be9b1539-0426-47ad-9c35-8c3eff347ef3, port_id None to router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:53:14,448 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:14,448 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 175.126.211.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-07-30 14:53:14,448 - DEBUG - ping -s 56 -c 3 -W 1 175.126.211.195
2026-07-30 14:53:17,587 - DEBUG - PING 175.126.211.195 (175.126.211.195): 56 data bytes
64 bytes from 175.126.211.195: seq=1 ttl=63 time=3.218 ms
64 bytes from 175.126.211.195: seq=2 ttl=63 time=1.074 ms
--- 175.126.211.195 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.074/2.146/3.218 ms
2026-07-30 14:53:17,587 - WARNING - Ping to IP 175.126.211.195 from VM ctest-vn1-vm1-34876773 failed
2026-07-30 14:53:18,587 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 175.126.211.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-07-30 14:53:18,588 - DEBUG - ping -s 56 -c 3 -W 1 175.126.211.195
2026-07-30 14:53:20,745 - DEBUG - PING 175.126.211.195 (175.126.211.195): 56 data bytes
64 bytes from 175.126.211.195: seq=0 ttl=63 time=1.993 ms
64 bytes from 175.126.211.195: seq=1 ttl=63 time=1.283 ms
64 bytes from 175.126.211.195: seq=2 ttl=63 time=1.304 ms
--- 175.126.211.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.283/1.526/1.993 ms
2026-07-30 14:53:20,745 - INFO - Ping to IP 175.126.211.195 from VM ctest-vn1-vm1-34876773 passed
2026-07-30 14:53:20,745 - INFO - Deleting interface with subnet_id 0c058ef7-aad1-4bda-ac91-17e2ee0c7100, port_id None from router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:53:20,932 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:20,932 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 175.126.211.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-07-30 14:53:20,932 - DEBUG - ping -s 56 -c 3 -W 1 175.126.211.195
2026-07-30 14:53:24,066 - DEBUG - PING 175.126.211.195 (175.126.211.195): 56 data bytes
--- 175.126.211.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-07-30 14:53:24,066 - WARNING - Ping to IP 175.126.211.195 from VM ctest-vn1-vm1-34876773 failed
2026-07-30 14:53:24,066 - INFO - Adding interface with subnet_id 0c058ef7-aad1-4bda-ac91-17e2ee0c7100, port_id None to router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:53:24,369 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-07-30 14:53:24,369 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 175.126.211.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2026-07-30 14:53:24,369 - DEBUG - ping -s 56 -c 3 -W 1 175.126.211.195
2026-07-30 14:53:26,522 - DEBUG - PING 175.126.211.195 (175.126.211.195): 56 data bytes
64 bytes from 175.126.211.195: seq=0 ttl=63 time=2.590 ms
64 bytes from 175.126.211.195: seq=1 ttl=63 time=1.341 ms
64 bytes from 175.126.211.195: seq=2 ttl=63 time=1.153 ms
--- 175.126.211.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.153/1.694/2.590 ms
2026-07-30 14:53:26,522 - INFO - Ping to IP 175.126.211.195 from VM ctest-vn1-vm1-34876773 passed
2026-07-30 14:53:26,522 - INFO - Deleting interface with subnet_id be9b1539-0426-47ad-9c35-8c3eff347ef3, port_id None from router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:53:26,714 - INFO - Deleting interface with subnet_id 0c058ef7-aad1-4bda-ac91-17e2ee0c7100, port_id None from router 9b38c803-1858-49e7-9c5f-72c3b669ced7
2026-07-30 14:53:26,994 - INFO - Deleting VM ctest-vn2-vm1-89378510
2026-07-30 14:53:27,095 - INFO - Deleting VM ctest-vn1-vm1-34876773
2026-07-30 14:53:27,188 - INFO - Deleting VN ctest-vn2-73245750
2026-07-30 14:53:27,225 - DEBUG - VN df8be42c-1878-49ad-a70a-6179d0707a80 still in use: Unable to complete operation on network df8be42c-1878-49ad-a70a-6179d0707a80. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-82df273c-a86a-4888-b74c-b384c511a30e']
2026-07-30 14:53:27,225 - WARNING - Deleting VN ctest-vn2-73245750 failed..Will retry
2026-07-30 14:53:29,305 - DEBUG - VN df8be42c-1878-49ad-a70a-6179d0707a80 still in use: Unable to complete operation on network df8be42c-1878-49ad-a70a-6179d0707a80. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-76e1cff4-472e-4eb9-b9aa-110b0371004e']
2026-07-30 14:53:29,306 - WARNING - Deleting VN ctest-vn2-73245750 failed..Will retry
2026-07-30 14:53:31,447 - DEBUG - Response for deleting network ()
2026-07-30 14:53:31,447 - INFO - Deleting VN ctest-vn1-71470285
2026-07-30 14:53:31,598 - DEBUG - Response for deleting network ()
2026-07-30 14:53:31,862 - DEBUG - No XMPP flaps were noticed during the test
2026-07-30 14:53:31,862 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:20]
2026-07-30 14:53:31,862 - INFO - --------------------------------------------------------------------------------
2026-07-30 14:53:32,889 - INFO - Deleted project: ctest-TestRouters-54864994, ID : a3ca2e71-6b85-4b86-b8cf-1b3627fc0719