2026-07-30 11:45:14,953 - INFO - Domain Default found not creating 2026-07-30 11:45:15,139 - INFO - Project ctest-TestRouters-75029221 not found, creating it 2026-07-30 11:45:15,663 - INFO - Created Project:ctest-TestRouters-75029221, ID : 4d49e669-c31e-4a20-916c-1ddc56453787 2026-07-30 11:45:17,337 - INFO - ================================================================================ 2026-07-30 11:45:17,337 - INFO - STARTING TEST : test_basic_router_behavior 2026-07-30 11:45:17,337 - 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-07-30 11:45:17,601 - DEBUG - Nothing to compare xmpp stats {'10.0.0.177': {'10.20.0.17': '0'}} with 2026-07-30 11:45:17,601 - INFO - Initial checks done. Running the testcase now 2026-07-30 11:45:17,601 - INFO - 2026-07-30 11:45:18,255 - DEBUG - Response for create_network : {'network': {'id': 'ac4856f5-c2aa-4419-9fea-81e3c6c2df1b', 'name': 'ctest-vn1-81451550', 'tenant_id': '4d49e669c31e4a20916c1ddc56453787', 'project_id': '4d49e669c31e4a20916c1ddc56453787', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-75029221', 'ctest-vn1-81451550'], 'port_security_enabled': True, 'description': ''}} 2026-07-30 11:45:18,464 - DEBUG - Response for create_subnet : {'subnet': {'id': '92543416-44c9-4ada-9672-6e5c296fc3b7', 'name': '', 'tenant_id': '4d49e669c31e4a20916c1ddc56453787', 'network_id': 'ac4856f5-c2aa-4419-9fea-81e3c6c2df1b', 'ip_version': 4, 'cidr': '22.233.245.192/26', 'allocation_pools': [{'start': '22.233.245.194', 'end': '22.233.245.254'}], 'gateway_ip': '22.233.245.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '22.233.245.194', 'tags': [], 'project_id': '4d49e669c31e4a20916c1ddc56453787'}} 2026-07-30 11:45:18,485 - INFO - Created VN ctest-vn1-81451550 2026-07-30 11:45:18,538 - DEBUG - VN ctest-vn1-81451550 UUID is ac4856f5-c2aa-4419-9fea-81e3c6c2df1b 2026-07-30 11:45:18,868 - DEBUG - Response for create_network : {'network': {'id': 'f6ef53f2-0a75-4c8c-969b-6285a099f855', 'name': 'ctest-vn2-26604708', 'tenant_id': '4d49e669c31e4a20916c1ddc56453787', 'project_id': '4d49e669c31e4a20916c1ddc56453787', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-75029221', 'ctest-vn2-26604708'], 'port_security_enabled': True, 'description': ''}} 2026-07-30 11:45:19,175 - DEBUG - Response for create_subnet : {'subnet': {'id': '57c5d68e-9216-4c6f-92a3-59435a1b39d0', 'name': '', 'tenant_id': '4d49e669c31e4a20916c1ddc56453787', 'network_id': 'f6ef53f2-0a75-4c8c-969b-6285a099f855', 'ip_version': 4, 'cidr': '115.146.194.192/26', 'allocation_pools': [{'start': '115.146.194.194', 'end': '115.146.194.254'}], 'gateway_ip': '115.146.194.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '115.146.194.194', 'tags': [], 'project_id': '4d49e669c31e4a20916c1ddc56453787'}} 2026-07-30 11:45:19,194 - INFO - Created VN ctest-vn2-26604708 2026-07-30 11:45:19,254 - DEBUG - VN ctest-vn2-26604708 UUID is f6ef53f2-0a75-4c8c-969b-6285a099f855 2026-07-30 11:45:19,525 - DEBUG - Services list from nova: [, , ] 2026-07-30 11:45:19,967 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6123-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6123-1) 2026-07-30 11:45:20,594 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6123-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6123-1) 2026-07-30 11:45:20,676 - INFO - Adding interface with subnet_id 92543416-44c9-4ada-9672-6e5c296fc3b7, port_id None to router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:45:20,973 - INFO - Waiting for VM ctest-vn1-vm1-85192779 to be up.. 2026-07-30 11:45:21,040 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:26,098 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:31,197 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:36,289 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:41,378 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:46,460 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:51,548 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:45:56,627 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-07-30 11:46:01,747 - DEBUG - VM is in ACTIVE state now 2026-07-30 11:46:01,747 - INFO - VM name : ctest-vn1-vm1-85192779 2026-07-30 11:46:01,856 - DEBUG - VM ctest-vn1-vm1-85192779 ID is 9e858bd8-0231-4358-a0bc-7c01d42eb475 2026-07-30 11:46:01,887 - DEBUG - VM ctest-vn1-vm1-85192779 launched on Node cn-jenkins-deploy-platform-ansible-os-6123-1 2026-07-30 11:46:01,989 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-machine/9e858bd8-0231-4358-a0bc-7c01d42eb475 2026-07-30 11:46:02,334 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-machine/9e858bd8-0231-4358-a0bc-7c01d42eb475 2026-07-30 11:46:02,374 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-machine-interface/ffb21ba2-d8c2-4ea8-ae68-622063408ab4 2026-07-30 11:46:05,655 - 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 1026ms') 2026-07-30 11:46:05,655 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-85192779 failed! 2026-07-30 11:46:05,710 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-75029221:ctest-vn1-81451550 is 22.233.245.193 and allocation pool is NOT set 2026-07-30 11:46:09,783 - 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=2 ttl=63 time=3.37 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1010ms\r\nrtt min/avg/max/mdev = 3.373/3.373/3.373/0.000 ms') 2026-07-30 11:46:09,783 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-85192779 passed 2026-07-30 11:46:09,942 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:09,943 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-85192779, IP 22.233.245.195, Port 22 2026-07-30 11:46:10,108 - DEBUG - VM ctest-vn1-vm1-85192779 is ready for SSH connections 2026-07-30 11:46:10,109 - INFO - Waiting for VM ctest-vn2-vm1-36851852 to be up.. 2026-07-30 11:46:10,187 - DEBUG - VM is in ACTIVE state now 2026-07-30 11:46:10,187 - INFO - VM name : ctest-vn2-vm1-36851852 2026-07-30 11:46:10,264 - DEBUG - VM ctest-vn2-vm1-36851852 ID is 0d18a970-283c-4166-a000-df4f4854ff2d 2026-07-30 11:46:10,264 - DEBUG - VM ctest-vn2-vm1-36851852 launched on Node cn-jenkins-deploy-platform-ansible-os-6123-1 2026-07-30 11:46:10,345 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-machine/0d18a970-283c-4166-a000-df4f4854ff2d 2026-07-30 11:46:10,358 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-machine-interface/5590fe2b-92e8-4880-8d84-3283db36d145 2026-07-30 11:46:11,607 - 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=4.10 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.658 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.658/2.378/4.099/1.720 ms') 2026-07-30 11:46:11,607 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-36851852 passed 2026-07-30 11:46:11,762 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:11,763 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-36851852, IP 115.146.194.195, Port 22 2026-07-30 11:46:11,940 - DEBUG - VM ctest-vn2-vm1-36851852 is ready for SSH connections 2026-07-30 11:46:11,940 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:11,940 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.146.194.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.177, gateway password: c0ntrail123 2026-07-30 11:46:11,940 - DEBUG - ping -s 56 -c 3 -W 1 115.146.194.195 2026-07-30 11:46:16,944 - DEBUG - PING 115.146.194.195 (115.146.194.195): 56 data bytes --- 115.146.194.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-07-30 11:46:16,944 - WARNING - Ping to IP 115.146.194.195 from VM ctest-vn1-vm1-85192779 failed 2026-07-30 11:46:16,944 - INFO - Adding interface with subnet_id 57c5d68e-9216-4c6f-92a3-59435a1b39d0, port_id None to router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:46:17,255 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:17,255 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.146.194.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.177, gateway password: c0ntrail123 2026-07-30 11:46:17,255 - DEBUG - ping -s 56 -c 3 -W 1 115.146.194.195 2026-07-30 11:46:20,385 - DEBUG - PING 115.146.194.195 (115.146.194.195): 56 data bytes 64 bytes from 115.146.194.195: seq=1 ttl=63 time=3.301 ms 64 bytes from 115.146.194.195: seq=2 ttl=63 time=1.241 ms --- 115.146.194.195 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.241/2.271/3.301 ms 2026-07-30 11:46:20,385 - WARNING - Ping to IP 115.146.194.195 from VM ctest-vn1-vm1-85192779 failed 2026-07-30 11:46:21,386 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.146.194.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.177, gateway password: c0ntrail123 2026-07-30 11:46:21,387 - DEBUG - ping -s 56 -c 3 -W 1 115.146.194.195 2026-07-30 11:46:23,519 - DEBUG - PING 115.146.194.195 (115.146.194.195): 56 data bytes 64 bytes from 115.146.194.195: seq=0 ttl=63 time=1.559 ms 64 bytes from 115.146.194.195: seq=1 ttl=63 time=1.089 ms 64 bytes from 115.146.194.195: seq=2 ttl=63 time=1.119 ms --- 115.146.194.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.089/1.255/1.559 ms 2026-07-30 11:46:23,519 - INFO - Ping to IP 115.146.194.195 from VM ctest-vn1-vm1-85192779 passed 2026-07-30 11:46:23,519 - INFO - Deleting interface with subnet_id 92543416-44c9-4ada-9672-6e5c296fc3b7, port_id None from router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:46:23,666 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:23,666 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.146.194.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.177, gateway password: c0ntrail123 2026-07-30 11:46:23,667 - DEBUG - ping -s 56 -c 3 -W 1 115.146.194.195 2026-07-30 11:46:26,794 - DEBUG - PING 115.146.194.195 (115.146.194.195): 56 data bytes --- 115.146.194.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-07-30 11:46:26,794 - WARNING - Ping to IP 115.146.194.195 from VM ctest-vn1-vm1-85192779 failed 2026-07-30 11:46:26,794 - INFO - Adding interface with subnet_id 92543416-44c9-4ada-9672-6e5c296fc3b7, port_id None to router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:46:27,056 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-07-30 11:46:27,056 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.146.194.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.177, gateway password: c0ntrail123 2026-07-30 11:46:27,056 - DEBUG - ping -s 56 -c 3 -W 1 115.146.194.195 2026-07-30 11:46:29,185 - DEBUG - PING 115.146.194.195 (115.146.194.195): 56 data bytes 64 bytes from 115.146.194.195: seq=0 ttl=63 time=1.459 ms 64 bytes from 115.146.194.195: seq=1 ttl=63 time=1.383 ms 64 bytes from 115.146.194.195: seq=2 ttl=63 time=1.111 ms --- 115.146.194.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.111/1.317/1.459 ms 2026-07-30 11:46:29,185 - INFO - Ping to IP 115.146.194.195 from VM ctest-vn1-vm1-85192779 passed 2026-07-30 11:46:29,185 - INFO - Deleting interface with subnet_id 57c5d68e-9216-4c6f-92a3-59435a1b39d0, port_id None from router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:46:29,321 - INFO - Deleting interface with subnet_id 92543416-44c9-4ada-9672-6e5c296fc3b7, port_id None from router 302b6f15-3106-412d-bdd5-9886c1167bff 2026-07-30 11:46:29,520 - INFO - Deleting VM ctest-vn2-vm1-36851852 2026-07-30 11:46:29,606 - INFO - Deleting VM ctest-vn1-vm1-85192779 2026-07-30 11:46:29,676 - INFO - Deleting VN ctest-vn2-26604708 2026-07-30 11:46:29,711 - DEBUG - VN f6ef53f2-0a75-4c8c-969b-6285a099f855 still in use: Unable to complete operation on network f6ef53f2-0a75-4c8c-969b-6285a099f855. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-192b22a4-b929-40c3-a59f-4a33e16368fc'] 2026-07-30 11:46:29,711 - WARNING - Deleting VN ctest-vn2-26604708 failed..Will retry 2026-07-30 11:46:31,908 - DEBUG - Response for deleting network () 2026-07-30 11:46:31,908 - INFO - Deleting VN ctest-vn1-81451550 2026-07-30 11:46:32,055 - DEBUG - Response for deleting network () 2026-07-30 11:46:32,332 - DEBUG - No XMPP flaps were noticed during the test
2026-07-30 11:46:32,332 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:15]
2026-07-30 11:46:32,332 - INFO - -------------------------------------------------------------------------------- 2026-07-30 11:46:33,115 - INFO - Deleted project: ctest-TestRouters-75029221, ID : 4d49e669-c31e-4a20-916c-1ddc56453787