2025-12-08 20:18:18,354 - INFO - Domain Default found not creating
2025-12-08 20:18:18,534 - INFO - Project ctest-TestRouters-02785138 not found, creating it
2025-12-08 20:18:19,032 - INFO - Created Project:ctest-TestRouters-02785138, ID : 740c9f8d-6e3b-407a-b1d9-50af7481e24e
2025-12-08 20:18:20,756 - INFO - ================================================================================
2025-12-08 20:18:20,756 - INFO - STARTING TEST : test_basic_router_behavior
2025-12-08 20:18:20,756 - 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-12-08 20:18:21,016 - DEBUG - Nothing to compare xmpp stats {'10.0.0.33': {'10.20.0.14': '0'}} with
2025-12-08 20:18:21,016 - INFO - Initial checks done. Running the testcase now
2025-12-08 20:18:21,016 - INFO -
2025-12-08 20:18:21,635 - DEBUG - Response for create_network : {'network': {'id': '61ac654f-6103-401f-a02d-b4d92ca7ec09', 'name': 'ctest-vn1-12950835', 'tenant_id': '740c9f8d6e3b407ab1d950af7481e24e', 'project_id': '740c9f8d6e3b407ab1d950af7481e24e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-02785138', 'ctest-vn1-12950835'], 'port_security_enabled': True, 'description': ''}}
2025-12-08 20:18:21,884 - DEBUG - Response for create_subnet : {'subnet': {'id': '1dd6f524-1941-478a-8feb-5a3bda52336d', 'name': '', 'tenant_id': '740c9f8d6e3b407ab1d950af7481e24e', 'network_id': '61ac654f-6103-401f-a02d-b4d92ca7ec09', 'ip_version': 4, 'cidr': '53.18.142.0/26', 'allocation_pools': [{'start': '53.18.142.2', 'end': '53.18.142.62'}], 'gateway_ip': '53.18.142.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '53.18.142.2', 'tags': [], 'project_id': '740c9f8d6e3b407ab1d950af7481e24e'}}
2025-12-08 20:18:21,904 - INFO - Created VN ctest-vn1-12950835
2025-12-08 20:18:21,957 - DEBUG - VN ctest-vn1-12950835 UUID is 61ac654f-6103-401f-a02d-b4d92ca7ec09
2025-12-08 20:18:22,303 - DEBUG - Response for create_network : {'network': {'id': 'de947af1-7862-4b1e-99d8-bb17e972a8c9', 'name': 'ctest-vn2-96719021', 'tenant_id': '740c9f8d6e3b407ab1d950af7481e24e', 'project_id': '740c9f8d6e3b407ab1d950af7481e24e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-02785138', 'ctest-vn2-96719021'], 'port_security_enabled': True, 'description': ''}}
2025-12-08 20:18:22,525 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd60d06fa-62d7-4da3-a115-a30e802018c9', 'name': '', 'tenant_id': '740c9f8d6e3b407ab1d950af7481e24e', 'network_id': 'de947af1-7862-4b1e-99d8-bb17e972a8c9', 'ip_version': 4, 'cidr': '163.16.177.128/26', 'allocation_pools': [{'start': '163.16.177.130', 'end': '163.16.177.190'}], 'gateway_ip': '163.16.177.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '163.16.177.130', 'tags': [], 'project_id': '740c9f8d6e3b407ab1d950af7481e24e'}}
2025-12-08 20:18:22,547 - INFO - Created VN ctest-vn2-96719021
2025-12-08 20:18:22,602 - DEBUG - VN ctest-vn2-96719021 UUID is de947af1-7862-4b1e-99d8-bb17e972a8c9
2025-12-08 20:18:22,784 - DEBUG - Services list from nova: [, , ]
2025-12-08 20:18:23,874 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4860-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4860-1)
2025-12-08 20:18:25,289 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4860-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4860-1)
2025-12-08 20:18:25,369 - INFO - Adding interface with subnet_id 1dd6f524-1941-478a-8feb-5a3bda52336d, port_id None to router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:25,648 - INFO - Waiting for VM ctest-vn1-vm1-89423288 to be up..
2025-12-08 20:18:25,762 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-12-08 20:18:30,864 - DEBUG - VM is in ACTIVE state now
2025-12-08 20:18:30,864 - INFO - VM name : ctest-vn1-vm1-89423288
2025-12-08 20:18:30,969 - DEBUG - VM ctest-vn1-vm1-89423288 ID is 4966ba6d-8af2-4c9a-a13f-6afe8bbfed69
2025-12-08 20:18:30,997 - DEBUG - VM ctest-vn1-vm1-89423288 launched on Node cn-jenkins-deploy-platform-ansible-os-4860-1
2025-12-08 20:18:31,099 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/4966ba6d-8af2-4c9a-a13f-6afe8bbfed69
2025-12-08 20:18:31,411 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/4966ba6d-8af2-4c9a-a13f-6afe8bbfed69
2025-12-08 20:18:31,452 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/7fa4906a-c514-4b7c-bcf1-c08eaa74de99
2025-12-08 20:18:34,725 - 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 1029ms')
2025-12-08 20:18:34,725 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-89423288 failed!
2025-12-08 20:18:34,782 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-02785138:ctest-vn1-12950835 is 53.18.142.1 and allocation pool is NOT set
2025-12-08 20:18:36,850 - 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=5.23 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.980 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.980/3.106/5.233/2.126 ms')
2025-12-08 20:18:36,850 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-89423288 passed
2025-12-08 20:18:37,001 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:37,002 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-89423288, IP 53.18.142.3, Port 22
2025-12-08 20:18:37,172 - DEBUG - VM ctest-vn1-vm1-89423288 is ready for SSH connections
2025-12-08 20:18:37,172 - INFO - Waiting for VM ctest-vn2-vm1-36550421 to be up..
2025-12-08 20:18:37,257 - DEBUG - VM is in ACTIVE state now
2025-12-08 20:18:37,257 - INFO - VM name : ctest-vn2-vm1-36550421
2025-12-08 20:18:37,342 - DEBUG - VM ctest-vn2-vm1-36550421 ID is cb75ccc9-e6e4-4d38-a870-8d8b490a5d1e
2025-12-08 20:18:37,342 - DEBUG - VM ctest-vn2-vm1-36550421 launched on Node cn-jenkins-deploy-platform-ansible-os-4860-1
2025-12-08 20:18:37,430 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/cb75ccc9-e6e4-4d38-a870-8d8b490a5d1e
2025-12-08 20:18:37,439 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/7ab95042-f16c-4f21-ba96-7571589b3b07
2025-12-08 20:18:38,683 - 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.03 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.882 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.882/2.956/5.030/2.074 ms')
2025-12-08 20:18:38,683 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-36550421 passed
2025-12-08 20:18:38,794 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:38,794 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-36550421, IP 163.16.177.131, Port 22
2025-12-08 20:18:38,960 - DEBUG - VM ctest-vn2-vm1-36550421 is ready for SSH connections
2025-12-08 20:18:38,960 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:38,960 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 163.16.177.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2025-12-08 20:18:38,960 - DEBUG - ping -s 56 -c 3 -W 1 163.16.177.131
2025-12-08 20:18:43,992 - DEBUG - PING 163.16.177.131 (163.16.177.131): 56 data bytes
--- 163.16.177.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-12-08 20:18:43,992 - WARNING - Ping to IP 163.16.177.131 from VM ctest-vn1-vm1-89423288 failed
2025-12-08 20:18:43,992 - INFO - Adding interface with subnet_id d60d06fa-62d7-4da3-a115-a30e802018c9, port_id None to router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:44,269 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:44,269 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 163.16.177.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2025-12-08 20:18:44,269 - DEBUG - ping -s 56 -c 3 -W 1 163.16.177.131
2025-12-08 20:18:47,499 - DEBUG - PING 163.16.177.131 (163.16.177.131): 56 data bytes
64 bytes from 163.16.177.131: seq=1 ttl=63 time=2.593 ms
64 bytes from 163.16.177.131: seq=2 ttl=63 time=1.097 ms
--- 163.16.177.131 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.097/1.845/2.593 ms
2025-12-08 20:18:47,499 - WARNING - Ping to IP 163.16.177.131 from VM ctest-vn1-vm1-89423288 failed
2025-12-08 20:18:48,500 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 163.16.177.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2025-12-08 20:18:48,500 - DEBUG - ping -s 56 -c 3 -W 1 163.16.177.131
2025-12-08 20:18:50,718 - DEBUG - PING 163.16.177.131 (163.16.177.131): 56 data bytes
64 bytes from 163.16.177.131: seq=0 ttl=63 time=1.459 ms
64 bytes from 163.16.177.131: seq=1 ttl=63 time=2.562 ms
64 bytes from 163.16.177.131: seq=2 ttl=63 time=1.017 ms
--- 163.16.177.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.017/1.679/2.562 ms
2025-12-08 20:18:50,718 - INFO - Ping to IP 163.16.177.131 from VM ctest-vn1-vm1-89423288 passed
2025-12-08 20:18:50,718 - INFO - Deleting interface with subnet_id 1dd6f524-1941-478a-8feb-5a3bda52336d, port_id None from router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:50,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:50,853 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 163.16.177.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2025-12-08 20:18:50,854 - DEBUG - ping -s 56 -c 3 -W 1 163.16.177.131
2025-12-08 20:18:54,066 - DEBUG - PING 163.16.177.131 (163.16.177.131): 56 data bytes
--- 163.16.177.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-12-08 20:18:54,066 - WARNING - Ping to IP 163.16.177.131 from VM ctest-vn1-vm1-89423288 failed
2025-12-08 20:18:54,066 - INFO - Adding interface with subnet_id 1dd6f524-1941-478a-8feb-5a3bda52336d, port_id None to router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:54,291 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 20:18:54,292 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 163.16.177.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2025-12-08 20:18:54,292 - DEBUG - ping -s 56 -c 3 -W 1 163.16.177.131
2025-12-08 20:18:56,526 - DEBUG - PING 163.16.177.131 (163.16.177.131): 56 data bytes
64 bytes from 163.16.177.131: seq=0 ttl=63 time=1.850 ms
64 bytes from 163.16.177.131: seq=1 ttl=63 time=1.068 ms
64 bytes from 163.16.177.131: seq=2 ttl=63 time=1.067 ms
--- 163.16.177.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.067/1.328/1.850 ms
2025-12-08 20:18:56,526 - INFO - Ping to IP 163.16.177.131 from VM ctest-vn1-vm1-89423288 passed
2025-12-08 20:18:56,526 - INFO - Deleting interface with subnet_id d60d06fa-62d7-4da3-a115-a30e802018c9, port_id None from router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:56,661 - INFO - Deleting interface with subnet_id 1dd6f524-1941-478a-8feb-5a3bda52336d, port_id None from router b7ce17a0-6ad4-4e11-a5ca-8e04abcca042
2025-12-08 20:18:56,881 - INFO - Deleting VM ctest-vn2-vm1-36550421
2025-12-08 20:18:56,964 - INFO - Deleting VM ctest-vn1-vm1-89423288
2025-12-08 20:18:57,049 - INFO - Deleting VN ctest-vn2-96719021
2025-12-08 20:18:57,093 - DEBUG - VN de947af1-7862-4b1e-99d8-bb17e972a8c9 still in use: Unable to complete operation on network de947af1-7862-4b1e-99d8-bb17e972a8c9. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-fd0faa2b-f43e-45b8-9799-5cd84a6a0324']
2025-12-08 20:18:57,093 - WARNING - Deleting VN ctest-vn2-96719021 failed..Will retry
2025-12-08 20:18:59,208 - DEBUG - Response for deleting network ()
2025-12-08 20:18:59,208 - INFO - Deleting VN ctest-vn1-12950835
2025-12-08 20:18:59,316 - DEBUG - Response for deleting network ()
2025-12-08 20:18:59,585 - DEBUG - No XMPP flaps were noticed during the test
2025-12-08 20:18:59,585 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-12-08 20:18:59,585 - INFO - --------------------------------------------------------------------------------
2025-12-08 20:19:00,309 - INFO - Deleted project: ctest-TestRouters-02785138, ID : 740c9f8d-6e3b-407a-b1d9-50af7481e24e