2025-08-30 22:20:09,161 - INFO - Domain Default found not creating 2025-08-30 22:20:09,358 - INFO - Project ctest-TestRouters-39018602 not found, creating it 2025-08-30 22:20:09,931 - INFO - Created Project:ctest-TestRouters-39018602, ID : 1153a05f-aa74-4561-80bb-493192c0d512 2025-08-30 22:20:11,604 - INFO - ================================================================================ 2025-08-30 22:20:11,604 - INFO - STARTING TEST : test_basic_router_behavior 2025-08-30 22:20:11,604 - 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-08-30 22:20:11,917 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.14': '0'}} with 2025-08-30 22:20:11,917 - INFO - Initial checks done. Running the testcase now 2025-08-30 22:20:11,918 - INFO - 2025-08-30 22:20:12,657 - DEBUG - Response for create_network : {'network': {'id': '64cdfda8-8ead-49e1-8d1e-96285f3f5633', 'name': 'ctest-vn1-27184078', 'tenant_id': '1153a05faa74456180bb493192c0d512', 'project_id': '1153a05faa74456180bb493192c0d512', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-39018602', 'ctest-vn1-27184078'], 'port_security_enabled': True, 'description': ''}} 2025-08-30 22:20:12,844 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f374485c-c2d5-4fc4-85e7-0c5afa5a45ab', 'name': '', 'tenant_id': '1153a05faa74456180bb493192c0d512', 'network_id': '64cdfda8-8ead-49e1-8d1e-96285f3f5633', 'ip_version': 4, 'cidr': '73.206.61.128/26', 'allocation_pools': [{'start': '73.206.61.130', 'end': '73.206.61.190'}], 'gateway_ip': '73.206.61.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '73.206.61.130', 'tags': [], 'project_id': '1153a05faa74456180bb493192c0d512'}} 2025-08-30 22:20:12,861 - INFO - Created VN ctest-vn1-27184078 2025-08-30 22:20:12,913 - DEBUG - VN ctest-vn1-27184078 UUID is 64cdfda8-8ead-49e1-8d1e-96285f3f5633 2025-08-30 22:20:13,460 - DEBUG - Response for create_network : {'network': {'id': 'b96dd463-3e02-4479-81f1-320f75e08ba8', 'name': 'ctest-vn2-13558516', 'tenant_id': '1153a05faa74456180bb493192c0d512', 'project_id': '1153a05faa74456180bb493192c0d512', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-39018602', 'ctest-vn2-13558516'], 'port_security_enabled': True, 'description': ''}} 2025-08-30 22:20:13,714 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd84e0367-785b-4719-964f-e2fbdc1385ad', 'name': '', 'tenant_id': '1153a05faa74456180bb493192c0d512', 'network_id': 'b96dd463-3e02-4479-81f1-320f75e08ba8', 'ip_version': 4, 'cidr': '55.160.231.128/26', 'allocation_pools': [{'start': '55.160.231.130', 'end': '55.160.231.190'}], 'gateway_ip': '55.160.231.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '55.160.231.130', 'tags': [], 'project_id': '1153a05faa74456180bb493192c0d512'}} 2025-08-30 22:20:13,743 - INFO - Created VN ctest-vn2-13558516 2025-08-30 22:20:13,797 - DEBUG - VN ctest-vn2-13558516 UUID is b96dd463-3e02-4479-81f1-320f75e08ba8 2025-08-30 22:20:14,108 - DEBUG - Services list from nova: [, , ] 2025-08-30 22:20:15,691 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3984-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3984-1) 2025-08-30 22:20:17,212 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3984-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3984-1) 2025-08-30 22:20:17,411 - INFO - Adding interface with subnet_id f374485c-c2d5-4fc4-85e7-0c5afa5a45ab, port_id None to router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:17,688 - INFO - Waiting for VM ctest-vn1-vm1-18839620 to be up.. 2025-08-30 22:20:17,787 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-30 22:20:22,971 - DEBUG - VM is in ACTIVE state now 2025-08-30 22:20:22,971 - INFO - VM name : ctest-vn1-vm1-18839620 2025-08-30 22:20:23,119 - DEBUG - VM ctest-vn1-vm1-18839620 ID is aef7e08b-4258-48f5-b321-08ac42d6be39 2025-08-30 22:20:23,149 - DEBUG - VM ctest-vn1-vm1-18839620 launched on Node cn-jenkins-deploy-platform-ansible-os-3984-1 2025-08-30 22:20:23,296 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/aef7e08b-4258-48f5-b321-08ac42d6be39 2025-08-30 22:20:23,651 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/aef7e08b-4258-48f5-b321-08ac42d6be39 2025-08-30 22:20:23,810 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/b13f32fc-52a9-4173-a8a4-f14a2ca19e3d 2025-08-30 22:20:27,130 - 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 1028ms') 2025-08-30 22:20:27,130 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-18839620 failed! 2025-08-30 22:20:27,201 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-39018602:ctest-vn1-27184078 is 73.206.61.129 and allocation pool is NOT set 2025-08-30 22:20:29,264 - 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.50 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.533 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.533/2.517/4.501/1.984 ms') 2025-08-30 22:20:29,265 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-18839620 passed 2025-08-30 22:20:29,441 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:29,442 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-18839620, IP 73.206.61.131, Port 22 2025-08-30 22:20:29,636 - DEBUG - VM ctest-vn1-vm1-18839620 is ready for SSH connections 2025-08-30 22:20:29,637 - INFO - Waiting for VM ctest-vn2-vm1-11217562 to be up.. 2025-08-30 22:20:29,770 - DEBUG - VM is in ACTIVE state now 2025-08-30 22:20:29,770 - INFO - VM name : ctest-vn2-vm1-11217562 2025-08-30 22:20:29,875 - DEBUG - VM ctest-vn2-vm1-11217562 ID is 2699025b-8f6d-428b-a8b1-38950603023c 2025-08-30 22:20:29,875 - DEBUG - VM ctest-vn2-vm1-11217562 launched on Node cn-jenkins-deploy-platform-ansible-os-3984-1 2025-08-30 22:20:29,985 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/2699025b-8f6d-428b-a8b1-38950603023c 2025-08-30 22:20:29,998 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/3b6762fd-bf1b-4d02-9670-d4c02c3d7d26 2025-08-30 22:20:31,278 - 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=6.57 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.20 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.198/4.385/6.572/2.187 ms') 2025-08-30 22:20:31,278 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-11217562 passed 2025-08-30 22:20:31,449 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:31,449 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-11217562, IP 55.160.231.131, Port 22 2025-08-30 22:20:31,525 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-30 22:20:31,661 - DEBUG - VM ctest-vn2-vm1-11217562 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-30 22:20:36,662 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:36,662 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-11217562, IP 55.160.231.131, Port 22 2025-08-30 22:20:36,881 - DEBUG - VM ctest-vn2-vm1-11217562 is ready for SSH connections 2025-08-30 22:20:36,881 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:36,882 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 55.160.231.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123 2025-08-30 22:20:36,882 - DEBUG - ping -s 56 -c 3 -W 1 55.160.231.131 2025-08-30 22:20:42,290 - DEBUG - PING 55.160.231.131 (55.160.231.131): 56 data bytes --- 55.160.231.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-08-30 22:20:42,291 - WARNING - Ping to IP 55.160.231.131 from VM ctest-vn1-vm1-18839620 failed 2025-08-30 22:20:42,291 - INFO - Adding interface with subnet_id d84e0367-785b-4719-964f-e2fbdc1385ad, port_id None to router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:42,745 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:42,745 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 55.160.231.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123 2025-08-30 22:20:42,745 - DEBUG - ping -s 56 -c 3 -W 1 55.160.231.131 2025-08-30 22:20:44,989 - DEBUG - PING 55.160.231.131 (55.160.231.131): 56 data bytes 64 bytes from 55.160.231.131: seq=0 ttl=63 time=7.470 ms 64 bytes from 55.160.231.131: seq=1 ttl=63 time=1.656 ms 64 bytes from 55.160.231.131: seq=2 ttl=63 time=1.144 ms --- 55.160.231.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.144/3.423/7.470 ms 2025-08-30 22:20:44,989 - INFO - Ping to IP 55.160.231.131 from VM ctest-vn1-vm1-18839620 passed 2025-08-30 22:20:44,990 - INFO - Deleting interface with subnet_id f374485c-c2d5-4fc4-85e7-0c5afa5a45ab, port_id None from router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:45,153 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:45,153 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 55.160.231.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123 2025-08-30 22:20:45,153 - DEBUG - ping -s 56 -c 3 -W 1 55.160.231.131 2025-08-30 22:20:48,379 - DEBUG - PING 55.160.231.131 (55.160.231.131): 56 data bytes --- 55.160.231.131 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-08-30 22:20:48,380 - WARNING - Ping to IP 55.160.231.131 from VM ctest-vn1-vm1-18839620 failed 2025-08-30 22:20:48,380 - INFO - Adding interface with subnet_id f374485c-c2d5-4fc4-85e7-0c5afa5a45ab, port_id None to router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:48,806 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-30 22:20:48,806 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 55.160.231.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123 2025-08-30 22:20:48,806 - DEBUG - ping -s 56 -c 3 -W 1 55.160.231.131 2025-08-30 22:20:51,055 - DEBUG - PING 55.160.231.131 (55.160.231.131): 56 data bytes 64 bytes from 55.160.231.131: seq=0 ttl=63 time=2.244 ms 64 bytes from 55.160.231.131: seq=1 ttl=63 time=2.195 ms 64 bytes from 55.160.231.131: seq=2 ttl=63 time=1.753 ms --- 55.160.231.131 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.753/2.064/2.244 ms 2025-08-30 22:20:51,056 - INFO - Ping to IP 55.160.231.131 from VM ctest-vn1-vm1-18839620 passed 2025-08-30 22:20:51,056 - INFO - Deleting interface with subnet_id d84e0367-785b-4719-964f-e2fbdc1385ad, port_id None from router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:51,320 - INFO - Deleting interface with subnet_id f374485c-c2d5-4fc4-85e7-0c5afa5a45ab, port_id None from router bee47b4b-844e-473c-abbf-6c265e58f17e 2025-08-30 22:20:51,501 - INFO - Deleting VM ctest-vn2-vm1-11217562 2025-08-30 22:20:51,567 - INFO - Deleting VM ctest-vn1-vm1-18839620 2025-08-30 22:20:51,635 - INFO - Deleting VN ctest-vn2-13558516 2025-08-30 22:20:51,678 - DEBUG - VN b96dd463-3e02-4479-81f1-320f75e08ba8 still in use: Unable to complete operation on network b96dd463-3e02-4479-81f1-320f75e08ba8. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-7a2de4b8-f5fa-43c5-887a-4e256ef50a40'] 2025-08-30 22:20:51,678 - WARNING - Deleting VN ctest-vn2-13558516 failed..Will retry 2025-08-30 22:20:53,860 - DEBUG - Response for deleting network () 2025-08-30 22:20:53,860 - INFO - Deleting VN ctest-vn1-27184078 2025-08-30 22:20:53,997 - DEBUG - Response for deleting network () 2025-08-30 22:20:54,306 - DEBUG - No XMPP flaps were noticed during the test
2025-08-30 22:20:54,306 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:43]
2025-08-30 22:20:54,306 - INFO - -------------------------------------------------------------------------------- 2025-08-30 22:20:55,171 - INFO - Deleted project: ctest-TestRouters-39018602, ID : 1153a05f-aa74-4561-80bb-493192c0d512