2026-10-29 18:48:24,597 - INFO - Domain Default found not creating 2026-10-29 18:48:24,902 - INFO - Project ctest-TestRouters-82103111 not found, creating it 2026-10-29 18:48:25,540 - INFO - Created Project:ctest-TestRouters-82103111, ID : fdd615e9-5deb-45af-aa32-2f19a6cdccf4 2026-10-29 18:48:27,688 - INFO - ================================================================================ 2026-10-29 18:48:27,688 - INFO - STARTING TEST : test_basic_router_behavior 2026-10-29 18:48:27,688 - 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-10-29 18:48:27,977 - DEBUG - Nothing to compare xmpp stats {'10.0.0.251': {'10.20.0.254': '0'}} with 2026-10-29 18:48:27,977 - INFO - Initial checks done. Running the testcase now 2026-10-29 18:48:27,977 - INFO - 2026-10-29 18:48:28,743 - DEBUG - Response for create_network : {'network': {'id': 'fca923c8-73b6-4ef0-a257-05dad4cf6812', 'name': 'ctest-vn1-78921816', 'tenant_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'project_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-82103111', 'ctest-vn1-78921816'], 'port_security_enabled': True, 'description': ''}} 2026-10-29 18:48:29,015 - DEBUG - Response for create_subnet : {'subnet': {'id': '86f52003-5b2f-4972-b380-6c68f8d12fba', 'name': '', 'tenant_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'network_id': 'fca923c8-73b6-4ef0-a257-05dad4cf6812', 'ip_version': 4, 'cidr': '201.142.31.192/26', 'allocation_pools': [{'start': '201.142.31.194', 'end': '201.142.31.254'}], 'gateway_ip': '201.142.31.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '201.142.31.194', 'tags': [], 'project_id': 'fdd615e95deb45afaa322f19a6cdccf4'}} 2026-10-29 18:48:29,042 - INFO - Created VN ctest-vn1-78921816 2026-10-29 18:48:29,105 - DEBUG - VN ctest-vn1-78921816 UUID is fca923c8-73b6-4ef0-a257-05dad4cf6812 2026-10-29 18:48:29,495 - DEBUG - Response for create_network : {'network': {'id': '40b1a198-cc4e-4a37-be91-175aef459b1f', 'name': 'ctest-vn2-33353587', 'tenant_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'project_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-82103111', 'ctest-vn2-33353587'], 'port_security_enabled': True, 'description': ''}} 2026-10-29 18:48:29,786 - DEBUG - Response for create_subnet : {'subnet': {'id': '234ab5e8-e87b-41ef-9d1e-852d006a0b62', 'name': '', 'tenant_id': 'fdd615e95deb45afaa322f19a6cdccf4', 'network_id': '40b1a198-cc4e-4a37-be91-175aef459b1f', 'ip_version': 4, 'cidr': '214.150.108.0/26', 'allocation_pools': [{'start': '214.150.108.2', 'end': '214.150.108.62'}], 'gateway_ip': '214.150.108.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '214.150.108.2', 'tags': [], 'project_id': 'fdd615e95deb45afaa322f19a6cdccf4'}} 2026-10-29 18:48:29,809 - INFO - Created VN ctest-vn2-33353587 2026-10-29 18:48:29,872 - DEBUG - VN ctest-vn2-33353587 UUID is 40b1a198-cc4e-4a37-be91-175aef459b1f 2026-10-29 18:48:30,302 - DEBUG - Services list from nova: [, , ] 2026-10-29 18:48:31,004 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6439-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6439-1) 2026-10-29 18:48:31,657 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6439-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6439-1) 2026-10-29 18:48:31,764 - INFO - Adding interface with subnet_id 86f52003-5b2f-4972-b380-6c68f8d12fba, port_id None to router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:48:32,076 - INFO - Waiting for VM ctest-vn1-vm1-10918960 to be up.. 2026-10-29 18:48:32,148 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:37,265 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:42,412 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:47,515 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:52,637 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:57,740 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:49:02,920 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:49:08,063 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:49:13,212 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:49:18,321 - DEBUG - VM is in ACTIVE state now 2026-10-29 18:49:18,321 - INFO - VM name : ctest-vn1-vm1-10918960 2026-10-29 18:49:18,423 - DEBUG - VM ctest-vn1-vm1-10918960 ID is 8b661663-722d-4a94-957d-12b47ef5627f 2026-10-29 18:49:18,450 - DEBUG - VM ctest-vn1-vm1-10918960 launched on Node cn-jenkins-deploy-platform-ansible-os-6439-1 2026-10-29 18:49:18,556 - DEBUG - Requesting: http://10.0.0.251:8082/virtual-machine/8b661663-722d-4a94-957d-12b47ef5627f 2026-10-29 18:49:18,952 - DEBUG - Requesting: http://10.0.0.251:8082/virtual-machine/8b661663-722d-4a94-957d-12b47ef5627f 2026-10-29 18:49:18,999 - DEBUG - Requesting: http://10.0.0.251:8082/virtual-machine-interface/779c1f71-574e-4eef-847c-23c9c3d054b0 2026-10-29 18:49:22,282 - 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 1017ms') 2026-10-29 18:49:22,282 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10918960 failed! 2026-10-29 18:49:22,344 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-82103111:ctest-vn1-78921816 is 201.142.31.193 and allocation pool is NOT set 2026-10-29 18:49:26,442 - 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 1028ms') 2026-10-29 18:49:26,442 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10918960 failed! 2026-10-29 18:49:26,508 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-82103111:ctest-vn1-78921816 is 201.142.31.193 and allocation pool is NOT set 2026-10-29 18:49:28,584 - 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=6.23 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.642 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 = 0.642/3.435/6.228/2.793 ms') 2026-10-29 18:49:28,584 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10918960 passed 2026-10-29 18:49:28,748 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:28,748 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-10918960, IP 201.142.31.195, Port 22 2026-10-29 18:49:28,922 - DEBUG - VM ctest-vn1-vm1-10918960 is ready for SSH connections 2026-10-29 18:49:28,922 - INFO - Waiting for VM ctest-vn2-vm1-35810869 to be up.. 2026-10-29 18:49:29,040 - DEBUG - VM is in ACTIVE state now 2026-10-29 18:49:29,041 - INFO - VM name : ctest-vn2-vm1-35810869 2026-10-29 18:49:29,146 - DEBUG - VM ctest-vn2-vm1-35810869 ID is 83e62944-6587-4ce9-b3ae-04aac7be89e2 2026-10-29 18:49:29,146 - DEBUG - VM ctest-vn2-vm1-35810869 launched on Node cn-jenkins-deploy-platform-ansible-os-6439-1 2026-10-29 18:49:29,253 - DEBUG - Requesting: http://10.0.0.251:8082/virtual-machine/83e62944-6587-4ce9-b3ae-04aac7be89e2 2026-10-29 18:49:29,267 - DEBUG - Requesting: http://10.0.0.251:8082/virtual-machine-interface/738c7efa-a141-47ee-ac35-81f91b1b01a3 2026-10-29 18:49:30,537 - 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=11.8 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.778 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.778/6.278/11.779/5.500 ms') 2026-10-29 18:49:30,537 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-35810869 passed 2026-10-29 18:49:30,696 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:30,696 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-35810869, IP 214.150.108.3, Port 22 2026-10-29 18:49:30,767 - 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-10-29 18:49:30,888 - DEBUG - VM ctest-vn2-vm1-35810869 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-29 18:49:35,888 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:35,889 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-35810869, IP 214.150.108.3, Port 22 2026-10-29 18:49:36,062 - DEBUG - VM ctest-vn2-vm1-35810869 is ready for SSH connections 2026-10-29 18:49:36,063 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:36,063 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 214.150.108.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.251, gateway password: c0ntrail123 2026-10-29 18:49:36,063 - DEBUG - ping -s 56 -c 3 -W 1 214.150.108.3 2026-10-29 18:49:41,263 - DEBUG - PING 214.150.108.3 (214.150.108.3): 56 data bytes --- 214.150.108.3 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-29 18:49:41,264 - WARNING - Ping to IP 214.150.108.3 from VM ctest-vn1-vm1-10918960 failed 2026-10-29 18:49:41,264 - INFO - Adding interface with subnet_id 234ab5e8-e87b-41ef-9d1e-852d006a0b62, port_id None to router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:49:41,656 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:41,656 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 214.150.108.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.251, gateway password: c0ntrail123 2026-10-29 18:49:41,656 - DEBUG - ping -s 56 -c 3 -W 1 214.150.108.3 2026-10-29 18:49:44,816 - DEBUG - PING 214.150.108.3 (214.150.108.3): 56 data bytes 64 bytes from 214.150.108.3: seq=1 ttl=63 time=4.051 ms 64 bytes from 214.150.108.3: seq=2 ttl=63 time=1.358 ms --- 214.150.108.3 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.358/2.704/4.051 ms 2026-10-29 18:49:44,816 - WARNING - Ping to IP 214.150.108.3 from VM ctest-vn1-vm1-10918960 failed 2026-10-29 18:49:45,817 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 214.150.108.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.251, gateway password: c0ntrail123 2026-10-29 18:49:45,817 - DEBUG - ping -s 56 -c 3 -W 1 214.150.108.3 2026-10-29 18:49:47,965 - DEBUG - PING 214.150.108.3 (214.150.108.3): 56 data bytes 64 bytes from 214.150.108.3: seq=0 ttl=63 time=1.612 ms 64 bytes from 214.150.108.3: seq=1 ttl=63 time=1.068 ms 64 bytes from 214.150.108.3: seq=2 ttl=63 time=1.013 ms --- 214.150.108.3 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.013/1.231/1.612 ms 2026-10-29 18:49:47,966 - INFO - Ping to IP 214.150.108.3 from VM ctest-vn1-vm1-10918960 passed 2026-10-29 18:49:47,966 - INFO - Deleting interface with subnet_id 86f52003-5b2f-4972-b380-6c68f8d12fba, port_id None from router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:49:48,132 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:48,133 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 214.150.108.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.251, gateway password: c0ntrail123 2026-10-29 18:49:48,133 - DEBUG - ping -s 56 -c 3 -W 1 214.150.108.3 2026-10-29 18:49:51,282 - DEBUG - PING 214.150.108.3 (214.150.108.3): 56 data bytes --- 214.150.108.3 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-29 18:49:51,283 - WARNING - Ping to IP 214.150.108.3 from VM ctest-vn1-vm1-10918960 failed 2026-10-29 18:49:51,283 - INFO - Adding interface with subnet_id 86f52003-5b2f-4972-b380-6c68f8d12fba, port_id None to router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:49:51,585 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:51,586 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 214.150.108.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.251, gateway password: c0ntrail123 2026-10-29 18:49:51,586 - DEBUG - ping -s 56 -c 3 -W 1 214.150.108.3 2026-10-29 18:49:53,728 - DEBUG - PING 214.150.108.3 (214.150.108.3): 56 data bytes 64 bytes from 214.150.108.3: seq=0 ttl=63 time=1.675 ms 64 bytes from 214.150.108.3: seq=1 ttl=63 time=1.028 ms 64 bytes from 214.150.108.3: seq=2 ttl=63 time=0.936 ms --- 214.150.108.3 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.936/1.213/1.675 ms 2026-10-29 18:49:53,728 - INFO - Ping to IP 214.150.108.3 from VM ctest-vn1-vm1-10918960 passed 2026-10-29 18:49:53,729 - INFO - Deleting interface with subnet_id 234ab5e8-e87b-41ef-9d1e-852d006a0b62, port_id None from router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:49:53,910 - INFO - Deleting interface with subnet_id 86f52003-5b2f-4972-b380-6c68f8d12fba, port_id None from router 8984d6be-2900-459f-8f28-54b558087846 2026-10-29 18:49:54,178 - INFO - Deleting VM ctest-vn2-vm1-35810869 2026-10-29 18:49:54,291 - INFO - Deleting VM ctest-vn1-vm1-10918960 2026-10-29 18:49:54,397 - INFO - Deleting VN ctest-vn2-33353587 2026-10-29 18:49:54,442 - DEBUG - VN 40b1a198-cc4e-4a37-be91-175aef459b1f still in use: Unable to complete operation on network 40b1a198-cc4e-4a37-be91-175aef459b1f. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-31f7cfd8-e8d8-447f-adca-fe7d88a5475f'] 2026-10-29 18:49:54,442 - WARNING - Deleting VN ctest-vn2-33353587 failed..Will retry 2026-10-29 18:49:56,486 - DEBUG - VN 40b1a198-cc4e-4a37-be91-175aef459b1f still in use: Unable to complete operation on network 40b1a198-cc4e-4a37-be91-175aef459b1f. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-7c8169a4-93d9-4f3f-9eec-bbcf9a534e8f'] 2026-10-29 18:49:56,486 - WARNING - Deleting VN ctest-vn2-33353587 failed..Will retry 2026-10-29 18:49:58,607 - DEBUG - Response for deleting network () 2026-10-29 18:49:58,607 - INFO - Deleting VN ctest-vn1-78921816 2026-10-29 18:49:58,737 - DEBUG - Response for deleting network () 2026-10-29 18:49:59,013 - DEBUG - No XMPP flaps were noticed during the test
2026-10-29 18:49:59,013 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:32]
2026-10-29 18:49:59,013 - INFO - -------------------------------------------------------------------------------- 2026-10-29 18:49:59,983 - INFO - Deleted project: ctest-TestRouters-82103111, ID : fdd615e9-5deb-45af-aa32-2f19a6cdccf4