2026-11-06 08:04:25,946 - INFO - Domain Default found not creating 2026-11-06 08:04:26,224 - INFO - Project ctest-TestRouters-43516644 not found, creating it 2026-11-06 08:04:26,840 - INFO - Created Project:ctest-TestRouters-43516644, ID : d8540875-30df-4372-9e9d-844618372ef5 2026-11-06 08:04:28,994 - INFO - ================================================================================ 2026-11-06 08:04:28,994 - INFO - STARTING TEST : test_basic_router_behavior 2026-11-06 08:04:28,994 - 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-06 08:04:29,279 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with 2026-11-06 08:04:29,279 - INFO - Initial checks done. Running the testcase now 2026-11-06 08:04:29,279 - INFO - 2026-11-06 08:04:30,070 - DEBUG - Response for create_network : {'network': {'id': '69897fa7-fbe5-4ec5-8e27-ee8c3b52c7cc', 'name': 'ctest-vn1-22847803', 'tenant_id': 'd854087530df43729e9d844618372ef5', 'project_id': 'd854087530df43729e9d844618372ef5', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-43516644', 'ctest-vn1-22847803'], 'port_security_enabled': True, 'description': ''}} 2026-11-06 08:04:30,335 - DEBUG - Response for create_subnet : {'subnet': {'id': 'be5fa3cd-1528-4b47-8e1a-d75e93d25105', 'name': '', 'tenant_id': 'd854087530df43729e9d844618372ef5', 'network_id': '69897fa7-fbe5-4ec5-8e27-ee8c3b52c7cc', 'ip_version': 4, 'cidr': '59.230.54.192/26', 'allocation_pools': [{'start': '59.230.54.194', 'end': '59.230.54.254'}], 'gateway_ip': '59.230.54.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '59.230.54.194', 'tags': [], 'project_id': 'd854087530df43729e9d844618372ef5'}} 2026-11-06 08:04:30,357 - INFO - Created VN ctest-vn1-22847803 2026-11-06 08:04:30,412 - DEBUG - VN ctest-vn1-22847803 UUID is 69897fa7-fbe5-4ec5-8e27-ee8c3b52c7cc 2026-11-06 08:04:30,783 - DEBUG - Response for create_network : {'network': {'id': 'cb260871-5862-49bc-987a-7b362ff323e0', 'name': 'ctest-vn2-99044378', 'tenant_id': 'd854087530df43729e9d844618372ef5', 'project_id': 'd854087530df43729e9d844618372ef5', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-43516644', 'ctest-vn2-99044378'], 'port_security_enabled': True, 'description': ''}} 2026-11-06 08:04:30,975 - DEBUG - Response for create_subnet : {'subnet': {'id': '75d6f4d9-7d75-4e05-b4c9-a5308768ffb3', 'name': '', 'tenant_id': 'd854087530df43729e9d844618372ef5', 'network_id': 'cb260871-5862-49bc-987a-7b362ff323e0', 'ip_version': 4, 'cidr': '16.124.98.192/26', 'allocation_pools': [{'start': '16.124.98.194', 'end': '16.124.98.254'}], 'gateway_ip': '16.124.98.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '16.124.98.194', 'tags': [], 'project_id': 'd854087530df43729e9d844618372ef5'}} 2026-11-06 08:04:31,000 - INFO - Created VN ctest-vn2-99044378 2026-11-06 08:04:31,059 - DEBUG - VN ctest-vn2-99044378 UUID is cb260871-5862-49bc-987a-7b362ff323e0 2026-11-06 08:04:31,454 - DEBUG - Services list from nova: [, , ] 2026-11-06 08:04:32,148 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6486-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6486-1) 2026-11-06 08:04:33,096 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6486-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6486-1) 2026-11-06 08:04:33,188 - INFO - Adding interface with subnet_id be5fa3cd-1528-4b47-8e1a-d75e93d25105, port_id None to router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:04:33,579 - INFO - Waiting for VM ctest-vn1-vm1-86401023 to be up.. 2026-11-06 08:04:33,675 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:04:38,780 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:04:43,884 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:04:48,984 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:04:54,086 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:04:59,183 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:05:04,314 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:05:09,447 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-11-06 08:05:14,566 - DEBUG - VM is in ACTIVE state now 2026-11-06 08:05:14,566 - INFO - VM name : ctest-vn1-vm1-86401023 2026-11-06 08:05:14,670 - DEBUG - VM ctest-vn1-vm1-86401023 ID is 33a3a71e-88d1-4287-9ff6-3b9f8499db66 2026-11-06 08:05:14,695 - DEBUG - VM ctest-vn1-vm1-86401023 launched on Node cn-jenkins-deploy-platform-ansible-os-6486-1 2026-11-06 08:05:14,792 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/33a3a71e-88d1-4287-9ff6-3b9f8499db66 2026-11-06 08:05:15,214 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/33a3a71e-88d1-4287-9ff6-3b9f8499db66 2026-11-06 08:05:15,260 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/ec553d0f-6bc3-4744-853a-2a1da34a592c 2026-11-06 08:05:18,561 - 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-11-06 08:05:18,561 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-86401023 failed! 2026-11-06 08:05:18,619 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-43516644:ctest-vn1-22847803 is 59.230.54.193 and allocation pool is NOT set 2026-11-06 08:05:20,692 - 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=3.84 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.600 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.600/2.222/3.844/1.622 ms') 2026-11-06 08:05:20,692 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-86401023 passed 2026-11-06 08:05:20,847 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:20,847 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-86401023, IP 59.230.54.195, Port 22 2026-11-06 08:05:21,021 - DEBUG - VM ctest-vn1-vm1-86401023 is ready for SSH connections 2026-11-06 08:05:21,021 - INFO - Waiting for VM ctest-vn2-vm1-19966695 to be up.. 2026-11-06 08:05:21,119 - DEBUG - VM is in ACTIVE state now 2026-11-06 08:05:21,119 - INFO - VM name : ctest-vn2-vm1-19966695 2026-11-06 08:05:21,218 - DEBUG - VM ctest-vn2-vm1-19966695 ID is f96a8deb-d677-46b5-b6ce-21baf5d55398 2026-11-06 08:05:21,219 - DEBUG - VM ctest-vn2-vm1-19966695 launched on Node cn-jenkins-deploy-platform-ansible-os-6486-1 2026-11-06 08:05:21,323 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/f96a8deb-d677-46b5-b6ce-21baf5d55398 2026-11-06 08:05:21,333 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/9f9b77e2-be26-4705-9b01-3045ba2399f3 2026-11-06 08:05:24,606 - 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 1022ms') 2026-11-06 08:05:24,606 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-19966695 failed! 2026-11-06 08:05:24,663 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-43516644:ctest-vn2-99044378 is 16.124.98.193 and allocation pool is NOT set 2026-11-06 08:05:26,735 - 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.74 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.07 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 = 1.065/3.403/5.742/2.338 ms') 2026-11-06 08:05:26,735 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-19966695 passed 2026-11-06 08:05:26,887 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:26,887 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-19966695, IP 16.124.98.195, Port 22 2026-11-06 08:05:27,065 - DEBUG - VM ctest-vn2-vm1-19966695 is ready for SSH connections 2026-11-06 08:05:27,065 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:27,066 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 16.124.98.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2026-11-06 08:05:27,066 - DEBUG - ping -s 56 -c 3 -W 1 16.124.98.195 2026-11-06 08:05:32,349 - DEBUG - PING 16.124.98.195 (16.124.98.195): 56 data bytes --- 16.124.98.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-11-06 08:05:32,349 - WARNING - Ping to IP 16.124.98.195 from VM ctest-vn1-vm1-86401023 failed 2026-11-06 08:05:32,349 - INFO - Adding interface with subnet_id 75d6f4d9-7d75-4e05-b4c9-a5308768ffb3, port_id None to router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:05:32,705 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:32,706 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 16.124.98.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2026-11-06 08:05:32,706 - DEBUG - ping -s 56 -c 3 -W 1 16.124.98.195 2026-11-06 08:05:35,912 - DEBUG - PING 16.124.98.195 (16.124.98.195): 56 data bytes 64 bytes from 16.124.98.195: seq=1 ttl=63 time=4.218 ms 64 bytes from 16.124.98.195: seq=2 ttl=63 time=1.079 ms --- 16.124.98.195 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.079/2.648/4.218 ms 2026-11-06 08:05:35,912 - WARNING - Ping to IP 16.124.98.195 from VM ctest-vn1-vm1-86401023 failed 2026-11-06 08:05:36,913 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 16.124.98.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2026-11-06 08:05:36,913 - DEBUG - ping -s 56 -c 3 -W 1 16.124.98.195 2026-11-06 08:05:39,125 - DEBUG - PING 16.124.98.195 (16.124.98.195): 56 data bytes 64 bytes from 16.124.98.195: seq=0 ttl=63 time=2.786 ms 64 bytes from 16.124.98.195: seq=1 ttl=63 time=1.219 ms 64 bytes from 16.124.98.195: seq=2 ttl=63 time=1.252 ms --- 16.124.98.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.219/1.752/2.786 ms 2026-11-06 08:05:39,125 - INFO - Ping to IP 16.124.98.195 from VM ctest-vn1-vm1-86401023 passed 2026-11-06 08:05:39,125 - INFO - Deleting interface with subnet_id be5fa3cd-1528-4b47-8e1a-d75e93d25105, port_id None from router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:05:39,319 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:39,319 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 16.124.98.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2026-11-06 08:05:39,319 - DEBUG - ping -s 56 -c 3 -W 1 16.124.98.195 2026-11-06 08:05:42,527 - DEBUG - PING 16.124.98.195 (16.124.98.195): 56 data bytes --- 16.124.98.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-11-06 08:05:42,527 - WARNING - Ping to IP 16.124.98.195 from VM ctest-vn1-vm1-86401023 failed 2026-11-06 08:05:42,527 - INFO - Adding interface with subnet_id be5fa3cd-1528-4b47-8e1a-d75e93d25105, port_id None to router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:05:42,812 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-11-06 08:05:42,813 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 16.124.98.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2026-11-06 08:05:42,813 - DEBUG - ping -s 56 -c 3 -W 1 16.124.98.195 2026-11-06 08:05:45,073 - DEBUG - PING 16.124.98.195 (16.124.98.195): 56 data bytes 64 bytes from 16.124.98.195: seq=0 ttl=63 time=3.099 ms 64 bytes from 16.124.98.195: seq=1 ttl=63 time=1.063 ms 64 bytes from 16.124.98.195: seq=2 ttl=63 time=1.219 ms --- 16.124.98.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.063/1.793/3.099 ms 2026-11-06 08:05:45,073 - INFO - Ping to IP 16.124.98.195 from VM ctest-vn1-vm1-86401023 passed 2026-11-06 08:05:45,073 - INFO - Deleting interface with subnet_id 75d6f4d9-7d75-4e05-b4c9-a5308768ffb3, port_id None from router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:05:45,258 - INFO - Deleting interface with subnet_id be5fa3cd-1528-4b47-8e1a-d75e93d25105, port_id None from router b9f65d2a-fd1e-4e10-a4e0-61b2947cb9db 2026-11-06 08:05:45,527 - INFO - Deleting VM ctest-vn2-vm1-19966695 2026-11-06 08:05:45,635 - INFO - Deleting VM ctest-vn1-vm1-86401023 2026-11-06 08:05:45,749 - INFO - Deleting VN ctest-vn2-99044378 2026-11-06 08:05:45,789 - DEBUG - VN cb260871-5862-49bc-987a-7b362ff323e0 still in use: Unable to complete operation on network cb260871-5862-49bc-987a-7b362ff323e0. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-1e28f718-294b-42e2-acd1-fd832ffb813f'] 2026-11-06 08:05:45,789 - WARNING - Deleting VN ctest-vn2-99044378 failed..Will retry 2026-11-06 08:05:47,831 - DEBUG - VN cb260871-5862-49bc-987a-7b362ff323e0 still in use: Unable to complete operation on network cb260871-5862-49bc-987a-7b362ff323e0. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-bf0e2766-52d6-4b38-8f63-1ca26d4e307d'] 2026-11-06 08:05:47,831 - WARNING - Deleting VN ctest-vn2-99044378 failed..Will retry 2026-11-06 08:05:49,972 - DEBUG - Response for deleting network () 2026-11-06 08:05:49,972 - INFO - Deleting VN ctest-vn1-22847803 2026-11-06 08:05:50,135 - DEBUG - Response for deleting network () 2026-11-06 08:05:50,407 - DEBUG - No XMPP flaps were noticed during the test
2026-11-06 08:05:50,407 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:22]
2026-11-06 08:05:50,407 - INFO - -------------------------------------------------------------------------------- 2026-11-06 08:05:51,292 - INFO - Deleted project: ctest-TestRouters-43516644, ID : d8540875-30df-4372-9e9d-844618372ef5