2025-10-27 04:07:31,998 - INFO - Domain Default found not creating 2025-10-27 04:07:32,144 - INFO - Project ctest-TestRouters-71351539 not found, creating it 2025-10-27 04:07:32,622 - INFO - Created Project:ctest-TestRouters-71351539, ID : 23cb1e01-3dca-4ff1-8f40-8e2a5189e18c 2025-10-27 04:07:34,055 - INFO - ================================================================================ 2025-10-27 04:07:34,056 - INFO - STARTING TEST : test_basic_router_behavior 2025-10-27 04:07:34,056 - 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-10-27 04:07:34,310 - DEBUG - Nothing to compare xmpp stats {'10.0.0.27': {'10.20.0.254': '0'}} with 2025-10-27 04:07:34,310 - INFO - Initial checks done. Running the testcase now 2025-10-27 04:07:34,310 - INFO - 2025-10-27 04:07:34,896 - DEBUG - Response for create_network : {'network': {'id': '0f523b67-4dff-4fd2-9ab6-5816eef5e97e', 'name': 'ctest-vn1-32066241', 'tenant_id': '23cb1e013dca4ff18f408e2a5189e18c', 'project_id': '23cb1e013dca4ff18f408e2a5189e18c', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-71351539', 'ctest-vn1-32066241'], 'port_security_enabled': True, 'description': ''}} 2025-10-27 04:07:35,118 - DEBUG - Response for create_subnet : {'subnet': {'id': '982057e5-7ad3-4183-a3ff-56aa8744975b', 'name': '', 'tenant_id': '23cb1e013dca4ff18f408e2a5189e18c', 'network_id': '0f523b67-4dff-4fd2-9ab6-5816eef5e97e', 'ip_version': 4, 'cidr': '154.147.215.0/26', 'allocation_pools': [{'start': '154.147.215.2', 'end': '154.147.215.62'}], 'gateway_ip': '154.147.215.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '154.147.215.2', 'tags': [], 'project_id': '23cb1e013dca4ff18f408e2a5189e18c'}} 2025-10-27 04:07:35,135 - INFO - Created VN ctest-vn1-32066241 2025-10-27 04:07:35,188 - DEBUG - VN ctest-vn1-32066241 UUID is 0f523b67-4dff-4fd2-9ab6-5816eef5e97e 2025-10-27 04:07:35,546 - DEBUG - Response for create_network : {'network': {'id': 'a5c9da37-5ce1-47c4-af0f-2f4ede04bc71', 'name': 'ctest-vn2-51592753', 'tenant_id': '23cb1e013dca4ff18f408e2a5189e18c', 'project_id': '23cb1e013dca4ff18f408e2a5189e18c', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-71351539', 'ctest-vn2-51592753'], 'port_security_enabled': True, 'description': ''}} 2025-10-27 04:07:35,723 - DEBUG - Response for create_subnet : {'subnet': {'id': 'ab83e2f8-2c70-4836-a964-4ff009b14993', 'name': '', 'tenant_id': '23cb1e013dca4ff18f408e2a5189e18c', 'network_id': 'a5c9da37-5ce1-47c4-af0f-2f4ede04bc71', 'ip_version': 4, 'cidr': '157.107.82.128/26', 'allocation_pools': [{'start': '157.107.82.130', 'end': '157.107.82.190'}], 'gateway_ip': '157.107.82.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '157.107.82.130', 'tags': [], 'project_id': '23cb1e013dca4ff18f408e2a5189e18c'}} 2025-10-27 04:07:35,740 - INFO - Created VN ctest-vn2-51592753 2025-10-27 04:07:35,792 - DEBUG - VN ctest-vn2-51592753 UUID is a5c9da37-5ce1-47c4-af0f-2f4ede04bc71 2025-10-27 04:07:35,964 - DEBUG - Services list from nova: [, , ] 2025-10-27 04:07:37,118 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4491-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4491-1) 2025-10-27 04:07:38,247 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4491-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4491-1) 2025-10-27 04:07:38,323 - INFO - Adding interface with subnet_id 982057e5-7ad3-4183-a3ff-56aa8744975b, port_id None to router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:07:38,621 - INFO - Waiting for VM ctest-vn1-vm1-78497451 to be up.. 2025-10-27 04:07:38,723 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-10-27 04:07:43,794 - DEBUG - VM is in ACTIVE state now 2025-10-27 04:07:43,794 - INFO - VM name : ctest-vn1-vm1-78497451 2025-10-27 04:07:43,863 - DEBUG - VM ctest-vn1-vm1-78497451 ID is cb336d09-7fca-401e-a02c-d598e80f8ba8 2025-10-27 04:07:43,881 - DEBUG - VM ctest-vn1-vm1-78497451 launched on Node cn-jenkins-deploy-platform-ansible-os-4491-1 2025-10-27 04:07:43,954 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/cb336d09-7fca-401e-a02c-d598e80f8ba8 2025-10-27 04:07:44,254 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/cb336d09-7fca-401e-a02c-d598e80f8ba8 2025-10-27 04:07:44,285 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/8f77319b-8422-4c01-b012-93ed7fb3a263 2025-10-27 04:07:47,560 - 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 1030ms') 2025-10-27 04:07:47,560 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-78497451 failed! 2025-10-27 04:07:47,612 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-71351539:ctest-vn1-32066241 is 154.147.215.1 and allocation pool is NOT set 2025-10-27 04:07:49,671 - 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.72 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.487 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 = 0.487/2.103/3.720/1.616 ms') 2025-10-27 04:07:49,671 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-78497451 passed 2025-10-27 04:07:49,824 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:07:49,825 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-78497451, IP 154.147.215.3, Port 22 2025-10-27 04:07:49,992 - DEBUG - VM ctest-vn1-vm1-78497451 is ready for SSH connections 2025-10-27 04:07:49,992 - INFO - Waiting for VM ctest-vn2-vm1-78354890 to be up.. 2025-10-27 04:07:50,070 - DEBUG - VM is in ACTIVE state now 2025-10-27 04:07:50,070 - INFO - VM name : ctest-vn2-vm1-78354890 2025-10-27 04:07:50,145 - DEBUG - VM ctest-vn2-vm1-78354890 ID is ea8d3ad6-e9ff-4060-b220-682acce84224 2025-10-27 04:07:50,145 - DEBUG - VM ctest-vn2-vm1-78354890 launched on Node cn-jenkins-deploy-platform-ansible-os-4491-1 2025-10-27 04:07:50,226 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/ea8d3ad6-e9ff-4060-b220-682acce84224 2025-10-27 04:07:50,234 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/65c84e34-d415-4f8d-a5e5-5f2622386dd3 2025-10-27 04:07:51,471 - 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=2.99 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.503 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.503/1.746/2.990/1.243 ms') 2025-10-27 04:07:51,471 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-78354890 passed 2025-10-27 04:07:51,620 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:07:51,620 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-78354890, IP 157.107.82.131, Port 22 2025-10-27 04:07:51,780 - DEBUG - VM ctest-vn2-vm1-78354890 is ready for SSH connections 2025-10-27 04:07:51,780 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:07:51,780 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.107.82.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-10-27 04:07:51,780 - DEBUG - ping -s 56 -c 3 -W 1 157.107.82.131 2025-10-27 04:07:56,729 - DEBUG - PING 157.107.82.131 (157.107.82.131): 56 data bytes --- 157.107.82.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-10-27 04:07:56,729 - WARNING - Ping to IP 157.107.82.131 from VM ctest-vn1-vm1-78497451 failed 2025-10-27 04:07:56,730 - INFO - Adding interface with subnet_id ab83e2f8-2c70-4836-a964-4ff009b14993, port_id None to router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:07:56,964 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:07:56,964 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.107.82.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-10-27 04:07:56,964 - DEBUG - ping -s 56 -c 3 -W 1 157.107.82.131 2025-10-27 04:08:00,166 - DEBUG - PING 157.107.82.131 (157.107.82.131): 56 data bytes 64 bytes from 157.107.82.131: seq=1 ttl=63 time=2.469 ms 64 bytes from 157.107.82.131: seq=2 ttl=63 time=0.845 ms --- 157.107.82.131 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 0.845/1.657/2.469 ms 2025-10-27 04:08:00,166 - WARNING - Ping to IP 157.107.82.131 from VM ctest-vn1-vm1-78497451 failed 2025-10-27 04:08:01,167 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.107.82.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-10-27 04:08:01,167 - DEBUG - ping -s 56 -c 3 -W 1 157.107.82.131 2025-10-27 04:08:03,375 - DEBUG - PING 157.107.82.131 (157.107.82.131): 56 data bytes 64 bytes from 157.107.82.131: seq=0 ttl=63 time=1.753 ms 64 bytes from 157.107.82.131: seq=1 ttl=63 time=1.621 ms 64 bytes from 157.107.82.131: seq=2 ttl=63 time=0.872 ms --- 157.107.82.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.872/1.415/1.753 ms 2025-10-27 04:08:03,375 - INFO - Ping to IP 157.107.82.131 from VM ctest-vn1-vm1-78497451 passed 2025-10-27 04:08:03,376 - INFO - Deleting interface with subnet_id 982057e5-7ad3-4183-a3ff-56aa8744975b, port_id None from router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:08:03,512 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:08:03,512 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.107.82.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-10-27 04:08:03,512 - DEBUG - ping -s 56 -c 3 -W 1 157.107.82.131 2025-10-27 04:08:06,721 - DEBUG - PING 157.107.82.131 (157.107.82.131): 56 data bytes --- 157.107.82.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-10-27 04:08:06,721 - WARNING - Ping to IP 157.107.82.131 from VM ctest-vn1-vm1-78497451 failed 2025-10-27 04:08:06,721 - INFO - Adding interface with subnet_id 982057e5-7ad3-4183-a3ff-56aa8744975b, port_id None to router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:08:06,922 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-27 04:08:06,923 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.107.82.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.27, gateway password: c0ntrail123 2025-10-27 04:08:06,923 - DEBUG - ping -s 56 -c 3 -W 1 157.107.82.131 2025-10-27 04:08:09,130 - DEBUG - PING 157.107.82.131 (157.107.82.131): 56 data bytes 64 bytes from 157.107.82.131: seq=0 ttl=63 time=1.553 ms 64 bytes from 157.107.82.131: seq=1 ttl=63 time=1.320 ms 64 bytes from 157.107.82.131: seq=2 ttl=63 time=0.961 ms --- 157.107.82.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.961/1.278/1.553 ms 2025-10-27 04:08:09,130 - INFO - Ping to IP 157.107.82.131 from VM ctest-vn1-vm1-78497451 passed 2025-10-27 04:08:09,130 - INFO - Deleting interface with subnet_id ab83e2f8-2c70-4836-a964-4ff009b14993, port_id None from router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:08:09,255 - INFO - Deleting interface with subnet_id 982057e5-7ad3-4183-a3ff-56aa8744975b, port_id None from router 5cbf1ea3-e21f-46fa-956c-169ff5e5dbb8 2025-10-27 04:08:09,437 - INFO - Deleting VM ctest-vn2-vm1-78354890 2025-10-27 04:08:09,534 - INFO - Deleting VM ctest-vn1-vm1-78497451 2025-10-27 04:08:09,615 - INFO - Deleting VN ctest-vn2-51592753 2025-10-27 04:08:09,653 - DEBUG - VN a5c9da37-5ce1-47c4-af0f-2f4ede04bc71 still in use: Unable to complete operation on network a5c9da37-5ce1-47c4-af0f-2f4ede04bc71. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-0d809705-0738-4a3f-994d-c05dc36bcd6a'] 2025-10-27 04:08:09,654 - WARNING - Deleting VN ctest-vn2-51592753 failed..Will retry 2025-10-27 04:08:11,788 - DEBUG - Response for deleting network () 2025-10-27 04:08:11,789 - INFO - Deleting VN ctest-vn1-32066241 2025-10-27 04:08:11,901 - DEBUG - Response for deleting network () 2025-10-27 04:08:12,155 - DEBUG - No XMPP flaps were noticed during the test
2025-10-27 04:08:12,155 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-10-27 04:08:12,155 - INFO - -------------------------------------------------------------------------------- 2025-10-27 04:08:12,950 - INFO - Deleted project: ctest-TestRouters-71351539, ID : 23cb1e01-3dca-4ff1-8f40-8e2a5189e18c