2026-10-29 18:47:59,610 - INFO - Domain Default found not creating 2026-10-29 18:47:59,769 - INFO - Project ctest-TestRouters-61076959 not found, creating it 2026-10-29 18:48:00,217 - INFO - Created Project:ctest-TestRouters-61076959, ID : ffd0d849-5b85-4616-8eef-57287a37ab28 2026-10-29 18:48:01,834 - INFO - ================================================================================ 2026-10-29 18:48:01,834 - INFO - STARTING TEST : test_basic_router_behavior 2026-10-29 18:48:01,834 - 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 2026-10-29 18:48:02,096 - DEBUG - Nothing to compare xmpp stats {'10.0.0.248': {'10.20.0.25': '0'}} with 2026-10-29 18:48:02,096 - INFO - Initial checks done. Running the testcase now 2026-10-29 18:48:02,096 - INFO - 2026-10-29 18:48:02,696 - DEBUG - Response for create_network : {'network': {'id': '226619c6-a8f3-4e4e-8893-68bc4a48e756', 'name': 'ctest-vn1-94886955', 'tenant_id': 'ffd0d8495b8546168eef57287a37ab28', 'project_id': 'ffd0d8495b8546168eef57287a37ab28', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-61076959', 'ctest-vn1-94886955'], 'port_security_enabled': True, 'description': ''}} 2026-10-29 18:48:02,869 - DEBUG - Response for create_subnet : {'subnet': {'id': 'ced90b8c-495f-47d4-b777-95eb6b7f21a6', 'name': '', 'tenant_id': 'ffd0d8495b8546168eef57287a37ab28', 'network_id': '226619c6-a8f3-4e4e-8893-68bc4a48e756', 'ip_version': 4, 'cidr': '158.221.171.192/26', 'allocation_pools': [{'start': '158.221.171.194', 'end': '158.221.171.254'}], 'gateway_ip': '158.221.171.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '158.221.171.194', 'tags': [], 'project_id': 'ffd0d8495b8546168eef57287a37ab28'}} 2026-10-29 18:48:02,884 - INFO - Created VN ctest-vn1-94886955 2026-10-29 18:48:02,935 - DEBUG - VN ctest-vn1-94886955 UUID is 226619c6-a8f3-4e4e-8893-68bc4a48e756 2026-10-29 18:48:03,227 - DEBUG - Response for create_network : {'network': {'id': 'b44095fd-f2f2-40b4-b543-4311ec6dd04a', 'name': 'ctest-vn2-43108525', 'tenant_id': 'ffd0d8495b8546168eef57287a37ab28', 'project_id': 'ffd0d8495b8546168eef57287a37ab28', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-61076959', 'ctest-vn2-43108525'], 'port_security_enabled': True, 'description': ''}} 2026-10-29 18:48:03,414 - DEBUG - Response for create_subnet : {'subnet': {'id': 'aac1a537-0e15-4de7-946e-36fb54efbd19', 'name': '', 'tenant_id': 'ffd0d8495b8546168eef57287a37ab28', 'network_id': 'b44095fd-f2f2-40b4-b543-4311ec6dd04a', 'ip_version': 4, 'cidr': '180.167.58.64/26', 'allocation_pools': [{'start': '180.167.58.66', 'end': '180.167.58.126'}], 'gateway_ip': '180.167.58.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '180.167.58.66', 'tags': [], 'project_id': 'ffd0d8495b8546168eef57287a37ab28'}} 2026-10-29 18:48:03,426 - INFO - Created VN ctest-vn2-43108525 2026-10-29 18:48:03,474 - DEBUG - VN ctest-vn2-43108525 UUID is b44095fd-f2f2-40b4-b543-4311ec6dd04a 2026-10-29 18:48:03,724 - DEBUG - Services list from nova: [, , ] 2026-10-29 18:48:04,149 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6440-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6440-1) 2026-10-29 18:48:04,557 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6440-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6440-1) 2026-10-29 18:48:04,622 - INFO - Adding interface with subnet_id ced90b8c-495f-47d4-b777-95eb6b7f21a6, port_id None to router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:48:04,821 - INFO - Waiting for VM ctest-vn1-vm1-69931336 to be up.. 2026-10-29 18:48:04,869 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:09,916 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:14,983 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:20,049 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:25,117 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:30,178 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:35,249 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:40,321 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-29 18:48:45,388 - DEBUG - VM is in ACTIVE state now 2026-10-29 18:48:45,388 - INFO - VM name : ctest-vn1-vm1-69931336 2026-10-29 18:48:45,454 - DEBUG - VM ctest-vn1-vm1-69931336 ID is 912e3214-be08-4b7f-ba73-938dfcbacaee 2026-10-29 18:48:45,472 - DEBUG - VM ctest-vn1-vm1-69931336 launched on Node cn-jenkins-deploy-platform-ansible-os-6440-1 2026-10-29 18:48:45,545 - DEBUG - Requesting: http://10.0.0.248:8082/virtual-machine/912e3214-be08-4b7f-ba73-938dfcbacaee 2026-10-29 18:48:45,914 - DEBUG - Requesting: http://10.0.0.248:8082/virtual-machine/912e3214-be08-4b7f-ba73-938dfcbacaee 2026-10-29 18:48:45,940 - DEBUG - Requesting: http://10.0.0.248:8082/virtual-machine-interface/1b50bd4d-436a-495c-a4a3-b087fb82718f 2026-10-29 18:48:49,189 - 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 1014ms') 2026-10-29 18:48:49,189 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-69931336 failed! 2026-10-29 18:48:49,243 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-61076959:ctest-vn1-94886955 is 158.221.171.193 and allocation pool is NOT set 2026-10-29 18:48:51,304 - 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.66 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.971 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.971/2.814/4.657/1.843 ms') 2026-10-29 18:48:51,304 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-69931336 passed 2026-10-29 18:48:51,463 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:48:51,463 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-69931336, IP 158.221.171.195, Port 22 2026-10-29 18:48:51,617 - DEBUG - VM ctest-vn1-vm1-69931336 is ready for SSH connections 2026-10-29 18:48:51,617 - INFO - Waiting for VM ctest-vn2-vm1-22336488 to be up.. 2026-10-29 18:48:51,683 - DEBUG - VM is in ACTIVE state now 2026-10-29 18:48:51,683 - INFO - VM name : ctest-vn2-vm1-22336488 2026-10-29 18:48:51,747 - DEBUG - VM ctest-vn2-vm1-22336488 ID is 2d8344d1-f95f-4598-b248-b33570727492 2026-10-29 18:48:51,747 - DEBUG - VM ctest-vn2-vm1-22336488 launched on Node cn-jenkins-deploy-platform-ansible-os-6440-1 2026-10-29 18:48:51,809 - DEBUG - Requesting: http://10.0.0.248:8082/virtual-machine/2d8344d1-f95f-4598-b248-b33570727492 2026-10-29 18:48:51,815 - DEBUG - Requesting: http://10.0.0.248:8082/virtual-machine-interface/d2c7d85b-f5c5-42d4-930b-83b8666b35ba 2026-10-29 18:48:53,053 - 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.54 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.841 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.841/2.688/4.536/1.847 ms') 2026-10-29 18:48:53,053 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-22336488 passed 2026-10-29 18:48:53,198 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:48:53,199 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-22336488, IP 180.167.58.67, Port 22 2026-10-29 18:48:53,368 - DEBUG - VM ctest-vn2-vm1-22336488 is ready for SSH connections 2026-10-29 18:48:53,368 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:48:53,368 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 180.167.58.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.248, gateway password: c0ntrail123 2026-10-29 18:48:53,368 - DEBUG - ping -s 56 -c 3 -W 1 180.167.58.67 2026-10-29 18:48:58,028 - DEBUG - PING 180.167.58.67 (180.167.58.67): 56 data bytes --- 180.167.58.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-29 18:48:58,028 - WARNING - Ping to IP 180.167.58.67 from VM ctest-vn1-vm1-69931336 failed 2026-10-29 18:48:58,028 - INFO - Adding interface with subnet_id aac1a537-0e15-4de7-946e-36fb54efbd19, port_id None to router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:48:58,355 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:48:58,355 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 180.167.58.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.248, gateway password: c0ntrail123 2026-10-29 18:48:58,356 - DEBUG - ping -s 56 -c 3 -W 1 180.167.58.67 2026-10-29 18:49:00,486 - DEBUG - PING 180.167.58.67 (180.167.58.67): 56 data bytes 64 bytes from 180.167.58.67: seq=0 ttl=63 time=3.084 ms 64 bytes from 180.167.58.67: seq=1 ttl=63 time=1.172 ms 64 bytes from 180.167.58.67: seq=2 ttl=63 time=0.771 ms --- 180.167.58.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.771/1.675/3.084 ms 2026-10-29 18:49:00,486 - INFO - Ping to IP 180.167.58.67 from VM ctest-vn1-vm1-69931336 passed 2026-10-29 18:49:00,486 - INFO - Deleting interface with subnet_id ced90b8c-495f-47d4-b777-95eb6b7f21a6, port_id None from router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:49:00,610 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:00,611 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 180.167.58.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.248, gateway password: c0ntrail123 2026-10-29 18:49:00,611 - DEBUG - ping -s 56 -c 3 -W 1 180.167.58.67 2026-10-29 18:49:03,727 - DEBUG - PING 180.167.58.67 (180.167.58.67): 56 data bytes --- 180.167.58.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-29 18:49:03,727 - WARNING - Ping to IP 180.167.58.67 from VM ctest-vn1-vm1-69931336 failed 2026-10-29 18:49:03,727 - INFO - Adding interface with subnet_id ced90b8c-495f-47d4-b777-95eb6b7f21a6, port_id None to router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:49:03,925 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-29 18:49:03,925 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 180.167.58.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.248, gateway password: c0ntrail123 2026-10-29 18:49:03,925 - DEBUG - ping -s 56 -c 3 -W 1 180.167.58.67 2026-10-29 18:49:06,041 - DEBUG - PING 180.167.58.67 (180.167.58.67): 56 data bytes 64 bytes from 180.167.58.67: seq=0 ttl=63 time=1.173 ms 64 bytes from 180.167.58.67: seq=1 ttl=63 time=0.761 ms 64 bytes from 180.167.58.67: seq=2 ttl=63 time=0.718 ms --- 180.167.58.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.718/0.884/1.173 ms 2026-10-29 18:49:06,041 - INFO - Ping to IP 180.167.58.67 from VM ctest-vn1-vm1-69931336 passed 2026-10-29 18:49:06,041 - INFO - Deleting interface with subnet_id aac1a537-0e15-4de7-946e-36fb54efbd19, port_id None from router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:49:06,142 - INFO - Deleting interface with subnet_id ced90b8c-495f-47d4-b777-95eb6b7f21a6, port_id None from router 54bafdc2-ee8d-4701-84d8-48a7c5214f72 2026-10-29 18:49:06,297 - INFO - Deleting VM ctest-vn2-vm1-22336488 2026-10-29 18:49:06,369 - INFO - Deleting VM ctest-vn1-vm1-69931336 2026-10-29 18:49:06,427 - INFO - Deleting VN ctest-vn2-43108525 2026-10-29 18:49:06,457 - DEBUG - VN b44095fd-f2f2-40b4-b543-4311ec6dd04a still in use: Unable to complete operation on network b44095fd-f2f2-40b4-b543-4311ec6dd04a. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-76a4a199-8cc8-46d1-bedb-e06eee5479fc'] 2026-10-29 18:49:06,458 - WARNING - Deleting VN ctest-vn2-43108525 failed..Will retry 2026-10-29 18:49:08,487 - DEBUG - VN b44095fd-f2f2-40b4-b543-4311ec6dd04a still in use: Unable to complete operation on network b44095fd-f2f2-40b4-b543-4311ec6dd04a. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-7b379058-a5c8-49bd-9f36-cc421e4c6989'] 2026-10-29 18:49:08,487 - WARNING - Deleting VN ctest-vn2-43108525 failed..Will retry 2026-10-29 18:49:10,575 - DEBUG - Response for deleting network () 2026-10-29 18:49:10,575 - INFO - Deleting VN ctest-vn1-94886955 2026-10-29 18:49:10,666 - DEBUG - Response for deleting network () 2026-10-29 18:49:10,936 - DEBUG - No XMPP flaps were noticed during the test
2026-10-29 18:49:10,936 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:09]
2026-10-29 18:49:10,936 - INFO - -------------------------------------------------------------------------------- 2026-10-29 18:49:11,669 - INFO - Deleted project: ctest-TestRouters-61076959, ID : ffd0d849-5b85-4616-8eef-57287a37ab28