2025-11-19 17:22:49,961 - INFO - Domain Default found not creating 2025-11-19 17:22:50,133 - INFO - Project ctest-TestRouters-02633562 not found, creating it 2025-11-19 17:22:50,615 - INFO - Created Project:ctest-TestRouters-02633562, ID : 2ad52e4a-9ecd-48cf-9dc0-1839eb45c824 2025-11-19 17:22:52,184 - INFO - ================================================================================ 2025-11-19 17:22:52,184 - INFO - STARTING TEST : test_basic_router_behavior 2025-11-19 17:22:52,185 - 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-11-19 17:22:52,437 - DEBUG - Nothing to compare xmpp stats {'10.0.0.242': {'10.20.0.192': '0'}} with 2025-11-19 17:22:52,437 - INFO - Initial checks done. Running the testcase now 2025-11-19 17:22:52,437 - INFO - 2025-11-19 17:22:53,075 - DEBUG - Response for create_network : {'network': {'id': '1d7feaa2-89ae-46a0-9f19-090461b5f3da', 'name': 'ctest-vn1-63767882', 'tenant_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'project_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-02633562', 'ctest-vn1-63767882'], 'port_security_enabled': True, 'description': ''}} 2025-11-19 17:22:53,287 - DEBUG - Response for create_subnet : {'subnet': {'id': '33fad013-3fef-47a1-8a67-d9fe44a30c41', 'name': '', 'tenant_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'network_id': '1d7feaa2-89ae-46a0-9f19-090461b5f3da', 'ip_version': 4, 'cidr': '24.152.107.128/26', 'allocation_pools': [{'start': '24.152.107.130', 'end': '24.152.107.190'}], 'gateway_ip': '24.152.107.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '24.152.107.130', 'tags': [], 'project_id': '2ad52e4a9ecd48cf9dc01839eb45c824'}} 2025-11-19 17:22:53,311 - INFO - Created VN ctest-vn1-63767882 2025-11-19 17:22:53,364 - DEBUG - VN ctest-vn1-63767882 UUID is 1d7feaa2-89ae-46a0-9f19-090461b5f3da 2025-11-19 17:22:53,654 - DEBUG - Response for create_network : {'network': {'id': '1e5438b0-9bf0-4d09-865e-940bb502ed6c', 'name': 'ctest-vn2-37327891', 'tenant_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'project_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-02633562', 'ctest-vn2-37327891'], 'port_security_enabled': True, 'description': ''}} 2025-11-19 17:22:53,838 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b308ff9f-a51f-4c02-96d3-e299cdb52d52', 'name': '', 'tenant_id': '2ad52e4a9ecd48cf9dc01839eb45c824', 'network_id': '1e5438b0-9bf0-4d09-865e-940bb502ed6c', 'ip_version': 4, 'cidr': '207.184.63.128/26', 'allocation_pools': [{'start': '207.184.63.130', 'end': '207.184.63.190'}], 'gateway_ip': '207.184.63.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '207.184.63.130', 'tags': [], 'project_id': '2ad52e4a9ecd48cf9dc01839eb45c824'}} 2025-11-19 17:22:53,857 - INFO - Created VN ctest-vn2-37327891 2025-11-19 17:22:53,912 - DEBUG - VN ctest-vn2-37327891 UUID is 1e5438b0-9bf0-4d09-865e-940bb502ed6c 2025-11-19 17:22:54,123 - DEBUG - Services list from nova: [, , ] 2025-11-19 17:22:55,186 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4765-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4765-1) 2025-11-19 17:22:56,459 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4765-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4765-1) 2025-11-19 17:22:56,545 - INFO - Adding interface with subnet_id 33fad013-3fef-47a1-8a67-d9fe44a30c41, port_id None to router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:22:56,814 - INFO - Waiting for VM ctest-vn1-vm1-36828391 to be up.. 2025-11-19 17:22:56,898 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-11-19 17:23:01,982 - DEBUG - VM is in ACTIVE state now 2025-11-19 17:23:01,982 - INFO - VM name : ctest-vn1-vm1-36828391 2025-11-19 17:23:02,076 - DEBUG - VM ctest-vn1-vm1-36828391 ID is be485b75-e3ef-481f-aa47-6e4834a9ac82 2025-11-19 17:23:02,102 - DEBUG - VM ctest-vn1-vm1-36828391 launched on Node cn-jenkins-deploy-platform-ansible-os-4765-1 2025-11-19 17:23:02,199 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/be485b75-e3ef-481f-aa47-6e4834a9ac82 2025-11-19 17:23:02,516 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/be485b75-e3ef-481f-aa47-6e4834a9ac82 2025-11-19 17:23:02,561 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine-interface/58f15c36-fd7f-4caf-a082-acb97d4859c5 2025-11-19 17:23:05,818 - 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') 2025-11-19 17:23:05,818 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-36828391 failed! 2025-11-19 17:23:05,876 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-02633562:ctest-vn1-63767882 is 24.152.107.129 and allocation pool is NOT set 2025-11-19 17:23:07,939 - 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=4.76 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.64 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 = 3.638/4.196/4.755/0.558 ms') 2025-11-19 17:23:07,939 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-36828391 passed 2025-11-19 17:23:08,092 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:08,092 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-36828391, IP 24.152.107.131, Port 22 2025-11-19 17:23:08,159 - 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-11-19 17:23:08,253 - DEBUG - VM ctest-vn1-vm1-36828391 is NOT ready for SSH connections, VM status: ACTIVE 2025-11-19 17:23:13,254 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:13,254 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-36828391, IP 24.152.107.131, Port 22 2025-11-19 17:23:13,422 - DEBUG - VM ctest-vn1-vm1-36828391 is ready for SSH connections 2025-11-19 17:23:13,422 - INFO - Waiting for VM ctest-vn2-vm1-17871742 to be up.. 2025-11-19 17:23:13,504 - DEBUG - VM is in ACTIVE state now 2025-11-19 17:23:13,504 - INFO - VM name : ctest-vn2-vm1-17871742 2025-11-19 17:23:13,593 - DEBUG - VM ctest-vn2-vm1-17871742 ID is f0ee36c4-a99e-4e1d-89a1-0d39a72c476f 2025-11-19 17:23:13,593 - DEBUG - VM ctest-vn2-vm1-17871742 launched on Node cn-jenkins-deploy-platform-ansible-os-4765-1 2025-11-19 17:23:13,686 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine/f0ee36c4-a99e-4e1d-89a1-0d39a72c476f 2025-11-19 17:23:13,696 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-machine-interface/4281e54e-ecac-4af0-988f-b665fb56fe5f 2025-11-19 17:23:14,950 - 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=3.59 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.429 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.429/2.007/3.585/1.578 ms') 2025-11-19 17:23:14,951 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-17871742 passed 2025-11-19 17:23:15,100 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:15,100 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-17871742, IP 207.184.63.131, Port 22 2025-11-19 17:23:15,267 - DEBUG - VM ctest-vn2-vm1-17871742 is ready for SSH connections 2025-11-19 17:23:15,267 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:15,268 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 207.184.63.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-11-19 17:23:15,268 - DEBUG - ping -s 56 -c 3 -W 1 207.184.63.131 2025-11-19 17:23:20,343 - DEBUG - PING 207.184.63.131 (207.184.63.131): 56 data bytes --- 207.184.63.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-11-19 17:23:20,343 - WARNING - Ping to IP 207.184.63.131 from VM ctest-vn1-vm1-36828391 failed 2025-11-19 17:23:20,343 - INFO - Adding interface with subnet_id b308ff9f-a51f-4c02-96d3-e299cdb52d52, port_id None to router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:23:20,603 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:20,603 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 207.184.63.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-11-19 17:23:20,603 - DEBUG - ping -s 56 -c 3 -W 1 207.184.63.131 2025-11-19 17:23:23,837 - DEBUG - PING 207.184.63.131 (207.184.63.131): 56 data bytes 64 bytes from 207.184.63.131: seq=1 ttl=63 time=2.691 ms 64 bytes from 207.184.63.131: seq=2 ttl=63 time=1.096 ms --- 207.184.63.131 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.096/1.893/2.691 ms 2025-11-19 17:23:23,837 - WARNING - Ping to IP 207.184.63.131 from VM ctest-vn1-vm1-36828391 failed 2025-11-19 17:23:24,839 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 207.184.63.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-11-19 17:23:24,839 - DEBUG - ping -s 56 -c 3 -W 1 207.184.63.131 2025-11-19 17:23:27,057 - DEBUG - PING 207.184.63.131 (207.184.63.131): 56 data bytes 64 bytes from 207.184.63.131: seq=0 ttl=63 time=1.805 ms 64 bytes from 207.184.63.131: seq=1 ttl=63 time=0.939 ms 64 bytes from 207.184.63.131: seq=2 ttl=63 time=0.888 ms --- 207.184.63.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.888/1.210/1.805 ms 2025-11-19 17:23:27,057 - INFO - Ping to IP 207.184.63.131 from VM ctest-vn1-vm1-36828391 passed 2025-11-19 17:23:27,058 - INFO - Deleting interface with subnet_id 33fad013-3fef-47a1-8a67-d9fe44a30c41, port_id None from router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:23:27,196 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:27,197 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 207.184.63.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-11-19 17:23:27,197 - DEBUG - ping -s 56 -c 3 -W 1 207.184.63.131 2025-11-19 17:23:30,445 - DEBUG - PING 207.184.63.131 (207.184.63.131): 56 data bytes --- 207.184.63.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-11-19 17:23:30,445 - WARNING - Ping to IP 207.184.63.131 from VM ctest-vn1-vm1-36828391 failed 2025-11-19 17:23:30,446 - INFO - Adding interface with subnet_id 33fad013-3fef-47a1-8a67-d9fe44a30c41, port_id None to router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:23:30,693 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-11-19 17:23:30,693 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 207.184.63.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.242, gateway password: c0ntrail123 2025-11-19 17:23:30,694 - DEBUG - ping -s 56 -c 3 -W 1 207.184.63.131 2025-11-19 17:23:32,912 - DEBUG - PING 207.184.63.131 (207.184.63.131): 56 data bytes 64 bytes from 207.184.63.131: seq=0 ttl=63 time=1.478 ms 64 bytes from 207.184.63.131: seq=1 ttl=63 time=0.842 ms 64 bytes from 207.184.63.131: seq=2 ttl=63 time=1.060 ms --- 207.184.63.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.842/1.126/1.478 ms 2025-11-19 17:23:32,913 - INFO - Ping to IP 207.184.63.131 from VM ctest-vn1-vm1-36828391 passed 2025-11-19 17:23:32,913 - INFO - Deleting interface with subnet_id b308ff9f-a51f-4c02-96d3-e299cdb52d52, port_id None from router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:23:33,067 - INFO - Deleting interface with subnet_id 33fad013-3fef-47a1-8a67-d9fe44a30c41, port_id None from router 4457a09a-bf0b-46bb-bb70-621864161ce7 2025-11-19 17:23:33,273 - INFO - Deleting VM ctest-vn2-vm1-17871742 2025-11-19 17:23:33,360 - INFO - Deleting VM ctest-vn1-vm1-36828391 2025-11-19 17:23:33,452 - INFO - Deleting VN ctest-vn2-37327891 2025-11-19 17:23:33,502 - DEBUG - VN 1e5438b0-9bf0-4d09-865e-940bb502ed6c still in use: Unable to complete operation on network 1e5438b0-9bf0-4d09-865e-940bb502ed6c. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-6be80f68-0f44-477c-ae5e-61cf3d9c8111'] 2025-11-19 17:23:33,502 - WARNING - Deleting VN ctest-vn2-37327891 failed..Will retry 2025-11-19 17:23:35,613 - DEBUG - Response for deleting network () 2025-11-19 17:23:35,613 - INFO - Deleting VN ctest-vn1-63767882 2025-11-19 17:23:35,730 - DEBUG - Response for deleting network () 2025-11-19 17:23:35,985 - DEBUG - No XMPP flaps were noticed during the test
2025-11-19 17:23:35,985 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:43]
2025-11-19 17:23:35,985 - INFO - -------------------------------------------------------------------------------- 2025-11-19 17:23:36,675 - INFO - Deleted project: ctest-TestRouters-02633562, ID : 2ad52e4a-9ecd-48cf-9dc0-1839eb45c824