2026-01-29 02:20:51,256 - INFO - Domain Default found not creating 2026-01-29 02:20:51,422 - INFO - Project ctest-TestRouters-15276313 not found, creating it 2026-01-29 02:20:51,989 - INFO - Created Project:ctest-TestRouters-15276313, ID : cda4d599-5959-4566-a6b3-17e7a8195c42 2026-01-29 02:20:53,491 - INFO - ================================================================================ 2026-01-29 02:20:53,491 - INFO - STARTING TEST : test_basic_router_behavior 2026-01-29 02:20:53,492 - 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-01-29 02:20:54,782 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.193': '0', '10.20.0.254': '0'}, '10.0.0.128': {'10.20.0.254': '0', '10.20.0.14': '0'}} with 2026-01-29 02:20:54,782 - INFO - Initial checks done. Running the testcase now 2026-01-29 02:20:54,782 - INFO - 2026-01-29 02:20:55,481 - DEBUG - Response for create_network : {'network': {'id': '7d97b8d3-d7f8-48d7-b286-298f61285496', 'name': 'ctest-vn1-49426132', 'tenant_id': 'cda4d59959594566a6b317e7a8195c42', 'project_id': 'cda4d59959594566a6b317e7a8195c42', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-15276313', 'ctest-vn1-49426132'], 'port_security_enabled': True, 'description': ''}} 2026-01-29 02:20:55,809 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd7e3756e-319f-4d3d-9a16-e498aed20840', 'name': '', 'tenant_id': 'cda4d59959594566a6b317e7a8195c42', 'network_id': '7d97b8d3-d7f8-48d7-b286-298f61285496', 'ip_version': 4, 'cidr': '114.114.53.192/26', 'allocation_pools': [{'start': '114.114.53.194', 'end': '114.114.53.254'}], 'gateway_ip': '114.114.53.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '114.114.53.194', 'tags': [], 'project_id': 'cda4d59959594566a6b317e7a8195c42'}} 2026-01-29 02:20:55,830 - INFO - Created VN ctest-vn1-49426132 2026-01-29 02:20:55,841 - DEBUG - VN ctest-vn1-49426132 UUID is 7d97b8d3-d7f8-48d7-b286-298f61285496 2026-01-29 02:20:56,204 - DEBUG - Response for create_network : {'network': {'id': '94230d3d-4c8c-40d8-bd54-3eb1e6e756e5', 'name': 'ctest-vn2-57494153', 'tenant_id': 'cda4d59959594566a6b317e7a8195c42', 'project_id': 'cda4d59959594566a6b317e7a8195c42', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-15276313', 'ctest-vn2-57494153'], 'port_security_enabled': True, 'description': ''}} 2026-01-29 02:20:56,394 - DEBUG - Response for create_subnet : {'subnet': {'id': '4aa203f6-2db4-4a69-97bc-dd19db6f9155', 'name': '', 'tenant_id': 'cda4d59959594566a6b317e7a8195c42', 'network_id': '94230d3d-4c8c-40d8-bd54-3eb1e6e756e5', 'ip_version': 4, 'cidr': '116.231.60.192/26', 'allocation_pools': [{'start': '116.231.60.194', 'end': '116.231.60.254'}], 'gateway_ip': '116.231.60.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '116.231.60.194', 'tags': [], 'project_id': 'cda4d59959594566a6b317e7a8195c42'}} 2026-01-29 02:20:56,421 - INFO - Created VN ctest-vn2-57494153 2026-01-29 02:20:56,433 - DEBUG - VN ctest-vn2-57494153 UUID is 94230d3d-4c8c-40d8-bd54-3eb1e6e756e5 2026-01-29 02:20:56,573 - DEBUG - Services list from nova: [, , , ] 2026-01-29 02:20:57,585 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5115-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5115-1) 2026-01-29 02:20:58,871 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-5115-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-5115-2) 2026-01-29 02:20:58,981 - INFO - Adding interface with subnet_id d7e3756e-319f-4d3d-9a16-e498aed20840, port_id None to router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:20:59,295 - INFO - Waiting for VM ctest-vn1-vm1-09765848 to be up.. 2026-01-29 02:20:59,460 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-29 02:21:04,551 - DEBUG - VM is in ACTIVE state now 2026-01-29 02:21:04,551 - INFO - VM name : ctest-vn1-vm1-09765848 2026-01-29 02:21:04,636 - DEBUG - VM ctest-vn1-vm1-09765848 ID is 540c5189-e927-43a9-a677-56fb2f1d1b0b 2026-01-29 02:21:04,657 - DEBUG - VM ctest-vn1-vm1-09765848 launched on Node an-jenkins-deploy-platform-ansible-os-5115-1 2026-01-29 02:21:04,740 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/540c5189-e927-43a9-a677-56fb2f1d1b0b 2026-01-29 02:21:05,046 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/540c5189-e927-43a9-a677-56fb2f1d1b0b 2026-01-29 02:21:05,082 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/a189da15-7936-476c-bf9f-814ebcc6137c 2026-01-29 02:21:08,274 - 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-01-29 02:21:08,274 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-09765848 failed! 2026-01-29 02:21:08,288 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-15276313:ctest-vn1-49426132 is 114.114.53.193 and allocation pool is NOT set 2026-01-29 02:21:12,403 - 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 1032ms') 2026-01-29 02:21:12,403 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-09765848 failed! 2026-01-29 02:21:12,417 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-15276313:ctest-vn1-49426132 is 114.114.53.193 and allocation pool is NOT set 2026-01-29 02:21:14,487 - 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.43 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.16 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.161/3.294/5.428/2.133 ms') 2026-01-29 02:21:14,487 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-09765848 passed 2026-01-29 02:21:14,554 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:14,554 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-09765848, IP 114.114.53.195, Port 22 2026-01-29 02:21:14,728 - DEBUG - VM ctest-vn1-vm1-09765848 is ready for SSH connections 2026-01-29 02:21:14,728 - INFO - Waiting for VM ctest-vn2-vm1-53971757 to be up.. 2026-01-29 02:21:14,815 - DEBUG - VM is in ACTIVE state now 2026-01-29 02:21:14,815 - INFO - VM name : ctest-vn2-vm1-53971757 2026-01-29 02:21:14,887 - DEBUG - VM ctest-vn2-vm1-53971757 ID is 9829ecc5-ada1-4b9d-9ba7-fcb4b560cc5f 2026-01-29 02:21:14,888 - DEBUG - VM ctest-vn2-vm1-53971757 launched on Node an-jenkins-deploy-platform-ansible-os-5115-2 2026-01-29 02:21:14,975 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine/9829ecc5-ada1-4b9d-9ba7-fcb4b560cc5f 2026-01-29 02:21:14,987 - DEBUG - Requesting: http://10.0.0.240:8082/virtual-machine-interface/c909d7ea-66f2-43df-aad6-527284a2fceb 2026-01-29 02:21:16,170 - 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.32 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.408 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.408/2.864/5.321/2.456 ms') 2026-01-29 02:21:16,170 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2-vm1-53971757 passed 2026-01-29 02:21:16,242 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:16,242 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-53971757, IP 116.231.60.195, Port 22 2026-01-29 02:21:16,418 - DEBUG - VM ctest-vn2-vm1-53971757 is ready for SSH connections 2026-01-29 02:21:16,418 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:16,418 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 116.231.60.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2026-01-29 02:21:16,418 - DEBUG - ping -s 56 -c 3 -W 1 116.231.60.195 2026-01-29 02:21:20,569 - DEBUG - PING 116.231.60.195 (116.231.60.195): 56 data bytes --- 116.231.60.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-01-29 02:21:20,569 - WARNING - Ping to IP 116.231.60.195 from VM ctest-vn1-vm1-09765848 failed 2026-01-29 02:21:20,569 - INFO - Adding interface with subnet_id 4aa203f6-2db4-4a69-97bc-dd19db6f9155, port_id None to router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:21:20,992 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:20,992 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 116.231.60.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2026-01-29 02:21:20,992 - DEBUG - ping -s 56 -c 3 -W 1 116.231.60.195 2026-01-29 02:21:24,241 - DEBUG - PING 116.231.60.195 (116.231.60.195): 56 data bytes 64 bytes from 116.231.60.195: seq=1 ttl=63 time=4.234 ms 64 bytes from 116.231.60.195: seq=2 ttl=63 time=1.685 ms --- 116.231.60.195 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.685/2.959/4.234 ms 2026-01-29 02:21:24,241 - WARNING - Ping to IP 116.231.60.195 from VM ctest-vn1-vm1-09765848 failed 2026-01-29 02:21:25,242 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 116.231.60.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2026-01-29 02:21:25,242 - DEBUG - ping -s 56 -c 3 -W 1 116.231.60.195 2026-01-29 02:21:27,495 - DEBUG - PING 116.231.60.195 (116.231.60.195): 56 data bytes 64 bytes from 116.231.60.195: seq=0 ttl=63 time=3.486 ms 64 bytes from 116.231.60.195: seq=1 ttl=63 time=1.371 ms 64 bytes from 116.231.60.195: seq=2 ttl=63 time=1.266 ms --- 116.231.60.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.266/2.041/3.486 ms 2026-01-29 02:21:27,495 - INFO - Ping to IP 116.231.60.195 from VM ctest-vn1-vm1-09765848 passed 2026-01-29 02:21:27,495 - INFO - Deleting interface with subnet_id d7e3756e-319f-4d3d-9a16-e498aed20840, port_id None from router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:21:27,778 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:27,778 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 116.231.60.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2026-01-29 02:21:27,778 - DEBUG - ping -s 56 -c 3 -W 1 116.231.60.195 2026-01-29 02:21:31,017 - DEBUG - PING 116.231.60.195 (116.231.60.195): 56 data bytes --- 116.231.60.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-01-29 02:21:31,017 - WARNING - Ping to IP 116.231.60.195 from VM ctest-vn1-vm1-09765848 failed 2026-01-29 02:21:31,017 - INFO - Adding interface with subnet_id d7e3756e-319f-4d3d-9a16-e498aed20840, port_id None to router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:21:31,343 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-29 02:21:31,343 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 116.231.60.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2026-01-29 02:21:31,343 - DEBUG - ping -s 56 -c 3 -W 1 116.231.60.195 2026-01-29 02:21:33,567 - DEBUG - PING 116.231.60.195 (116.231.60.195): 56 data bytes 64 bytes from 116.231.60.195: seq=0 ttl=63 time=3.123 ms 64 bytes from 116.231.60.195: seq=1 ttl=63 time=1.199 ms 64 bytes from 116.231.60.195: seq=2 ttl=63 time=1.197 ms --- 116.231.60.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.197/1.839/3.123 ms 2026-01-29 02:21:33,567 - INFO - Ping to IP 116.231.60.195 from VM ctest-vn1-vm1-09765848 passed 2026-01-29 02:21:33,567 - INFO - Deleting interface with subnet_id 4aa203f6-2db4-4a69-97bc-dd19db6f9155, port_id None from router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:21:33,831 - INFO - Deleting interface with subnet_id d7e3756e-319f-4d3d-9a16-e498aed20840, port_id None from router c0dae7d0-4f90-4b81-be6b-9ab220dbcef7 2026-01-29 02:21:34,101 - INFO - Deleting VM ctest-vn2-vm1-53971757 2026-01-29 02:21:34,205 - INFO - Deleting VM ctest-vn1-vm1-09765848 2026-01-29 02:21:34,285 - INFO - Deleting VN ctest-vn2-57494153 2026-01-29 02:21:34,326 - DEBUG - VN 94230d3d-4c8c-40d8-bd54-3eb1e6e756e5 still in use: Unable to complete operation on network 94230d3d-4c8c-40d8-bd54-3eb1e6e756e5. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-a1cc5565-f8fd-4849-8fb2-184ad47dc8c6'] 2026-01-29 02:21:34,326 - WARNING - Deleting VN ctest-vn2-57494153 failed..Will retry 2026-01-29 02:21:36,469 - DEBUG - Response for deleting network () 2026-01-29 02:21:36,469 - INFO - Deleting VN ctest-vn1-49426132 2026-01-29 02:21:36,611 - DEBUG - Response for deleting network () 2026-01-29 02:21:37,890 - DEBUG - No XMPP flaps were noticed during the test
2026-01-29 02:21:37,890 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:44]
2026-01-29 02:21:37,890 - INFO - -------------------------------------------------------------------------------- 2026-01-29 02:21:38,657 - INFO - Deleted project: ctest-TestRouters-15276313, ID : cda4d599-5959-4566-a6b3-17e7a8195c42