2026-11-02 10:18:29,146 - INFO - Domain Default found not creating 2026-11-02 10:18:29,359 - INFO - Project ctest-TestRouters-81056411 not found, creating it 2026-11-02 10:18:29,898 - INFO - Created Project:ctest-TestRouters-81056411, ID : 2384bd6c-f1f6-45e9-86ea-0a1348cd6bf2 2026-11-02 10:18:31,821 - INFO - ================================================================================ 2026-11-02 10:18:31,822 - INFO - STARTING TEST : test_basic_router_behavior 2026-11-02 10:18:31,822 - 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-11-02 10:18:32,104 - DEBUG - Nothing to compare xmpp stats {'10.0.0.38': {'10.20.0.29': '0'}} with 2026-11-02 10:18:32,104 - INFO - Initial checks done. Running the testcase now 2026-11-02 10:18:32,104 - INFO - 2026-11-02 10:18:32,741 - DEBUG - Response for create_network : {'network': {'id': '1264c877-748d-4c13-b179-ba30220fa515', 'name': 'ctest-vn1-09906226', 'tenant_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'project_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-81056411', 'ctest-vn1-09906226'], 'port_security_enabled': True, 'description': ''}} 2026-11-02 10:18:33,000 - DEBUG - Response for create_subnet : {'subnet': {'id': '46dc48a0-f6c6-472b-ab35-806c2d16a519', 'name': '', 'tenant_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'network_id': '1264c877-748d-4c13-b179-ba30220fa515', 'ip_version': 4, 'cidr': '161.204.22.64/26', 'allocation_pools': [{'start': '161.204.22.66', 'end': '161.204.22.126'}], 'gateway_ip': '161.204.22.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '161.204.22.66', 'tags': [], 'project_id': '2384bd6cf1f645e986ea0a1348cd6bf2'}} 2026-11-02 10:18:33,017 - INFO - Created VN ctest-vn1-09906226 2026-11-02 10:18:33,080 - DEBUG - VN ctest-vn1-09906226 UUID is 1264c877-748d-4c13-b179-ba30220fa515 2026-11-02 10:18:33,442 - DEBUG - Response for create_network : {'network': {'id': '94e11180-50a2-4e36-91c2-30d42f7d9948', 'name': 'ctest-vn2-24845465', 'tenant_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'project_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-81056411', 'ctest-vn2-24845465'], 'port_security_enabled': True, 'description': ''}} 2026-11-02 10:18:33,745 - DEBUG - Response for create_subnet : {'subnet': {'id': 'e9e657fb-de22-4df9-be30-7717b6d8d9e2', 'name': '', 'tenant_id': '2384bd6cf1f645e986ea0a1348cd6bf2', 'network_id': '94e11180-50a2-4e36-91c2-30d42f7d9948', 'ip_version': 4, 'cidr': '126.185.82.64/26', 'allocation_pools': [{'start': '126.185.82.66', 'end': '126.185.82.126'}], 'gateway_ip': '126.185.82.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '126.185.82.66', 'tags': [], 'project_id': '2384bd6cf1f645e986ea0a1348cd6bf2'}} 2026-11-02 10:18:33,764 - INFO - Created VN ctest-vn2-24845465 2026-11-02 10:18:33,823 - DEBUG - VN ctest-vn2-24845465 UUID is 94e11180-50a2-4e36-91c2-30d42f7d9948 2026-11-02 10:18:34,289 - DEBUG - Services list from nova: [, , ] 2026-11-02 10:18:34,710 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6463-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6463-1) 2026-11-02 10:18:35,423 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6463-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6463-1) 2026-11-02 10:18:35,498 - INFO - Adding interface with subnet_id 46dc48a0-f6c6-472b-ab35-806c2d16a519, port_id None to router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:18:35,753 - INFO - Waiting for VM ctest-vn1-vm1-81059759 to be up.. 2026-11-02 10:18:35,805 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:18:40,900 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:18:45,987 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:18:51,065 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:18:56,143 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:19:01,239 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:19:06,381 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:19:11,456 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-02 10:19:16,547 - DEBUG - VM is in ACTIVE state now 2026-11-02 10:19:16,547 - INFO - VM name : ctest-vn1-vm1-81059759 2026-11-02 10:19:16,642 - DEBUG - VM ctest-vn1-vm1-81059759 ID is 6ddc0606-7b47-44e9-9883-0b268d75be2e 2026-11-02 10:19:16,669 - DEBUG - VM ctest-vn1-vm1-81059759 launched on Node cn-jenkins-deploy-platform-ansible-os-6463-1 2026-11-02 10:19:16,759 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/6ddc0606-7b47-44e9-9883-0b268d75be2e 2026-11-02 10:19:17,143 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/6ddc0606-7b47-44e9-9883-0b268d75be2e 2026-11-02 10:19:17,180 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/37bfd61d-a0fb-4739-9031-b4347c763def 2026-11-02 10:19:20,429 - 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 1009ms') 2026-11-02 10:19:20,429 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-81059759 failed! 2026-11-02 10:19:20,483 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-81056411:ctest-vn1-09906226 is 161.204.22.65 and allocation pool is NOT set 2026-11-02 10:19:22,543 - 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=9.75 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.214 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.214/4.982/9.751/4.768 ms') 2026-11-02 10:19:22,543 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-81059759 passed 2026-11-02 10:19:22,695 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:22,695 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-81059759, IP 161.204.22.67, Port 22 2026-11-02 10:19:22,864 - DEBUG - VM ctest-vn1-vm1-81059759 is ready for SSH connections 2026-11-02 10:19:22,865 - INFO - Waiting for VM ctest-vn2-vm1-62390578 to be up.. 2026-11-02 10:19:22,944 - DEBUG - VM is in ACTIVE state now 2026-11-02 10:19:22,944 - INFO - VM name : ctest-vn2-vm1-62390578 2026-11-02 10:19:23,018 - DEBUG - VM ctest-vn2-vm1-62390578 ID is b381f3ac-1a4d-4c38-8541-9efb58fa0663 2026-11-02 10:19:23,018 - DEBUG - VM ctest-vn2-vm1-62390578 launched on Node cn-jenkins-deploy-platform-ansible-os-6463-1 2026-11-02 10:19:23,099 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine/b381f3ac-1a4d-4c38-8541-9efb58fa0663 2026-11-02 10:19:23,108 - DEBUG - Requesting: http://10.0.0.38:8082/virtual-machine-interface/d4917472-d30c-40d0-8486-800be5640b17 2026-11-02 10:19:26,351 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1001ms') 2026-11-02 10:19:26,351 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-62390578 failed! 2026-11-02 10:19:26,407 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-81056411:ctest-vn2-24845465 is 126.185.82.65 and allocation pool is NOT set 2026-11-02 10:19:28,474 - 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=3.44 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.513 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.513/1.975/3.438/1.462 ms') 2026-11-02 10:19:28,474 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-62390578 passed 2026-11-02 10:19:28,627 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:28,627 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-62390578, IP 126.185.82.67, Port 22 2026-11-02 10:19:28,782 - DEBUG - VM ctest-vn2-vm1-62390578 is ready for SSH connections 2026-11-02 10:19:28,782 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:28,783 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.185.82.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123 2026-11-02 10:19:28,783 - DEBUG - ping -s 56 -c 3 -W 1 126.185.82.67 2026-11-02 10:19:33,813 - DEBUG - PING 126.185.82.67 (126.185.82.67): 56 data bytes --- 126.185.82.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-11-02 10:19:33,813 - WARNING - Ping to IP 126.185.82.67 from VM ctest-vn1-vm1-81059759 failed 2026-11-02 10:19:33,813 - INFO - Adding interface with subnet_id e9e657fb-de22-4df9-be30-7717b6d8d9e2, port_id None to router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:19:34,077 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:34,078 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.185.82.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123 2026-11-02 10:19:34,078 - DEBUG - ping -s 56 -c 3 -W 1 126.185.82.67 2026-11-02 10:19:37,231 - DEBUG - PING 126.185.82.67 (126.185.82.67): 56 data bytes 64 bytes from 126.185.82.67: seq=1 ttl=63 time=3.019 ms 64 bytes from 126.185.82.67: seq=2 ttl=63 time=0.988 ms --- 126.185.82.67 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 0.988/2.003/3.019 ms 2026-11-02 10:19:37,231 - WARNING - Ping to IP 126.185.82.67 from VM ctest-vn1-vm1-81059759 failed 2026-11-02 10:19:38,232 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.185.82.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123 2026-11-02 10:19:38,232 - DEBUG - ping -s 56 -c 3 -W 1 126.185.82.67 2026-11-02 10:19:40,371 - DEBUG - PING 126.185.82.67 (126.185.82.67): 56 data bytes 64 bytes from 126.185.82.67: seq=0 ttl=63 time=1.359 ms 64 bytes from 126.185.82.67: seq=1 ttl=63 time=0.965 ms 64 bytes from 126.185.82.67: seq=2 ttl=63 time=0.842 ms --- 126.185.82.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.842/1.055/1.359 ms 2026-11-02 10:19:40,371 - INFO - Ping to IP 126.185.82.67 from VM ctest-vn1-vm1-81059759 passed 2026-11-02 10:19:40,371 - INFO - Deleting interface with subnet_id 46dc48a0-f6c6-472b-ab35-806c2d16a519, port_id None from router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:19:40,496 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:40,496 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.185.82.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123 2026-11-02 10:19:40,496 - DEBUG - ping -s 56 -c 3 -W 1 126.185.82.67 2026-11-02 10:19:43,659 - DEBUG - PING 126.185.82.67 (126.185.82.67): 56 data bytes --- 126.185.82.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-11-02 10:19:43,659 - WARNING - Ping to IP 126.185.82.67 from VM ctest-vn1-vm1-81059759 failed 2026-11-02 10:19:43,659 - INFO - Adding interface with subnet_id 46dc48a0-f6c6-472b-ab35-806c2d16a519, port_id None to router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:19:43,905 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-02 10:19:43,905 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 126.185.82.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.38, gateway password: c0ntrail123 2026-11-02 10:19:43,905 - DEBUG - ping -s 56 -c 3 -W 1 126.185.82.67 2026-11-02 10:19:46,037 - DEBUG - PING 126.185.82.67 (126.185.82.67): 56 data bytes 64 bytes from 126.185.82.67: seq=0 ttl=63 time=2.009 ms 64 bytes from 126.185.82.67: seq=1 ttl=63 time=0.902 ms 64 bytes from 126.185.82.67: seq=2 ttl=63 time=1.008 ms --- 126.185.82.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.902/1.306/2.009 ms 2026-11-02 10:19:46,037 - INFO - Ping to IP 126.185.82.67 from VM ctest-vn1-vm1-81059759 passed 2026-11-02 10:19:46,037 - INFO - Deleting interface with subnet_id e9e657fb-de22-4df9-be30-7717b6d8d9e2, port_id None from router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:19:46,152 - INFO - Deleting interface with subnet_id 46dc48a0-f6c6-472b-ab35-806c2d16a519, port_id None from router 8144d905-b87f-459f-888a-652627017b9a 2026-11-02 10:19:46,359 - INFO - Deleting VM ctest-vn2-vm1-62390578 2026-11-02 10:19:46,512 - INFO - Deleting VM ctest-vn1-vm1-81059759 2026-11-02 10:19:46,648 - INFO - Deleting VN ctest-vn2-24845465 2026-11-02 10:19:46,695 - DEBUG - VN 94e11180-50a2-4e36-91c2-30d42f7d9948 still in use: Unable to complete operation on network 94e11180-50a2-4e36-91c2-30d42f7d9948. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-64c2f114-a665-4f31-9c79-1f4c28a11bd0'] 2026-11-02 10:19:46,695 - WARNING - Deleting VN ctest-vn2-24845465 failed..Will retry 2026-11-02 10:19:48,730 - DEBUG - VN 94e11180-50a2-4e36-91c2-30d42f7d9948 still in use: Unable to complete operation on network 94e11180-50a2-4e36-91c2-30d42f7d9948. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-2a300af7-bb34-44de-9cbe-6aa41f29b5f1'] 2026-11-02 10:19:48,730 - WARNING - Deleting VN ctest-vn2-24845465 failed..Will retry 2026-11-02 10:19:50,909 - DEBUG - Response for deleting network () 2026-11-02 10:19:50,909 - INFO - Deleting VN ctest-vn1-09906226 2026-11-02 10:19:51,114 - DEBUG - Response for deleting network () 2026-11-02 10:19:51,383 - DEBUG - No XMPP flaps were noticed during the test
2026-11-02 10:19:51,383 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:20]
2026-11-02 10:19:51,383 - INFO - -------------------------------------------------------------------------------- 2026-11-02 10:19:52,211 - INFO - Deleted project: ctest-TestRouters-81056411, ID : 2384bd6c-f1f6-45e9-86ea-0a1348cd6bf2