2025-09-05 16:06:21,354 - INFO - Domain Default found not creating 2025-09-05 16:06:21,692 - INFO - Project ctest-TestRouters-23729163 not found, creating it 2025-09-05 16:06:22,322 - INFO - Created Project:ctest-TestRouters-23729163, ID : 79bed184-ad66-4c17-bf7e-7df4e861e905 2025-09-05 16:06:24,452 - INFO - ================================================================================ 2025-09-05 16:06:24,453 - INFO - STARTING TEST : test_basic_router_behavior 2025-09-05 16:06:24,453 - 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-05 16:06:24,761 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.17': '0'}} with 2025-09-05 16:06:24,762 - INFO - Initial checks done. Running the testcase now 2025-09-05 16:06:24,762 - INFO - 2025-09-05 16:06:25,576 - DEBUG - Response for create_network : {'network': {'id': '741cb32c-b106-4449-9d9d-8a0d738d64df', 'name': 'ctest-vn1-70113144', 'tenant_id': '79bed184ad664c17bf7e7df4e861e905', 'project_id': '79bed184ad664c17bf7e7df4e861e905', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-23729163', 'ctest-vn1-70113144'], 'port_security_enabled': True, 'description': ''}} 2025-09-05 16:06:25,811 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b1a35f8d-488c-4fb4-a838-7cbcf03c555f', 'name': '', 'tenant_id': '79bed184ad664c17bf7e7df4e861e905', 'network_id': '741cb32c-b106-4449-9d9d-8a0d738d64df', 'ip_version': 4, 'cidr': '137.244.157.128/26', 'allocation_pools': [{'start': '137.244.157.130', 'end': '137.244.157.190'}], 'gateway_ip': '137.244.157.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '137.244.157.130', 'tags': [], 'project_id': '79bed184ad664c17bf7e7df4e861e905'}} 2025-09-05 16:06:25,831 - INFO - Created VN ctest-vn1-70113144 2025-09-05 16:06:25,891 - DEBUG - VN ctest-vn1-70113144 UUID is 741cb32c-b106-4449-9d9d-8a0d738d64df 2025-09-05 16:06:26,380 - DEBUG - Response for create_network : {'network': {'id': '16448f18-19e5-4b1e-8237-e5c49fe243a6', 'name': 'ctest-vn2-75166912', 'tenant_id': '79bed184ad664c17bf7e7df4e861e905', 'project_id': '79bed184ad664c17bf7e7df4e861e905', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-23729163', 'ctest-vn2-75166912'], 'port_security_enabled': True, 'description': ''}} 2025-09-05 16:06:26,580 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a1261ceb-f9a0-4ce8-b01e-efd78ef851af', 'name': '', 'tenant_id': '79bed184ad664c17bf7e7df4e861e905', 'network_id': '16448f18-19e5-4b1e-8237-e5c49fe243a6', 'ip_version': 4, 'cidr': '115.37.215.192/26', 'allocation_pools': [{'start': '115.37.215.194', 'end': '115.37.215.254'}], 'gateway_ip': '115.37.215.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '115.37.215.194', 'tags': [], 'project_id': '79bed184ad664c17bf7e7df4e861e905'}} 2025-09-05 16:06:26,599 - INFO - Created VN ctest-vn2-75166912 2025-09-05 16:06:26,655 - DEBUG - VN ctest-vn2-75166912 UUID is 16448f18-19e5-4b1e-8237-e5c49fe243a6 2025-09-05 16:06:26,905 - DEBUG - Services list from nova: [, , ] 2025-09-05 16:06:28,473 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4026-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4026-1) 2025-09-05 16:06:30,016 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4026-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4026-1) 2025-09-05 16:06:30,119 - INFO - Adding interface with subnet_id b1a35f8d-488c-4fb4-a838-7cbcf03c555f, port_id None to router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:30,428 - INFO - Waiting for VM ctest-vn1-vm1-12140384 to be up.. 2025-09-05 16:06:30,524 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-05 16:06:35,705 - DEBUG - VM is in ACTIVE state now 2025-09-05 16:06:35,705 - INFO - VM name : ctest-vn1-vm1-12140384 2025-09-05 16:06:35,849 - DEBUG - VM ctest-vn1-vm1-12140384 ID is f689c9da-29b4-4e78-8587-52b2fe7c3d4b 2025-09-05 16:06:35,887 - DEBUG - VM ctest-vn1-vm1-12140384 launched on Node cn-jenkins-deploy-platform-ansible-os-4026-1 2025-09-05 16:06:36,080 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/f689c9da-29b4-4e78-8587-52b2fe7c3d4b 2025-09-05 16:06:36,448 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/f689c9da-29b4-4e78-8587-52b2fe7c3d4b 2025-09-05 16:06:36,484 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/e0c1f67e-3004-4ca9-bfd9-2ad59d3ae5bc 2025-09-05 16:06:39,764 - 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 1019ms') 2025-09-05 16:06:39,764 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-12140384 failed! 2025-09-05 16:06:39,835 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-23729163:ctest-vn1-70113144 is 137.244.157.129 and allocation pool is NOT set 2025-09-05 16:06:41,905 - 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.32 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.64 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 2.636/3.476/4.316/0.840 ms') 2025-09-05 16:06:41,905 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-12140384 passed 2025-09-05 16:06:42,083 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:42,083 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-12140384, IP 137.244.157.131, Port 22 2025-09-05 16:06:42,268 - DEBUG - VM ctest-vn1-vm1-12140384 is ready for SSH connections 2025-09-05 16:06:42,269 - INFO - Waiting for VM ctest-vn2-vm1-55976662 to be up.. 2025-09-05 16:06:42,399 - DEBUG - VM is in ACTIVE state now 2025-09-05 16:06:42,400 - INFO - VM name : ctest-vn2-vm1-55976662 2025-09-05 16:06:42,552 - DEBUG - VM ctest-vn2-vm1-55976662 ID is a1593706-63d2-48a4-95b0-b41ddd91a02f 2025-09-05 16:06:42,552 - DEBUG - VM ctest-vn2-vm1-55976662 launched on Node cn-jenkins-deploy-platform-ansible-os-4026-1 2025-09-05 16:06:42,728 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/a1593706-63d2-48a4-95b0-b41ddd91a02f 2025-09-05 16:06:42,745 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/491a1415-92a7-4228-be0b-9f2ed74f3b5b 2025-09-05 16:06:44,055 - 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=5.20 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.18 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 = 2.183/3.691/5.199/1.508 ms') 2025-09-05 16:06:44,055 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-55976662 passed 2025-09-05 16:06:44,235 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:44,236 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-55976662, IP 115.37.215.195, Port 22 2025-09-05 16:06:44,437 - DEBUG - VM ctest-vn2-vm1-55976662 is ready for SSH connections 2025-09-05 16:06:44,437 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:44,437 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.37.215.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-09-05 16:06:44,438 - DEBUG - ping -s 56 -c 3 -W 1 115.37.215.195 2025-09-05 16:06:50,215 - DEBUG - PING 115.37.215.195 (115.37.215.195): 56 data bytes --- 115.37.215.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-09-05 16:06:50,215 - WARNING - Ping to IP 115.37.215.195 from VM ctest-vn1-vm1-12140384 failed 2025-09-05 16:06:50,216 - INFO - Adding interface with subnet_id a1261ceb-f9a0-4ce8-b01e-efd78ef851af, port_id None to router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:50,641 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:50,641 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.37.215.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-09-05 16:06:50,641 - DEBUG - ping -s 56 -c 3 -W 1 115.37.215.195 2025-09-05 16:06:52,884 - DEBUG - PING 115.37.215.195 (115.37.215.195): 56 data bytes 64 bytes from 115.37.215.195: seq=0 ttl=63 time=3.195 ms 64 bytes from 115.37.215.195: seq=1 ttl=63 time=2.385 ms 64 bytes from 115.37.215.195: seq=2 ttl=63 time=1.802 ms --- 115.37.215.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.802/2.460/3.195 ms 2025-09-05 16:06:52,885 - INFO - Ping to IP 115.37.215.195 from VM ctest-vn1-vm1-12140384 passed 2025-09-05 16:06:52,885 - INFO - Deleting interface with subnet_id b1a35f8d-488c-4fb4-a838-7cbcf03c555f, port_id None from router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:53,159 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:53,160 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.37.215.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-09-05 16:06:53,160 - DEBUG - ping -s 56 -c 3 -W 1 115.37.215.195 2025-09-05 16:06:56,481 - DEBUG - PING 115.37.215.195 (115.37.215.195): 56 data bytes --- 115.37.215.195 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-09-05 16:06:56,481 - WARNING - Ping to IP 115.37.215.195 from VM ctest-vn1-vm1-12140384 failed 2025-09-05 16:06:56,482 - INFO - Adding interface with subnet_id b1a35f8d-488c-4fb4-a838-7cbcf03c555f, port_id None to router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:56,787 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-05 16:06:56,787 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 115.37.215.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123 2025-09-05 16:06:56,787 - DEBUG - ping -s 56 -c 3 -W 1 115.37.215.195 2025-09-05 16:06:59,019 - DEBUG - PING 115.37.215.195 (115.37.215.195): 56 data bytes 64 bytes from 115.37.215.195: seq=0 ttl=63 time=2.487 ms 64 bytes from 115.37.215.195: seq=1 ttl=63 time=1.749 ms 64 bytes from 115.37.215.195: seq=2 ttl=63 time=1.917 ms --- 115.37.215.195 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.749/2.051/2.487 ms 2025-09-05 16:06:59,020 - INFO - Ping to IP 115.37.215.195 from VM ctest-vn1-vm1-12140384 passed 2025-09-05 16:06:59,020 - INFO - Deleting interface with subnet_id a1261ceb-f9a0-4ce8-b01e-efd78ef851af, port_id None from router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:59,287 - INFO - Deleting interface with subnet_id b1a35f8d-488c-4fb4-a838-7cbcf03c555f, port_id None from router 5b9302f2-0624-4def-8d57-2e962306c6f3 2025-09-05 16:06:59,486 - INFO - Deleting VM ctest-vn2-vm1-55976662 2025-09-05 16:06:59,570 - INFO - Deleting VM ctest-vn1-vm1-12140384 2025-09-05 16:06:59,672 - INFO - Deleting VN ctest-vn2-75166912 2025-09-05 16:06:59,747 - DEBUG - VN 16448f18-19e5-4b1e-8237-e5c49fe243a6 still in use: Unable to complete operation on network 16448f18-19e5-4b1e-8237-e5c49fe243a6. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-4b2da338-0276-4967-bbf8-d000230069c9'] 2025-09-05 16:06:59,747 - WARNING - Deleting VN ctest-vn2-75166912 failed..Will retry 2025-09-05 16:07:01,909 - DEBUG - Response for deleting network () 2025-09-05 16:07:01,909 - INFO - Deleting VN ctest-vn1-70113144 2025-09-05 16:07:02,048 - DEBUG - Response for deleting network () 2025-09-05 16:07:02,348 - DEBUG - No XMPP flaps were noticed during the test
2025-09-05 16:07:02,349 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-09-05 16:07:02,349 - INFO - -------------------------------------------------------------------------------- 2025-09-05 16:07:03,241 - INFO - Deleted project: ctest-TestRouters-23729163, ID : 79bed184-ad66-4c17-bf7e-7df4e861e905