2025-10-22 12:56:32,334 - INFO - Domain Default found not creating 2025-10-22 12:56:32,637 - INFO - Project ctest-TestRouters-75145792 not found, creating it 2025-10-22 12:56:33,170 - INFO - Created Project:ctest-TestRouters-75145792, ID : 429fa472-d3f8-4019-8675-839aa0ba4d11 2025-10-22 12:56:34,924 - INFO - ================================================================================ 2025-10-22 12:56:34,924 - INFO - STARTING TEST : test_basic_router_behavior 2025-10-22 12:56:34,924 - 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 2025-10-22 12:56:35,196 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.14': '0'}} with 2025-10-22 12:56:35,196 - INFO - Initial checks done. Running the testcase now 2025-10-22 12:56:35,196 - INFO - 2025-10-22 12:56:35,828 - DEBUG - Response for create_network : {'network': {'id': '7079e7d3-ce79-49ac-ac45-3a7c9b28aff6', 'name': 'ctest-vn1-24087229', 'tenant_id': '429fa472d3f840198675839aa0ba4d11', 'project_id': '429fa472d3f840198675839aa0ba4d11', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-75145792', 'ctest-vn1-24087229'], 'port_security_enabled': True, 'description': ''}} 2025-10-22 12:56:36,018 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b3d34d2b-1e4c-490d-8759-a888d881dac6', 'name': '', 'tenant_id': '429fa472d3f840198675839aa0ba4d11', 'network_id': '7079e7d3-ce79-49ac-ac45-3a7c9b28aff6', 'ip_version': 4, 'cidr': '186.87.209.192/26', 'allocation_pools': [{'start': '186.87.209.194', 'end': '186.87.209.254'}], 'gateway_ip': '186.87.209.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '186.87.209.194', 'tags': [], 'project_id': '429fa472d3f840198675839aa0ba4d11'}} 2025-10-22 12:56:36,036 - INFO - Created VN ctest-vn1-24087229 2025-10-22 12:56:36,086 - DEBUG - VN ctest-vn1-24087229 UUID is 7079e7d3-ce79-49ac-ac45-3a7c9b28aff6 2025-10-22 12:56:36,392 - DEBUG - Response for create_network : {'network': {'id': '917cfc63-b001-4bbc-90f4-9de67a2802db', 'name': 'ctest-vn2-84919964', 'tenant_id': '429fa472d3f840198675839aa0ba4d11', 'project_id': '429fa472d3f840198675839aa0ba4d11', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-75145792', 'ctest-vn2-84919964'], 'port_security_enabled': True, 'description': ''}} 2025-10-22 12:56:36,551 - DEBUG - Response for create_subnet : {'subnet': {'id': '13b95372-3cf1-4448-a4dc-b6b3c576a6b5', 'name': '', 'tenant_id': '429fa472d3f840198675839aa0ba4d11', 'network_id': '917cfc63-b001-4bbc-90f4-9de67a2802db', 'ip_version': 4, 'cidr': '37.125.248.192/26', 'allocation_pools': [{'start': '37.125.248.194', 'end': '37.125.248.254'}], 'gateway_ip': '37.125.248.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '37.125.248.194', 'tags': [], 'project_id': '429fa472d3f840198675839aa0ba4d11'}} 2025-10-22 12:56:36,570 - INFO - Created VN ctest-vn2-84919964 2025-10-22 12:56:36,626 - DEBUG - VN ctest-vn2-84919964 UUID is 917cfc63-b001-4bbc-90f4-9de67a2802db 2025-10-22 12:56:36,802 - DEBUG - Services list from nova: [, , ] 2025-10-22 12:56:37,944 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4428-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4428-1) 2025-10-22 12:56:39,317 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4428-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4428-1) 2025-10-22 12:56:39,411 - INFO - Adding interface with subnet_id b3d34d2b-1e4c-490d-8759-a888d881dac6, port_id None to router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:56:39,774 - INFO - Waiting for VM ctest-vn1-vm1-78141047 to be up.. 2025-10-22 12:56:39,928 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-10-22 12:56:45,007 - DEBUG - VM is in ACTIVE state now 2025-10-22 12:56:45,007 - INFO - VM name : ctest-vn1-vm1-78141047 2025-10-22 12:56:45,082 - DEBUG - VM ctest-vn1-vm1-78141047 ID is 59da9c81-180f-41f9-9efd-61930b27e285 2025-10-22 12:56:45,102 - DEBUG - VM ctest-vn1-vm1-78141047 launched on Node cn-jenkins-deploy-platform-ansible-os-4428-1 2025-10-22 12:56:45,180 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/59da9c81-180f-41f9-9efd-61930b27e285 2025-10-22 12:56:45,517 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/59da9c81-180f-41f9-9efd-61930b27e285 2025-10-22 12:56:45,553 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/32bc19fc-4db8-4f20-a669-e2cb26119073 2025-10-22 12:56:48,805 - 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 1018ms') 2025-10-22 12:56:48,805 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-78141047 failed! 2025-10-22 12:56:48,862 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-75145792:ctest-vn1-24087229 is 186.87.209.193 and allocation pool is NOT set 2025-10-22 12:56:50,921 - 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=4.48 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.34 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 = 1.343/2.911/4.479/1.568 ms') 2025-10-22 12:56:50,921 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-78141047 passed 2025-10-22 12:56:51,082 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:56:51,082 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-78141047, IP 186.87.209.195, Port 22 2025-10-22 12:56:51,241 - DEBUG - VM ctest-vn1-vm1-78141047 is ready for SSH connections 2025-10-22 12:56:51,242 - INFO - Waiting for VM ctest-vn2-vm1-73524787 to be up.. 2025-10-22 12:56:51,319 - DEBUG - VM is in ACTIVE state now 2025-10-22 12:56:51,320 - INFO - VM name : ctest-vn2-vm1-73524787 2025-10-22 12:56:51,395 - DEBUG - VM ctest-vn2-vm1-73524787 ID is b9c639a8-a12e-45dd-90f0-5bbda3d8d4dc 2025-10-22 12:56:51,396 - DEBUG - VM ctest-vn2-vm1-73524787 launched on Node cn-jenkins-deploy-platform-ansible-os-4428-1 2025-10-22 12:56:51,471 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/b9c639a8-a12e-45dd-90f0-5bbda3d8d4dc 2025-10-22 12:56:51,479 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/1a4e1bd2-1315-44ac-b54c-6695cd14cd51 2025-10-22 12:56:52,723 - 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.59 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.597 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.597/2.095/3.593/1.498 ms') 2025-10-22 12:56:52,723 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-73524787 passed 2025-10-22 12:56:52,878 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:56:52,878 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-73524787, IP 37.125.248.195, Port 22 2025-10-22 12:56:53,034 - DEBUG - VM ctest-vn2-vm1-73524787 is ready for SSH connections 2025-10-22 12:56:53,034 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:56:53,035 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 37.125.248.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-10-22 12:56:53,035 - DEBUG - ping -s 56 -c 3 -W 1 37.125.248.195 2025-10-22 12:56:58,156 - DEBUG - PING 37.125.248.195 (37.125.248.195): 56 data bytes --- 37.125.248.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-10-22 12:56:58,156 - WARNING - Ping to IP 37.125.248.195 from VM ctest-vn1-vm1-78141047 failed 2025-10-22 12:56:58,156 - INFO - Adding interface with subnet_id 13b95372-3cf1-4448-a4dc-b6b3c576a6b5, port_id None to router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:56:58,425 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:56:58,425 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 37.125.248.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-10-22 12:56:58,425 - DEBUG - ping -s 56 -c 3 -W 1 37.125.248.195 2025-10-22 12:57:01,657 - DEBUG - PING 37.125.248.195 (37.125.248.195): 56 data bytes 64 bytes from 37.125.248.195: seq=1 ttl=63 time=2.872 ms 64 bytes from 37.125.248.195: seq=2 ttl=63 time=0.889 ms --- 37.125.248.195 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 0.889/1.880/2.872 ms 2025-10-22 12:57:01,657 - WARNING - Ping to IP 37.125.248.195 from VM ctest-vn1-vm1-78141047 failed 2025-10-22 12:57:02,658 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 37.125.248.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-10-22 12:57:02,658 - DEBUG - ping -s 56 -c 3 -W 1 37.125.248.195 2025-10-22 12:57:04,922 - DEBUG - PING 37.125.248.195 (37.125.248.195): 56 data bytes 64 bytes from 37.125.248.195: seq=0 ttl=63 time=1.531 ms 64 bytes from 37.125.248.195: seq=1 ttl=63 time=0.907 ms 64 bytes from 37.125.248.195: seq=2 ttl=63 time=0.948 ms --- 37.125.248.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.907/1.128/1.531 ms 2025-10-22 12:57:04,922 - INFO - Ping to IP 37.125.248.195 from VM ctest-vn1-vm1-78141047 passed 2025-10-22 12:57:04,922 - INFO - Deleting interface with subnet_id b3d34d2b-1e4c-490d-8759-a888d881dac6, port_id None from router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:57:05,058 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:57:05,058 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 37.125.248.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-10-22 12:57:05,058 - DEBUG - ping -s 56 -c 3 -W 1 37.125.248.195 2025-10-22 12:57:08,290 - DEBUG - PING 37.125.248.195 (37.125.248.195): 56 data bytes --- 37.125.248.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-10-22 12:57:08,290 - WARNING - Ping to IP 37.125.248.195 from VM ctest-vn1-vm1-78141047 failed 2025-10-22 12:57:08,290 - INFO - Adding interface with subnet_id b3d34d2b-1e4c-490d-8759-a888d881dac6, port_id None to router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:57:08,529 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 12:57:08,529 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 37.125.248.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2025-10-22 12:57:08,529 - DEBUG - ping -s 56 -c 3 -W 1 37.125.248.195 2025-10-22 12:57:10,754 - DEBUG - PING 37.125.248.195 (37.125.248.195): 56 data bytes 64 bytes from 37.125.248.195: seq=0 ttl=63 time=1.606 ms 64 bytes from 37.125.248.195: seq=1 ttl=63 time=0.931 ms 64 bytes from 37.125.248.195: seq=2 ttl=63 time=0.864 ms --- 37.125.248.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.864/1.133/1.606 ms 2025-10-22 12:57:10,754 - INFO - Ping to IP 37.125.248.195 from VM ctest-vn1-vm1-78141047 passed 2025-10-22 12:57:10,754 - INFO - Deleting interface with subnet_id 13b95372-3cf1-4448-a4dc-b6b3c576a6b5, port_id None from router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:57:10,870 - INFO - Deleting interface with subnet_id b3d34d2b-1e4c-490d-8759-a888d881dac6, port_id None from router 81d18ab5-3c66-42fc-bc2a-521d0eae553d 2025-10-22 12:57:11,034 - INFO - Deleting VM ctest-vn2-vm1-73524787 2025-10-22 12:57:11,111 - INFO - Deleting VM ctest-vn1-vm1-78141047 2025-10-22 12:57:11,184 - INFO - Deleting VN ctest-vn2-84919964 2025-10-22 12:57:11,223 - DEBUG - VN 917cfc63-b001-4bbc-90f4-9de67a2802db still in use: Unable to complete operation on network 917cfc63-b001-4bbc-90f4-9de67a2802db. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-7a9ceb78-5363-48e3-a9ba-9e6c4d02c05c'] 2025-10-22 12:57:11,223 - WARNING - Deleting VN ctest-vn2-84919964 failed..Will retry 2025-10-22 12:57:13,327 - DEBUG - Response for deleting network () 2025-10-22 12:57:13,327 - INFO - Deleting VN ctest-vn1-24087229 2025-10-22 12:57:13,434 - DEBUG - Response for deleting network () 2025-10-22 12:57:13,691 - DEBUG - No XMPP flaps were noticed during the test
2025-10-22 12:57:13,691 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-10-22 12:57:13,691 - INFO - -------------------------------------------------------------------------------- 2025-10-22 12:57:14,402 - INFO - Deleted project: ctest-TestRouters-75145792, ID : 429fa472-d3f8-4019-8675-839aa0ba4d11