2026-08-18 07:14:47,099 - INFO - Domain Default found not creating 2026-08-18 07:14:47,279 - INFO - Project ctest-TestRouters-06890664 not found, creating it 2026-08-18 07:14:47,794 - INFO - Created Project:ctest-TestRouters-06890664, ID : 60eeda4b-a1dd-42d1-8db3-48977e14b7fe 2026-08-18 07:14:49,566 - INFO - ================================================================================ 2026-08-18 07:14:49,566 - INFO - STARTING TEST : test_basic_router_behavior 2026-08-18 07:14:49,566 - 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-08-18 07:14:49,827 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.25': '0'}} with 2026-08-18 07:14:49,827 - INFO - Initial checks done. Running the testcase now 2026-08-18 07:14:49,828 - INFO - 2026-08-18 07:14:50,564 - DEBUG - Response for create_network : {'network': {'id': '0d8f7a7e-5178-4057-ab02-909cd5e328e5', 'name': 'ctest-vn1-76002035', 'tenant_id': '60eeda4ba1dd42d18db348977e14b7fe', 'project_id': '60eeda4ba1dd42d18db348977e14b7fe', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-06890664', 'ctest-vn1-76002035'], 'port_security_enabled': True, 'description': ''}} 2026-08-18 07:14:50,807 - DEBUG - Response for create_subnet : {'subnet': {'id': '308696be-7501-4be2-b80f-5a5e4bb8895b', 'name': '', 'tenant_id': '60eeda4ba1dd42d18db348977e14b7fe', 'network_id': '0d8f7a7e-5178-4057-ab02-909cd5e328e5', 'ip_version': 4, 'cidr': '166.10.203.128/26', 'allocation_pools': [{'start': '166.10.203.130', 'end': '166.10.203.190'}], 'gateway_ip': '166.10.203.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '166.10.203.130', 'tags': [], 'project_id': '60eeda4ba1dd42d18db348977e14b7fe'}} 2026-08-18 07:14:50,826 - INFO - Created VN ctest-vn1-76002035 2026-08-18 07:14:50,880 - DEBUG - VN ctest-vn1-76002035 UUID is 0d8f7a7e-5178-4057-ab02-909cd5e328e5 2026-08-18 07:14:51,220 - DEBUG - Response for create_network : {'network': {'id': '0cd541b4-a84c-4617-96b7-1ce300c57706', 'name': 'ctest-vn2-19611943', 'tenant_id': '60eeda4ba1dd42d18db348977e14b7fe', 'project_id': '60eeda4ba1dd42d18db348977e14b7fe', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-06890664', 'ctest-vn2-19611943'], 'port_security_enabled': True, 'description': ''}} 2026-08-18 07:14:51,434 - DEBUG - Response for create_subnet : {'subnet': {'id': '5dbac29b-fc26-4f9d-ba9f-9ef82b6f43e0', 'name': '', 'tenant_id': '60eeda4ba1dd42d18db348977e14b7fe', 'network_id': '0cd541b4-a84c-4617-96b7-1ce300c57706', 'ip_version': 4, 'cidr': '209.175.21.128/26', 'allocation_pools': [{'start': '209.175.21.130', 'end': '209.175.21.190'}], 'gateway_ip': '209.175.21.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '209.175.21.130', 'tags': [], 'project_id': '60eeda4ba1dd42d18db348977e14b7fe'}} 2026-08-18 07:14:51,451 - INFO - Created VN ctest-vn2-19611943 2026-08-18 07:14:51,508 - DEBUG - VN ctest-vn2-19611943 UUID is 0cd541b4-a84c-4617-96b7-1ce300c57706 2026-08-18 07:14:51,764 - DEBUG - Services list from nova: [, , ] 2026-08-18 07:14:52,194 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6179-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6179-1) 2026-08-18 07:14:52,833 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6179-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6179-1) 2026-08-18 07:14:52,944 - INFO - Adding interface with subnet_id 308696be-7501-4be2-b80f-5a5e4bb8895b, port_id None to router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:14:53,266 - INFO - Waiting for VM ctest-vn1-vm1-10332229 to be up.. 2026-08-18 07:14:53,334 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:14:58,391 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:03,483 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:08,571 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:13,654 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:18,745 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:23,827 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:28,907 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-08-18 07:15:33,990 - DEBUG - VM is in ACTIVE state now 2026-08-18 07:15:33,990 - INFO - VM name : ctest-vn1-vm1-10332229 2026-08-18 07:15:34,083 - DEBUG - VM ctest-vn1-vm1-10332229 ID is 7b7b7c89-8003-4a05-a159-c6a98e8a9ab2 2026-08-18 07:15:34,120 - DEBUG - VM ctest-vn1-vm1-10332229 launched on Node cn-jenkins-deploy-platform-ansible-os-6179-1 2026-08-18 07:15:34,210 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/7b7b7c89-8003-4a05-a159-c6a98e8a9ab2 2026-08-18 07:15:34,579 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/7b7b7c89-8003-4a05-a159-c6a98e8a9ab2 2026-08-18 07:15:34,613 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/d494dfe4-4149-40bf-a167-ca6ef89a2463 2026-08-18 07:15:37,875 - 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 1014ms') 2026-08-18 07:15:37,876 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10332229 failed! 2026-08-18 07:15:37,936 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-06890664:ctest-vn1-76002035 is 166.10.203.129 and allocation pool is NOT set 2026-08-18 07:15:40,005 - 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.60 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.573 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.573/2.587/4.602/2.014 ms') 2026-08-18 07:15:40,005 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-10332229 passed 2026-08-18 07:15:40,160 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:40,160 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-10332229, IP 166.10.203.131, Port 22 2026-08-18 07:15:40,339 - DEBUG - VM ctest-vn1-vm1-10332229 is ready for SSH connections 2026-08-18 07:15:40,340 - INFO - Waiting for VM ctest-vn2-vm1-04909879 to be up.. 2026-08-18 07:15:40,423 - DEBUG - VM is in ACTIVE state now 2026-08-18 07:15:40,424 - INFO - VM name : ctest-vn2-vm1-04909879 2026-08-18 07:15:40,512 - DEBUG - VM ctest-vn2-vm1-04909879 ID is ea62375b-2f1f-448d-b478-d86935c27a3f 2026-08-18 07:15:40,512 - DEBUG - VM ctest-vn2-vm1-04909879 launched on Node cn-jenkins-deploy-platform-ansible-os-6179-1 2026-08-18 07:15:40,602 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/ea62375b-2f1f-448d-b478-d86935c27a3f 2026-08-18 07:15:40,612 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/2d70a597-75e4-4299-abf8-dfcd39165b40 2026-08-18 07:15:43,867 - 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=2 ttl=63 time=6.36 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1006ms\r\nrtt min/avg/max/mdev = 6.361/6.361/6.361/0.000 ms') 2026-08-18 07:15:43,867 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-04909879 passed 2026-08-18 07:15:44,020 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:44,020 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-04909879, IP 209.175.21.131, Port 22 2026-08-18 07:15:44,190 - DEBUG - VM ctest-vn2-vm1-04909879 is ready for SSH connections 2026-08-18 07:15:44,190 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:44,190 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 209.175.21.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2026-08-18 07:15:44,190 - DEBUG - ping -s 56 -c 3 -W 1 209.175.21.131 2026-08-18 07:15:49,209 - DEBUG - PING 209.175.21.131 (209.175.21.131): 56 data bytes --- 209.175.21.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-08-18 07:15:49,210 - WARNING - Ping to IP 209.175.21.131 from VM ctest-vn1-vm1-10332229 failed 2026-08-18 07:15:49,210 - INFO - Adding interface with subnet_id 5dbac29b-fc26-4f9d-ba9f-9ef82b6f43e0, port_id None to router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:15:49,524 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:49,524 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 209.175.21.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2026-08-18 07:15:49,524 - DEBUG - ping -s 56 -c 3 -W 1 209.175.21.131 2026-08-18 07:15:52,654 - DEBUG - PING 209.175.21.131 (209.175.21.131): 56 data bytes 64 bytes from 209.175.21.131: seq=1 ttl=63 time=3.288 ms 64 bytes from 209.175.21.131: seq=2 ttl=63 time=1.129 ms --- 209.175.21.131 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.129/2.208/3.288 ms 2026-08-18 07:15:52,655 - WARNING - Ping to IP 209.175.21.131 from VM ctest-vn1-vm1-10332229 failed 2026-08-18 07:15:53,655 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 209.175.21.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2026-08-18 07:15:53,656 - DEBUG - ping -s 56 -c 3 -W 1 209.175.21.131 2026-08-18 07:15:55,786 - DEBUG - PING 209.175.21.131 (209.175.21.131): 56 data bytes 64 bytes from 209.175.21.131: seq=0 ttl=63 time=3.216 ms 64 bytes from 209.175.21.131: seq=1 ttl=63 time=1.095 ms 64 bytes from 209.175.21.131: seq=2 ttl=63 time=1.011 ms --- 209.175.21.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.011/1.774/3.216 ms 2026-08-18 07:15:55,787 - INFO - Ping to IP 209.175.21.131 from VM ctest-vn1-vm1-10332229 passed 2026-08-18 07:15:55,787 - INFO - Deleting interface with subnet_id 308696be-7501-4be2-b80f-5a5e4bb8895b, port_id None from router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:15:55,929 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:55,930 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 209.175.21.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2026-08-18 07:15:55,930 - DEBUG - ping -s 56 -c 3 -W 1 209.175.21.131 2026-08-18 07:15:59,055 - DEBUG - PING 209.175.21.131 (209.175.21.131): 56 data bytes --- 209.175.21.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-08-18 07:15:59,055 - WARNING - Ping to IP 209.175.21.131 from VM ctest-vn1-vm1-10332229 failed 2026-08-18 07:15:59,055 - INFO - Adding interface with subnet_id 308696be-7501-4be2-b80f-5a5e4bb8895b, port_id None to router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:15:59,355 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-08-18 07:15:59,355 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 209.175.21.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.19, gateway password: c0ntrail123 2026-08-18 07:15:59,355 - DEBUG - ping -s 56 -c 3 -W 1 209.175.21.131 2026-08-18 07:16:01,500 - DEBUG - PING 209.175.21.131 (209.175.21.131): 56 data bytes 64 bytes from 209.175.21.131: seq=0 ttl=63 time=1.356 ms 64 bytes from 209.175.21.131: seq=1 ttl=63 time=0.995 ms 64 bytes from 209.175.21.131: seq=2 ttl=63 time=1.054 ms --- 209.175.21.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.995/1.135/1.356 ms 2026-08-18 07:16:01,501 - INFO - Ping to IP 209.175.21.131 from VM ctest-vn1-vm1-10332229 passed 2026-08-18 07:16:01,501 - INFO - Deleting interface with subnet_id 5dbac29b-fc26-4f9d-ba9f-9ef82b6f43e0, port_id None from router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:16:01,650 - INFO - Deleting interface with subnet_id 308696be-7501-4be2-b80f-5a5e4bb8895b, port_id None from router a1950954-e845-4dc1-9fd3-ae1f139cace1 2026-08-18 07:16:01,845 - INFO - Deleting VM ctest-vn2-vm1-04909879 2026-08-18 07:16:01,929 - INFO - Deleting VM ctest-vn1-vm1-10332229 2026-08-18 07:16:02,005 - INFO - Deleting VN ctest-vn2-19611943 2026-08-18 07:16:02,041 - DEBUG - VN 0cd541b4-a84c-4617-96b7-1ce300c57706 still in use: Unable to complete operation on network 0cd541b4-a84c-4617-96b7-1ce300c57706. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-e03a7ccb-6699-4a2f-9395-42af1e1db572'] 2026-08-18 07:16:02,042 - WARNING - Deleting VN ctest-vn2-19611943 failed..Will retry 2026-08-18 07:16:04,233 - DEBUG - Response for deleting network () 2026-08-18 07:16:04,233 - INFO - Deleting VN ctest-vn1-76002035 2026-08-18 07:16:04,345 - DEBUG - Response for deleting network () 2026-08-18 07:16:04,616 - DEBUG - No XMPP flaps were noticed during the test
2026-08-18 07:16:04,616 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:15]
2026-08-18 07:16:04,616 - INFO - -------------------------------------------------------------------------------- 2026-08-18 07:16:05,420 - INFO - Deleted project: ctest-TestRouters-06890664, ID : 60eeda4b-a1dd-42d1-8db3-48977e14b7fe