2025-12-01 02:22:18,652 - INFO - Domain Default found not creating 2025-12-01 02:22:18,834 - INFO - Project ctest-TestRouters-92579844 not found, creating it 2025-12-01 02:22:19,471 - INFO - Created Project:ctest-TestRouters-92579844, ID : ae10a84b-ec86-4019-8999-b3a4ac9cbf12 2025-12-01 02:22:21,271 - INFO - ================================================================================ 2025-12-01 02:22:21,272 - INFO - STARTING TEST : test_basic_router_behavior 2025-12-01 02:22:21,272 - 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-01 02:22:22,582 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.209': '0', '10.20.0.192': '0'}, '10.0.0.241': {'10.20.0.209': '0', '10.20.0.192': '0'}} with 2025-12-01 02:22:22,582 - INFO - Initial checks done. Running the testcase now 2025-12-01 02:22:22,583 - INFO - 2025-12-01 02:22:23,443 - DEBUG - Response for create_network : {'network': {'id': 'ae42d7e1-74ff-4e24-ad0e-a3a794e6140b', 'name': 'ctest-vn1-08994415', 'tenant_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'project_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-92579844', 'ctest-vn1-08994415'], 'port_security_enabled': True, 'description': ''}} 2025-12-01 02:22:23,797 - DEBUG - Response for create_subnet : {'subnet': {'id': '002c8a6a-05ac-4405-9172-e05bc298cf5c', 'name': '', 'tenant_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'network_id': 'ae42d7e1-74ff-4e24-ad0e-a3a794e6140b', 'ip_version': 4, 'cidr': '185.23.165.128/26', 'allocation_pools': [{'start': '185.23.165.130', 'end': '185.23.165.190'}], 'gateway_ip': '185.23.165.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '185.23.165.130', 'tags': [], 'project_id': 'ae10a84bec8640198999b3a4ac9cbf12'}} 2025-12-01 02:22:23,828 - INFO - Created VN ctest-vn1-08994415 2025-12-01 02:22:23,843 - DEBUG - VN ctest-vn1-08994415 UUID is ae42d7e1-74ff-4e24-ad0e-a3a794e6140b 2025-12-01 02:22:24,287 - DEBUG - Response for create_network : {'network': {'id': 'dd9c59e7-69c8-44b5-a468-4463efdf3e66', 'name': 'ctest-vn2-62627018', 'tenant_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'project_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-92579844', 'ctest-vn2-62627018'], 'port_security_enabled': True, 'description': ''}} 2025-12-01 02:22:24,558 - DEBUG - Response for create_subnet : {'subnet': {'id': '40088e45-a9a1-470c-b66f-7078c809f7b5', 'name': '', 'tenant_id': 'ae10a84bec8640198999b3a4ac9cbf12', 'network_id': 'dd9c59e7-69c8-44b5-a468-4463efdf3e66', 'ip_version': 4, 'cidr': '148.134.22.192/26', 'allocation_pools': [{'start': '148.134.22.194', 'end': '148.134.22.254'}], 'gateway_ip': '148.134.22.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '148.134.22.194', 'tags': [], 'project_id': 'ae10a84bec8640198999b3a4ac9cbf12'}} 2025-12-01 02:22:24,582 - INFO - Created VN ctest-vn2-62627018 2025-12-01 02:22:24,600 - DEBUG - VN ctest-vn2-62627018 UUID is dd9c59e7-69c8-44b5-a468-4463efdf3e66 2025-12-01 02:22:24,779 - DEBUG - Services list from nova: [, , , ] 2025-12-01 02:22:26,229 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4827-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4827-1) 2025-12-01 02:22:27,881 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4827-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4827-2) 2025-12-01 02:22:27,990 - INFO - Adding interface with subnet_id 002c8a6a-05ac-4405-9172-e05bc298cf5c, port_id None to router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:22:28,506 - INFO - Waiting for VM ctest-vn1-vm1-96503301 to be up.. 2025-12-01 02:22:28,676 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-12-01 02:22:33,783 - DEBUG - VM is in ACTIVE state now 2025-12-01 02:22:33,783 - INFO - VM name : ctest-vn1-vm1-96503301 2025-12-01 02:22:33,881 - DEBUG - VM ctest-vn1-vm1-96503301 ID is daed2226-3f2d-49d3-8dbd-16811a7a17b2 2025-12-01 02:22:33,908 - DEBUG - VM ctest-vn1-vm1-96503301 launched on Node an-jenkins-deploy-platform-ansible-os-4827-1 2025-12-01 02:22:34,013 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/daed2226-3f2d-49d3-8dbd-16811a7a17b2 2025-12-01 02:22:34,360 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/daed2226-3f2d-49d3-8dbd-16811a7a17b2 2025-12-01 02:22:34,404 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/b875de31-b1c8-4afb-beb3-87836ec296de 2025-12-01 02:22:37,640 - 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 1025ms') 2025-12-01 02:22:37,641 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-96503301 failed! 2025-12-01 02:22:37,658 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-92579844:ctest-vn1-08994415 is 185.23.165.129 and allocation pool is NOT set 2025-12-01 02:22:39,727 - 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=10.3 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.28 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 = 2.282/6.274/10.267/3.992 ms') 2025-12-01 02:22:39,727 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-96503301 passed 2025-12-01 02:22:39,800 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:39,800 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-96503301, IP 185.23.165.131, Port 22 2025-12-01 02:22:40,002 - DEBUG - VM ctest-vn1-vm1-96503301 is ready for SSH connections 2025-12-01 02:22:40,002 - INFO - Waiting for VM ctest-vn2-vm1-05820326 to be up.. 2025-12-01 02:22:40,134 - DEBUG - VM is in ACTIVE state now 2025-12-01 02:22:40,135 - INFO - VM name : ctest-vn2-vm1-05820326 2025-12-01 02:22:40,252 - DEBUG - VM ctest-vn2-vm1-05820326 ID is cdc193fd-032a-458a-83c3-7eec1d3966de 2025-12-01 02:22:40,253 - DEBUG - VM ctest-vn2-vm1-05820326 launched on Node an-jenkins-deploy-platform-ansible-os-4827-2 2025-12-01 02:22:40,385 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/cdc193fd-032a-458a-83c3-7eec1d3966de 2025-12-01 02:22:40,400 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/32b4da37-42e9-4f4a-8b8b-5f3155c24a9a 2025-12-01 02:22:41,588 - 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=3.61 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.96 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 = 2.960/3.285/3.610/0.325 ms') 2025-12-01 02:22:41,588 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2-vm1-05820326 passed 2025-12-01 02:22:41,664 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:41,664 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-05820326, IP 148.134.22.195, Port 22 2025-12-01 02:22:41,733 - DEBUG - Error on ssh to cirros@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-12-01 02:22:41,859 - DEBUG - VM ctest-vn2-vm1-05820326 is NOT ready for SSH connections, VM status: ACTIVE 2025-12-01 02:22:46,859 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:46,859 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-05820326, IP 148.134.22.195, Port 22 2025-12-01 02:22:47,033 - DEBUG - VM ctest-vn2-vm1-05820326 is ready for SSH connections 2025-12-01 02:22:47,033 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:47,033 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 148.134.22.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-12-01 02:22:47,034 - DEBUG - ping -s 56 -c 3 -W 1 148.134.22.195 2025-12-01 02:22:51,056 - DEBUG - PING 148.134.22.195 (148.134.22.195): 56 data bytes --- 148.134.22.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-12-01 02:22:51,056 - WARNING - Ping to IP 148.134.22.195 from VM ctest-vn1-vm1-96503301 failed 2025-12-01 02:22:51,056 - INFO - Adding interface with subnet_id 40088e45-a9a1-470c-b66f-7078c809f7b5, port_id None to router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:22:51,545 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:51,545 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 148.134.22.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-12-01 02:22:51,545 - DEBUG - ping -s 56 -c 3 -W 1 148.134.22.195 2025-12-01 02:22:53,754 - DEBUG - PING 148.134.22.195 (148.134.22.195): 56 data bytes 64 bytes from 148.134.22.195: seq=0 ttl=63 time=4.280 ms 64 bytes from 148.134.22.195: seq=1 ttl=63 time=1.208 ms 64 bytes from 148.134.22.195: seq=2 ttl=63 time=1.233 ms --- 148.134.22.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.208/2.240/4.280 ms 2025-12-01 02:22:53,754 - INFO - Ping to IP 148.134.22.195 from VM ctest-vn1-vm1-96503301 passed 2025-12-01 02:22:53,754 - INFO - Deleting interface with subnet_id 002c8a6a-05ac-4405-9172-e05bc298cf5c, port_id None from router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:22:54,022 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:54,022 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 148.134.22.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-12-01 02:22:54,023 - DEBUG - ping -s 56 -c 3 -W 1 148.134.22.195 2025-12-01 02:22:57,231 - DEBUG - PING 148.134.22.195 (148.134.22.195): 56 data bytes --- 148.134.22.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-12-01 02:22:57,231 - WARNING - Ping to IP 148.134.22.195 from VM ctest-vn1-vm1-96503301 failed 2025-12-01 02:22:57,231 - INFO - Adding interface with subnet_id 002c8a6a-05ac-4405-9172-e05bc298cf5c, port_id None to router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:22:57,599 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-12-01 02:22:57,599 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 148.134.22.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-12-01 02:22:57,599 - DEBUG - ping -s 56 -c 3 -W 1 148.134.22.195 2025-12-01 02:22:59,807 - DEBUG - PING 148.134.22.195 (148.134.22.195): 56 data bytes 64 bytes from 148.134.22.195: seq=0 ttl=63 time=4.043 ms 64 bytes from 148.134.22.195: seq=1 ttl=63 time=0.960 ms 64 bytes from 148.134.22.195: seq=2 ttl=63 time=1.138 ms --- 148.134.22.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.960/2.047/4.043 ms 2025-12-01 02:22:59,807 - INFO - Ping to IP 148.134.22.195 from VM ctest-vn1-vm1-96503301 passed 2025-12-01 02:22:59,807 - INFO - Deleting interface with subnet_id 40088e45-a9a1-470c-b66f-7078c809f7b5, port_id None from router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:23:00,108 - INFO - Deleting interface with subnet_id 002c8a6a-05ac-4405-9172-e05bc298cf5c, port_id None from router 739091b1-7337-4c98-a901-d5a886592f6e 2025-12-01 02:23:00,504 - INFO - Deleting VM ctest-vn2-vm1-05820326 2025-12-01 02:23:00,630 - INFO - Deleting VM ctest-vn1-vm1-96503301 2025-12-01 02:23:00,705 - INFO - Deleting VN ctest-vn2-62627018 2025-12-01 02:23:00,755 - DEBUG - VN dd9c59e7-69c8-44b5-a468-4463efdf3e66 still in use: Unable to complete operation on network dd9c59e7-69c8-44b5-a468-4463efdf3e66. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-8b7dafd8-6cd8-4527-9f94-e261f99ad067'] 2025-12-01 02:23:00,755 - WARNING - Deleting VN ctest-vn2-62627018 failed..Will retry 2025-12-01 02:23:02,923 - DEBUG - Response for deleting network () 2025-12-01 02:23:02,923 - INFO - Deleting VN ctest-vn1-08994415 2025-12-01 02:23:03,087 - DEBUG - Response for deleting network () 2025-12-01 02:23:04,372 - DEBUG - No XMPP flaps were noticed during the test
2025-12-01 02:23:04,372 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:43]
2025-12-01 02:23:04,372 - INFO - -------------------------------------------------------------------------------- 2025-12-01 02:23:05,239 - INFO - Deleted project: ctest-TestRouters-92579844, ID : ae10a84b-ec86-4019-8999-b3a4ac9cbf12