2026-03-19 06:14:26,967 - INFO - Domain Default found not creating 2026-03-19 06:14:27,148 - INFO - Project ctest-TestRouters-14517362 not found, creating it 2026-03-19 06:14:27,778 - INFO - Created Project:ctest-TestRouters-14517362, ID : df52e693-2dae-4486-a9a4-2192aae345f3 2026-03-19 06:14:29,476 - INFO - ================================================================================ 2026-03-19 06:14:29,476 - INFO - STARTING TEST : test_basic_router_behavior 2026-03-19 06:14:29,477 - 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-03-19 06:14:30,779 - DEBUG - Nothing to compare xmpp stats {'10.0.0.249': {'10.20.0.14': '0', '10.20.0.254': '0'}, '10.0.0.22': {'10.20.0.254': '0', '10.20.0.17': '0'}} with 2026-03-19 06:14:30,780 - INFO - Initial checks done. Running the testcase now 2026-03-19 06:14:30,780 - INFO - 2026-03-19 06:14:31,544 - DEBUG - Response for create_network : {'network': {'id': '387828d9-c112-42d2-bb73-9e51648c8966', 'name': 'ctest-vn1-43843007', 'tenant_id': 'df52e6932dae4486a9a42192aae345f3', 'project_id': 'df52e6932dae4486a9a42192aae345f3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-14517362', 'ctest-vn1-43843007'], 'port_security_enabled': True, 'description': ''}} 2026-03-19 06:14:31,885 - DEBUG - Response for create_subnet : {'subnet': {'id': 'aa7d7bb3-0e0b-43a9-b35f-311fef17a852', 'name': '', 'tenant_id': 'df52e6932dae4486a9a42192aae345f3', 'network_id': '387828d9-c112-42d2-bb73-9e51648c8966', 'ip_version': 4, 'cidr': '14.131.15.0/26', 'allocation_pools': [{'start': '14.131.15.2', 'end': '14.131.15.62'}], 'gateway_ip': '14.131.15.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '14.131.15.2', 'tags': [], 'project_id': 'df52e6932dae4486a9a42192aae345f3'}} 2026-03-19 06:14:31,914 - INFO - Created VN ctest-vn1-43843007 2026-03-19 06:14:31,932 - DEBUG - VN ctest-vn1-43843007 UUID is 387828d9-c112-42d2-bb73-9e51648c8966 2026-03-19 06:14:32,419 - DEBUG - Response for create_network : {'network': {'id': 'f57b3adc-2aec-4eca-b936-ec715d9f2286', 'name': 'ctest-vn2-28208830', 'tenant_id': 'df52e6932dae4486a9a42192aae345f3', 'project_id': 'df52e6932dae4486a9a42192aae345f3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-14517362', 'ctest-vn2-28208830'], 'port_security_enabled': True, 'description': ''}} 2026-03-19 06:14:32,727 - DEBUG - Response for create_subnet : {'subnet': {'id': '10159257-a5ba-422b-b4a2-be0f9772a144', 'name': '', 'tenant_id': 'df52e6932dae4486a9a42192aae345f3', 'network_id': 'f57b3adc-2aec-4eca-b936-ec715d9f2286', 'ip_version': 4, 'cidr': '29.32.189.64/26', 'allocation_pools': [{'start': '29.32.189.66', 'end': '29.32.189.126'}], 'gateway_ip': '29.32.189.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '29.32.189.66', 'tags': [], 'project_id': 'df52e6932dae4486a9a42192aae345f3'}} 2026-03-19 06:14:32,756 - INFO - Created VN ctest-vn2-28208830 2026-03-19 06:14:32,773 - DEBUG - VN ctest-vn2-28208830 UUID is f57b3adc-2aec-4eca-b936-ec715d9f2286 2026-03-19 06:14:32,938 - DEBUG - Services list from nova: [, , , ] 2026-03-19 06:14:34,129 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5495-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5495-2) 2026-03-19 06:14:35,722 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5495-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5495-1) 2026-03-19 06:14:35,865 - INFO - Adding interface with subnet_id aa7d7bb3-0e0b-43a9-b35f-311fef17a852, port_id None to router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:14:36,381 - INFO - Waiting for VM ctest-vn1-vm1-73661438 to be up.. 2026-03-19 06:14:36,609 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-03-19 06:14:41,754 - DEBUG - VM is in ACTIVE state now 2026-03-19 06:14:41,754 - INFO - VM name : ctest-vn1-vm1-73661438 2026-03-19 06:14:41,904 - DEBUG - VM ctest-vn1-vm1-73661438 ID is a4c5acaf-dadd-447f-9af8-340b5d144e34 2026-03-19 06:14:41,934 - DEBUG - VM ctest-vn1-vm1-73661438 launched on Node an-jenkins-deploy-platform-ansible-os-5495-2 2026-03-19 06:14:42,059 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/a4c5acaf-dadd-447f-9af8-340b5d144e34 2026-03-19 06:14:42,393 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/a4c5acaf-dadd-447f-9af8-340b5d144e34 2026-03-19 06:14:42,443 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/b6dfae4e-1ba9-471e-960c-51efc186b1ad 2026-03-19 06:14:45,685 - 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 1022ms') 2026-03-19 06:14:45,685 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-73661438 failed! 2026-03-19 06:14:45,704 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-14517362:ctest-vn1-43843007 is 14.131.15.1 and allocation pool is NOT set 2026-03-19 06:14:49,782 - 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 1005ms') 2026-03-19 06:14:49,782 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-73661438 failed! 2026-03-19 06:14:49,800 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-14517362:ctest-vn1-43843007 is 14.131.15.1 and allocation pool is NOT set 2026-03-19 06:14:51,874 - 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.52 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.50 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 = 1.495/3.508/5.521/2.013 ms') 2026-03-19 06:14:51,874 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-73661438 passed 2026-03-19 06:14:51,998 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:14:51,998 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-73661438, IP 14.131.15.3, Port 22 2026-03-19 06:14:52,173 - DEBUG - VM ctest-vn1-vm1-73661438 is ready for SSH connections 2026-03-19 06:14:52,173 - INFO - Waiting for VM ctest-vn2-vm1-59738725 to be up.. 2026-03-19 06:14:52,305 - DEBUG - VM is in ACTIVE state now 2026-03-19 06:14:52,305 - INFO - VM name : ctest-vn2-vm1-59738725 2026-03-19 06:14:52,411 - DEBUG - VM ctest-vn2-vm1-59738725 ID is 6d37811d-d2f9-439f-8aa3-6595c8956279 2026-03-19 06:14:52,411 - DEBUG - VM ctest-vn2-vm1-59738725 launched on Node an-jenkins-deploy-platform-ansible-os-5495-1 2026-03-19 06:14:52,530 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/6d37811d-d2f9-439f-8aa3-6595c8956279 2026-03-19 06:14:52,544 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/026b1145-e4ea-4dc7-9dde-66bc524f2a53 2026-03-19 06:14:53,772 - 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=2.89 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.494 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.494/1.692/2.890/1.198 ms') 2026-03-19 06:14:53,772 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2-vm1-59738725 passed 2026-03-19 06:14:53,899 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:14:53,900 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-59738725, IP 29.32.189.67, Port 22 2026-03-19 06:14:54,075 - DEBUG - VM ctest-vn2-vm1-59738725 is ready for SSH connections 2026-03-19 06:14:54,075 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:14:54,075 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 29.32.189.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2026-03-19 06:14:54,075 - DEBUG - ping -s 56 -c 3 -W 1 29.32.189.67 2026-03-19 06:14:59,305 - DEBUG - PING 29.32.189.67 (29.32.189.67): 56 data bytes --- 29.32.189.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-03-19 06:14:59,306 - WARNING - Ping to IP 29.32.189.67 from VM ctest-vn1-vm1-73661438 failed 2026-03-19 06:14:59,306 - INFO - Adding interface with subnet_id 10159257-a5ba-422b-b4a2-be0f9772a144, port_id None to router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:14:59,878 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:14:59,878 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 29.32.189.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2026-03-19 06:14:59,878 - DEBUG - ping -s 56 -c 3 -W 1 29.32.189.67 2026-03-19 06:15:02,163 - DEBUG - PING 29.32.189.67 (29.32.189.67): 56 data bytes 64 bytes from 29.32.189.67: seq=0 ttl=63 time=7.340 ms 64 bytes from 29.32.189.67: seq=1 ttl=63 time=1.390 ms 64 bytes from 29.32.189.67: seq=2 ttl=63 time=1.158 ms --- 29.32.189.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.158/3.296/7.340 ms 2026-03-19 06:15:02,163 - INFO - Ping to IP 29.32.189.67 from VM ctest-vn1-vm1-73661438 passed 2026-03-19 06:15:02,163 - INFO - Deleting interface with subnet_id aa7d7bb3-0e0b-43a9-b35f-311fef17a852, port_id None from router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:15:02,527 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:15:02,527 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 29.32.189.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2026-03-19 06:15:02,527 - DEBUG - ping -s 56 -c 3 -W 1 29.32.189.67 2026-03-19 06:15:05,774 - DEBUG - PING 29.32.189.67 (29.32.189.67): 56 data bytes --- 29.32.189.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-03-19 06:15:05,775 - WARNING - Ping to IP 29.32.189.67 from VM ctest-vn1-vm1-73661438 failed 2026-03-19 06:15:05,775 - INFO - Adding interface with subnet_id aa7d7bb3-0e0b-43a9-b35f-311fef17a852, port_id None to router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:15:06,294 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-03-19 06:15:06,295 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 29.32.189.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2026-03-19 06:15:06,295 - DEBUG - ping -s 56 -c 3 -W 1 29.32.189.67 2026-03-19 06:15:09,591 - DEBUG - PING 29.32.189.67 (29.32.189.67): 56 data bytes 64 bytes from 29.32.189.67: seq=1 ttl=63 time=3.438 ms 64 bytes from 29.32.189.67: seq=2 ttl=63 time=1.470 ms --- 29.32.189.67 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.470/2.454/3.438 ms 2026-03-19 06:15:09,591 - WARNING - Ping to IP 29.32.189.67 from VM ctest-vn1-vm1-73661438 failed 2026-03-19 06:15:10,592 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 29.32.189.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2026-03-19 06:15:10,592 - DEBUG - ping -s 56 -c 3 -W 1 29.32.189.67 2026-03-19 06:15:12,883 - DEBUG - PING 29.32.189.67 (29.32.189.67): 56 data bytes 64 bytes from 29.32.189.67: seq=0 ttl=63 time=2.482 ms 64 bytes from 29.32.189.67: seq=1 ttl=63 time=1.979 ms 64 bytes from 29.32.189.67: seq=2 ttl=63 time=6.535 ms --- 29.32.189.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.979/3.665/6.535 ms 2026-03-19 06:15:12,883 - INFO - Ping to IP 29.32.189.67 from VM ctest-vn1-vm1-73661438 passed 2026-03-19 06:15:12,883 - INFO - Deleting interface with subnet_id 10159257-a5ba-422b-b4a2-be0f9772a144, port_id None from router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:15:13,204 - INFO - Deleting interface with subnet_id aa7d7bb3-0e0b-43a9-b35f-311fef17a852, port_id None from router 5404adbe-c7b8-469f-bcea-83dab2f1232a 2026-03-19 06:15:13,631 - INFO - Deleting VM ctest-vn2-vm1-59738725 2026-03-19 06:15:13,749 - INFO - Deleting VM ctest-vn1-vm1-73661438 2026-03-19 06:15:13,839 - INFO - Deleting VN ctest-vn2-28208830 2026-03-19 06:15:13,894 - DEBUG - VN f57b3adc-2aec-4eca-b936-ec715d9f2286 still in use: Unable to complete operation on network f57b3adc-2aec-4eca-b936-ec715d9f2286. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-55137344-028f-40d4-8b07-30abfba44cb3'] 2026-03-19 06:15:13,894 - WARNING - Deleting VN ctest-vn2-28208830 failed..Will retry 2026-03-19 06:15:16,089 - DEBUG - Response for deleting network () 2026-03-19 06:15:16,089 - INFO - Deleting VN ctest-vn1-43843007 2026-03-19 06:15:16,343 - DEBUG - Response for deleting network () 2026-03-19 06:15:17,653 - DEBUG - No XMPP flaps were noticed during the test
2026-03-19 06:15:17,654 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:48]
2026-03-19 06:15:17,654 - INFO - -------------------------------------------------------------------------------- 2026-03-19 06:15:18,494 - INFO - Deleted project: ctest-TestRouters-14517362, ID : df52e693-2dae-4486-a9a4-2192aae345f3