2026-09-21 21:52:40,397 - INFO - Domain Default found not creating 2026-09-21 21:52:40,631 - INFO - Project ctest-TestRouters-43398104 not found, creating it 2026-09-21 21:52:42,044 - INFO - Created Project:ctest-TestRouters-43398104, ID : f081486c-21a1-43ce-807f-2b1a85f7e4de 2026-09-21 21:52:44,071 - INFO - ================================================================================ 2026-09-21 21:52:44,071 - INFO - STARTING TEST : test_basic_router_behavior 2026-09-21 21:52:44,071 - 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-09-21 21:52:44,349 - DEBUG - Nothing to compare xmpp stats {'10.0.0.161': {'10.20.0.17': '0'}} with 2026-09-21 21:52:44,349 - INFO - Initial checks done. Running the testcase now 2026-09-21 21:52:44,349 - INFO - 2026-09-21 21:52:45,096 - DEBUG - Response for create_network : {'network': {'id': 'c56b8523-1752-4adf-b6c7-2d704db0549c', 'name': 'ctest-vn1-33933931', 'tenant_id': 'f081486c21a143ce807f2b1a85f7e4de', 'project_id': 'f081486c21a143ce807f2b1a85f7e4de', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-43398104', 'ctest-vn1-33933931'], 'port_security_enabled': True, 'description': ''}} 2026-09-21 21:52:45,333 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f40eec7e-94b1-49ad-be99-ba1fb4c699bb', 'name': '', 'tenant_id': 'f081486c21a143ce807f2b1a85f7e4de', 'network_id': 'c56b8523-1752-4adf-b6c7-2d704db0549c', 'ip_version': 4, 'cidr': '18.231.76.128/26', 'allocation_pools': [{'start': '18.231.76.130', 'end': '18.231.76.190'}], 'gateway_ip': '18.231.76.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '18.231.76.130', 'tags': [], 'project_id': 'f081486c21a143ce807f2b1a85f7e4de'}} 2026-09-21 21:52:45,355 - INFO - Created VN ctest-vn1-33933931 2026-09-21 21:52:45,414 - DEBUG - VN ctest-vn1-33933931 UUID is c56b8523-1752-4adf-b6c7-2d704db0549c 2026-09-21 21:52:45,816 - DEBUG - Response for create_network : {'network': {'id': '373f16a5-3aee-4611-b9f6-df64804d94e6', 'name': 'ctest-vn2-85001466', 'tenant_id': 'f081486c21a143ce807f2b1a85f7e4de', 'project_id': 'f081486c21a143ce807f2b1a85f7e4de', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-43398104', 'ctest-vn2-85001466'], 'port_security_enabled': True, 'description': ''}} 2026-09-21 21:52:46,097 - DEBUG - Response for create_subnet : {'subnet': {'id': '5d3e1128-0c7f-4d4f-91bc-67e96ba3e177', 'name': '', 'tenant_id': 'f081486c21a143ce807f2b1a85f7e4de', 'network_id': '373f16a5-3aee-4611-b9f6-df64804d94e6', 'ip_version': 4, 'cidr': '119.61.32.128/26', 'allocation_pools': [{'start': '119.61.32.130', 'end': '119.61.32.190'}], 'gateway_ip': '119.61.32.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '119.61.32.130', 'tags': [], 'project_id': 'f081486c21a143ce807f2b1a85f7e4de'}} 2026-09-21 21:52:46,120 - INFO - Created VN ctest-vn2-85001466 2026-09-21 21:52:46,182 - DEBUG - VN ctest-vn2-85001466 UUID is 373f16a5-3aee-4611-b9f6-df64804d94e6 2026-09-21 21:52:46,699 - DEBUG - Services list from nova: [, , ] 2026-09-21 21:52:47,222 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6316-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6316-1) 2026-09-21 21:52:47,845 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6316-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6316-1) 2026-09-21 21:52:47,958 - INFO - Adding interface with subnet_id f40eec7e-94b1-49ad-be99-ba1fb4c699bb, port_id None to router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:52:48,400 - INFO - Waiting for VM ctest-vn1-vm1-10784021 to be up.. 2026-09-21 21:52:48,509 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:52:53,580 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:52:58,720 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:03,837 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:08,943 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:14,056 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:19,168 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:24,277 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:29,400 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-09-21 21:53:34,513 - DEBUG - VM is in ACTIVE state now 2026-09-21 21:53:34,513 - INFO - VM name : ctest-vn1-vm1-10784021 2026-09-21 21:53:34,622 - DEBUG - VM ctest-vn1-vm1-10784021 ID is 6b112891-84b8-42d1-af4b-7aac466efe78 2026-09-21 21:53:34,646 - DEBUG - VM ctest-vn1-vm1-10784021 launched on Node cn-jenkins-deploy-platform-ansible-os-6316-1 2026-09-21 21:53:34,759 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/6b112891-84b8-42d1-af4b-7aac466efe78 2026-09-21 21:53:35,282 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/6b112891-84b8-42d1-af4b-7aac466efe78 2026-09-21 21:53:35,323 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/e713f0ee-88ab-4aa3-b68f-71b121a81be4 2026-09-21 21:53:38,580 - 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 1001ms') 2026-09-21 21:53:38,581 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10784021 failed! 2026-09-21 21:53:38,638 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-43398104:ctest-vn1-33933931 is 18.231.76.129 and allocation pool is NOT set 2026-09-21 21:53:40,712 - 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=12.8 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.706 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.706/6.730/12.754/6.024 ms') 2026-09-21 21:53:40,712 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10784021 passed 2026-09-21 21:53:40,878 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:53:40,878 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-10784021, IP 18.231.76.131, Port 22 2026-09-21 21:53:41,053 - DEBUG - VM ctest-vn1-vm1-10784021 is ready for SSH connections 2026-09-21 21:53:41,053 - INFO - Waiting for VM ctest-vn2-vm1-54061023 to be up.. 2026-09-21 21:53:41,192 - DEBUG - VM is in ACTIVE state now 2026-09-21 21:53:41,192 - INFO - VM name : ctest-vn2-vm1-54061023 2026-09-21 21:53:41,322 - DEBUG - VM ctest-vn2-vm1-54061023 ID is 67f050dd-e02a-46a5-b242-7d171f4cf96a 2026-09-21 21:53:41,322 - DEBUG - VM ctest-vn2-vm1-54061023 launched on Node cn-jenkins-deploy-platform-ansible-os-6316-1 2026-09-21 21:53:41,435 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/67f050dd-e02a-46a5-b242-7d171f4cf96a 2026-09-21 21:53:41,451 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/44434a37-f20d-4f83-8361-1edf3abc4667 2026-09-21 21:53:44,723 - 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 1011ms') 2026-09-21 21:53:44,724 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-54061023 failed! 2026-09-21 21:53:44,782 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-43398104:ctest-vn2-85001466 is 119.61.32.129 and allocation pool is NOT set 2026-09-21 21:53:46,852 - 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.56 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.643 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 = 0.643/3.099/5.555/2.456 ms') 2026-09-21 21:53:46,852 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-54061023 passed 2026-09-21 21:53:47,010 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:53:47,010 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-54061023, IP 119.61.32.131, Port 22 2026-09-21 21:53:47,182 - DEBUG - VM ctest-vn2-vm1-54061023 is ready for SSH connections 2026-09-21 21:53:47,182 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:53:47,182 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 119.61.32.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-09-21 21:53:47,182 - DEBUG - ping -s 56 -c 3 -W 1 119.61.32.131 2026-09-21 21:53:52,347 - DEBUG - PING 119.61.32.131 (119.61.32.131): 56 data bytes --- 119.61.32.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-09-21 21:53:52,348 - WARNING - Ping to IP 119.61.32.131 from VM ctest-vn1-vm1-10784021 failed 2026-09-21 21:53:52,348 - INFO - Adding interface with subnet_id 5d3e1128-0c7f-4d4f-91bc-67e96ba3e177, port_id None to router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:53:52,777 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:53:52,777 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 119.61.32.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-09-21 21:53:52,777 - DEBUG - ping -s 56 -c 3 -W 1 119.61.32.131 2026-09-21 21:53:56,052 - DEBUG - PING 119.61.32.131 (119.61.32.131): 56 data bytes 64 bytes from 119.61.32.131: seq=1 ttl=63 time=3.491 ms 64 bytes from 119.61.32.131: seq=2 ttl=63 time=1.903 ms --- 119.61.32.131 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.903/2.697/3.491 ms 2026-09-21 21:53:56,053 - WARNING - Ping to IP 119.61.32.131 from VM ctest-vn1-vm1-10784021 failed 2026-09-21 21:53:57,054 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 119.61.32.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-09-21 21:53:57,054 - DEBUG - ping -s 56 -c 3 -W 1 119.61.32.131 2026-09-21 21:53:59,274 - DEBUG - PING 119.61.32.131 (119.61.32.131): 56 data bytes 64 bytes from 119.61.32.131: seq=0 ttl=63 time=2.235 ms 64 bytes from 119.61.32.131: seq=1 ttl=63 time=1.388 ms 64 bytes from 119.61.32.131: seq=2 ttl=63 time=1.349 ms --- 119.61.32.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.349/1.657/2.235 ms 2026-09-21 21:53:59,274 - INFO - Ping to IP 119.61.32.131 from VM ctest-vn1-vm1-10784021 passed 2026-09-21 21:53:59,274 - INFO - Deleting interface with subnet_id f40eec7e-94b1-49ad-be99-ba1fb4c699bb, port_id None from router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:53:59,483 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:53:59,483 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 119.61.32.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-09-21 21:53:59,484 - DEBUG - ping -s 56 -c 3 -W 1 119.61.32.131 2026-09-21 21:54:02,740 - DEBUG - PING 119.61.32.131 (119.61.32.131): 56 data bytes --- 119.61.32.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-09-21 21:54:02,740 - WARNING - Ping to IP 119.61.32.131 from VM ctest-vn1-vm1-10784021 failed 2026-09-21 21:54:02,740 - INFO - Adding interface with subnet_id f40eec7e-94b1-49ad-be99-ba1fb4c699bb, port_id None to router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:54:03,105 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-09-21 21:54:03,105 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 119.61.32.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123 2026-09-21 21:54:03,105 - DEBUG - ping -s 56 -c 3 -W 1 119.61.32.131 2026-09-21 21:54:05,359 - DEBUG - PING 119.61.32.131 (119.61.32.131): 56 data bytes 64 bytes from 119.61.32.131: seq=0 ttl=63 time=2.663 ms 64 bytes from 119.61.32.131: seq=1 ttl=63 time=1.298 ms 64 bytes from 119.61.32.131: seq=2 ttl=63 time=1.337 ms --- 119.61.32.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.298/1.766/2.663 ms 2026-09-21 21:54:05,360 - INFO - Ping to IP 119.61.32.131 from VM ctest-vn1-vm1-10784021 passed 2026-09-21 21:54:05,360 - INFO - Deleting interface with subnet_id 5d3e1128-0c7f-4d4f-91bc-67e96ba3e177, port_id None from router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:54:05,585 - INFO - Deleting interface with subnet_id f40eec7e-94b1-49ad-be99-ba1fb4c699bb, port_id None from router c187bd4e-d927-48f9-a1f8-1b84a32e59c2 2026-09-21 21:54:05,898 - INFO - Deleting VM ctest-vn2-vm1-54061023 2026-09-21 21:54:06,009 - INFO - Deleting VM ctest-vn1-vm1-10784021 2026-09-21 21:54:06,111 - INFO - Deleting VN ctest-vn2-85001466 2026-09-21 21:54:06,157 - DEBUG - VN 373f16a5-3aee-4611-b9f6-df64804d94e6 still in use: Unable to complete operation on network 373f16a5-3aee-4611-b9f6-df64804d94e6. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-5c960b3a-74cc-4f20-b7b0-c951b33b044b'] 2026-09-21 21:54:06,157 - WARNING - Deleting VN ctest-vn2-85001466 failed..Will retry 2026-09-21 21:54:08,202 - DEBUG - VN 373f16a5-3aee-4611-b9f6-df64804d94e6 still in use: Unable to complete operation on network 373f16a5-3aee-4611-b9f6-df64804d94e6. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-a83ffa12-a395-4cf3-b0dc-318e9f95c9f5'] 2026-09-21 21:54:08,202 - WARNING - Deleting VN ctest-vn2-85001466 failed..Will retry 2026-09-21 21:54:10,399 - DEBUG - Response for deleting network () 2026-09-21 21:54:10,400 - INFO - Deleting VN ctest-vn1-33933931 2026-09-21 21:54:10,579 - DEBUG - Response for deleting network () 2026-09-21 21:54:10,862 - DEBUG - No XMPP flaps were noticed during the test
2026-09-21 21:54:10,862 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:26]
2026-09-21 21:54:10,862 - INFO - -------------------------------------------------------------------------------- 2026-09-21 21:54:11,751 - INFO - Deleted project: ctest-TestRouters-43398104, ID : f081486c-21a1-43ce-807f-2b1a85f7e4de