2025-09-18 01:55:40,762 - INFO - Domain Default found not creating 2025-09-18 01:55:40,908 - INFO - Project ctest-TestRouters-89674475 not found, creating it 2025-09-18 01:55:41,362 - INFO - Created Project:ctest-TestRouters-89674475, ID : 1309aed6-8924-4cca-9a4e-710ee6746eaa 2025-09-18 01:55:42,959 - INFO - ================================================================================ 2025-09-18 01:55:42,960 - INFO - STARTING TEST : test_basic_router_behavior 2025-09-18 01:55:42,960 - 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-09-18 01:55:43,217 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.18': '0'}} with 2025-09-18 01:55:43,217 - INFO - Initial checks done. Running the testcase now 2025-09-18 01:55:43,218 - INFO - 2025-09-18 01:55:43,822 - DEBUG - Response for create_network : {'network': {'id': '1b51e858-3a29-44dc-bdc8-d168d05291f4', 'name': 'ctest-vn1-20514962', 'tenant_id': '1309aed689244cca9a4e710ee6746eaa', 'project_id': '1309aed689244cca9a4e710ee6746eaa', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-89674475', 'ctest-vn1-20514962'], 'port_security_enabled': True, 'description': ''}} 2025-09-18 01:55:43,980 - DEBUG - Response for create_subnet : {'subnet': {'id': '67afec56-f9c7-46b8-8105-fe1bbd04df3e', 'name': '', 'tenant_id': '1309aed689244cca9a4e710ee6746eaa', 'network_id': '1b51e858-3a29-44dc-bdc8-d168d05291f4', 'ip_version': 4, 'cidr': '56.1.162.128/26', 'allocation_pools': [{'start': '56.1.162.130', 'end': '56.1.162.190'}], 'gateway_ip': '56.1.162.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '56.1.162.130', 'tags': [], 'project_id': '1309aed689244cca9a4e710ee6746eaa'}} 2025-09-18 01:55:44,005 - INFO - Created VN ctest-vn1-20514962 2025-09-18 01:55:44,059 - DEBUG - VN ctest-vn1-20514962 UUID is 1b51e858-3a29-44dc-bdc8-d168d05291f4 2025-09-18 01:55:44,377 - DEBUG - Response for create_network : {'network': {'id': '6e3e5385-6a6b-4c9e-bf07-b285e9e15ede', 'name': 'ctest-vn2-29461431', 'tenant_id': '1309aed689244cca9a4e710ee6746eaa', 'project_id': '1309aed689244cca9a4e710ee6746eaa', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-89674475', 'ctest-vn2-29461431'], 'port_security_enabled': True, 'description': ''}} 2025-09-18 01:55:44,543 - DEBUG - Response for create_subnet : {'subnet': {'id': '868bebcb-a077-41e7-b66b-389041d98df9', 'name': '', 'tenant_id': '1309aed689244cca9a4e710ee6746eaa', 'network_id': '6e3e5385-6a6b-4c9e-bf07-b285e9e15ede', 'ip_version': 4, 'cidr': '36.105.7.64/26', 'allocation_pools': [{'start': '36.105.7.66', 'end': '36.105.7.126'}], 'gateway_ip': '36.105.7.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '36.105.7.66', 'tags': [], 'project_id': '1309aed689244cca9a4e710ee6746eaa'}} 2025-09-18 01:55:44,560 - INFO - Created VN ctest-vn2-29461431 2025-09-18 01:55:44,611 - DEBUG - VN ctest-vn2-29461431 UUID is 6e3e5385-6a6b-4c9e-bf07-b285e9e15ede 2025-09-18 01:55:44,784 - DEBUG - Services list from nova: [, , ] 2025-09-18 01:55:45,907 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4131-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4131-1) 2025-09-18 01:55:47,247 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4131-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4131-1) 2025-09-18 01:55:47,321 - INFO - Adding interface with subnet_id 67afec56-f9c7-46b8-8105-fe1bbd04df3e, port_id None to router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:55:47,647 - INFO - Waiting for VM ctest-vn1-vm1-38177132 to be up.. 2025-09-18 01:55:47,733 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-18 01:55:52,808 - DEBUG - VM is in ACTIVE state now 2025-09-18 01:55:52,808 - INFO - VM name : ctest-vn1-vm1-38177132 2025-09-18 01:55:52,884 - DEBUG - VM ctest-vn1-vm1-38177132 ID is 1dc17521-25c2-4f29-affe-8417226f18f4 2025-09-18 01:55:52,907 - DEBUG - VM ctest-vn1-vm1-38177132 launched on Node cn-jenkins-deploy-platform-ansible-os-4131-1 2025-09-18 01:55:52,990 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/1dc17521-25c2-4f29-affe-8417226f18f4 2025-09-18 01:55:53,341 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/1dc17521-25c2-4f29-affe-8417226f18f4 2025-09-18 01:55:53,372 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/20e3f1a5-9f44-4636-914d-755548d156e9 2025-09-18 01:55:56,634 - 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-09-18 01:55:56,634 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-38177132 failed! 2025-09-18 01:55:56,687 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-89674475:ctest-vn1-20514962 is 56.1.162.129 and allocation pool is NOT set 2025-09-18 01:55:58,752 - 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.03 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.718 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.718/1.872/3.027/1.154 ms') 2025-09-18 01:55:58,752 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-38177132 passed 2025-09-18 01:55:58,907 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:55:58,907 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-38177132, IP 56.1.162.131, Port 22 2025-09-18 01:55:59,073 - DEBUG - VM ctest-vn1-vm1-38177132 is ready for SSH connections 2025-09-18 01:55:59,073 - INFO - Waiting for VM ctest-vn2-vm1-56203567 to be up.. 2025-09-18 01:55:59,149 - DEBUG - VM is in ACTIVE state now 2025-09-18 01:55:59,149 - INFO - VM name : ctest-vn2-vm1-56203567 2025-09-18 01:55:59,292 - DEBUG - VM ctest-vn2-vm1-56203567 ID is 52146695-03cd-487b-aa69-24e80a6ea774 2025-09-18 01:55:59,292 - DEBUG - VM ctest-vn2-vm1-56203567 launched on Node cn-jenkins-deploy-platform-ansible-os-4131-1 2025-09-18 01:55:59,439 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/52146695-03cd-487b-aa69-24e80a6ea774 2025-09-18 01:55:59,450 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/152e96dd-ccf5-40a3-9618-e524486e347f 2025-09-18 01:56:00,734 - 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=4.38 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.25 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.245/2.813/4.382/1.568 ms') 2025-09-18 01:56:00,734 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-56203567 passed 2025-09-18 01:56:00,883 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:56:00,883 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-56203567, IP 36.105.7.67, Port 22 2025-09-18 01:56:01,038 - DEBUG - VM ctest-vn2-vm1-56203567 is ready for SSH connections 2025-09-18 01:56:01,039 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:56:01,039 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 36.105.7.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-09-18 01:56:01,039 - DEBUG - ping -s 56 -c 3 -W 1 36.105.7.67 2025-09-18 01:56:06,092 - DEBUG - PING 36.105.7.67 (36.105.7.67): 56 data bytes --- 36.105.7.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-09-18 01:56:06,092 - WARNING - Ping to IP 36.105.7.67 from VM ctest-vn1-vm1-38177132 failed 2025-09-18 01:56:06,093 - INFO - Adding interface with subnet_id 868bebcb-a077-41e7-b66b-389041d98df9, port_id None to router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:56:06,360 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:56:06,360 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 36.105.7.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-09-18 01:56:06,360 - DEBUG - ping -s 56 -c 3 -W 1 36.105.7.67 2025-09-18 01:56:09,590 - DEBUG - PING 36.105.7.67 (36.105.7.67): 56 data bytes 64 bytes from 36.105.7.67: seq=1 ttl=63 time=2.781 ms 64 bytes from 36.105.7.67: seq=2 ttl=63 time=1.002 ms --- 36.105.7.67 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.002/1.891/2.781 ms 2025-09-18 01:56:09,590 - WARNING - Ping to IP 36.105.7.67 from VM ctest-vn1-vm1-38177132 failed 2025-09-18 01:56:10,591 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 36.105.7.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-09-18 01:56:10,591 - DEBUG - ping -s 56 -c 3 -W 1 36.105.7.67 2025-09-18 01:56:12,816 - DEBUG - PING 36.105.7.67 (36.105.7.67): 56 data bytes 64 bytes from 36.105.7.67: seq=0 ttl=63 time=1.406 ms 64 bytes from 36.105.7.67: seq=1 ttl=63 time=0.868 ms 64 bytes from 36.105.7.67: seq=2 ttl=63 time=0.831 ms --- 36.105.7.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.831/1.035/1.406 ms 2025-09-18 01:56:12,816 - INFO - Ping to IP 36.105.7.67 from VM ctest-vn1-vm1-38177132 passed 2025-09-18 01:56:12,816 - INFO - Deleting interface with subnet_id 67afec56-f9c7-46b8-8105-fe1bbd04df3e, port_id None from router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:56:12,938 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:56:12,939 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 36.105.7.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-09-18 01:56:12,939 - DEBUG - ping -s 56 -c 3 -W 1 36.105.7.67 2025-09-18 01:56:16,160 - DEBUG - PING 36.105.7.67 (36.105.7.67): 56 data bytes --- 36.105.7.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-09-18 01:56:16,160 - WARNING - Ping to IP 36.105.7.67 from VM ctest-vn1-vm1-38177132 failed 2025-09-18 01:56:16,160 - INFO - Adding interface with subnet_id 67afec56-f9c7-46b8-8105-fe1bbd04df3e, port_id None to router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:56:16,378 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-18 01:56:16,379 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 36.105.7.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123 2025-09-18 01:56:16,379 - DEBUG - ping -s 56 -c 3 -W 1 36.105.7.67 2025-09-18 01:56:18,604 - DEBUG - PING 36.105.7.67 (36.105.7.67): 56 data bytes 64 bytes from 36.105.7.67: seq=0 ttl=63 time=1.625 ms 64 bytes from 36.105.7.67: seq=1 ttl=63 time=0.949 ms 64 bytes from 36.105.7.67: seq=2 ttl=63 time=0.957 ms --- 36.105.7.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.949/1.177/1.625 ms 2025-09-18 01:56:18,604 - INFO - Ping to IP 36.105.7.67 from VM ctest-vn1-vm1-38177132 passed 2025-09-18 01:56:18,604 - INFO - Deleting interface with subnet_id 868bebcb-a077-41e7-b66b-389041d98df9, port_id None from router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:56:18,728 - INFO - Deleting interface with subnet_id 67afec56-f9c7-46b8-8105-fe1bbd04df3e, port_id None from router ef736538-3b6e-4f95-99a8-7d02142687dd 2025-09-18 01:56:18,933 - INFO - Deleting VM ctest-vn2-vm1-56203567 2025-09-18 01:56:19,014 - INFO - Deleting VM ctest-vn1-vm1-38177132 2025-09-18 01:56:19,090 - INFO - Deleting VN ctest-vn2-29461431 2025-09-18 01:56:19,127 - DEBUG - VN 6e3e5385-6a6b-4c9e-bf07-b285e9e15ede still in use: Unable to complete operation on network 6e3e5385-6a6b-4c9e-bf07-b285e9e15ede. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-f6f6e611-6c6b-49fe-8687-16fe2bc76299'] 2025-09-18 01:56:19,127 - WARNING - Deleting VN ctest-vn2-29461431 failed..Will retry 2025-09-18 01:56:21,228 - DEBUG - Response for deleting network () 2025-09-18 01:56:21,228 - INFO - Deleting VN ctest-vn1-20514962 2025-09-18 01:56:21,328 - DEBUG - Response for deleting network () 2025-09-18 01:56:21,592 - DEBUG - No XMPP flaps were noticed during the test
2025-09-18 01:56:21,592 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-09-18 01:56:21,592 - INFO - -------------------------------------------------------------------------------- 2025-09-18 01:56:22,294 - INFO - Deleted project: ctest-TestRouters-89674475, ID : 1309aed6-8924-4cca-9a4e-710ee6746eaa