2026-10-05 02:32:20,512 - INFO - Domain Default found not creating 2026-10-05 02:32:20,690 - INFO - Project ctest-TestRouters-98665619 not found, creating it 2026-10-05 02:32:21,221 - INFO - Created Project:ctest-TestRouters-98665619, ID : 54c5b736-9735-4a7c-9d1f-e5d88d05980d 2026-10-05 02:32:22,994 - INFO - ================================================================================ 2026-10-05 02:32:22,994 - INFO - STARTING TEST : test_basic_router_behavior 2026-10-05 02:32:22,994 - 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-05 02:32:23,255 - DEBUG - Nothing to compare xmpp stats {'10.0.0.189': {'10.20.0.17': '0'}} with 2026-10-05 02:32:23,255 - INFO - Initial checks done. Running the testcase now 2026-10-05 02:32:23,255 - INFO - 2026-10-05 02:32:23,927 - DEBUG - Response for create_network : {'network': {'id': '89fb68eb-af65-4303-acdb-d4d6fdf8de09', 'name': 'ctest-vn1-26366181', 'tenant_id': '54c5b73697354a7c9d1fe5d88d05980d', 'project_id': '54c5b73697354a7c9d1fe5d88d05980d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-98665619', 'ctest-vn1-26366181'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}} 2026-10-05 02:32:24,167 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f589f82f-2186-45fa-be1f-4467c7a2b135', 'name': '', 'tenant_id': '54c5b73697354a7c9d1fe5d88d05980d', 'network_id': '89fb68eb-af65-4303-acdb-d4d6fdf8de09', 'ip_version': 4, 'cidr': '32.42.235.64/26', 'allocation_pools': [{'start': '32.42.235.66', 'end': '32.42.235.126'}], 'gateway_ip': '32.42.235.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2026-10-05T02:32:24.099218', 'updated_at': '2026-10-05T02:32:24.099218', 'dns_server_address': '32.42.235.66', 'tags': [], 'project_id': '54c5b73697354a7c9d1fe5d88d05980d'}} 2026-10-05 02:32:24,187 - INFO - Created VN ctest-vn1-26366181 2026-10-05 02:32:24,249 - DEBUG - VN ctest-vn1-26366181 UUID is 89fb68eb-af65-4303-acdb-d4d6fdf8de09 2026-10-05 02:32:24,583 - DEBUG - Response for create_network : {'network': {'id': '3ddb0de7-4718-4999-86a0-b48ea776b70d', 'name': 'ctest-vn2-98111103', 'tenant_id': '54c5b73697354a7c9d1fe5d88d05980d', 'project_id': '54c5b73697354a7c9d1fe5d88d05980d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-98665619', 'ctest-vn2-98111103'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}} 2026-10-05 02:32:24,787 - DEBUG - Response for create_subnet : {'subnet': {'id': 'eaf90ad6-05a1-49dc-850d-6fdc53578888', 'name': '', 'tenant_id': '54c5b73697354a7c9d1fe5d88d05980d', 'network_id': '3ddb0de7-4718-4999-86a0-b48ea776b70d', 'ip_version': 4, 'cidr': '191.241.190.0/26', 'allocation_pools': [{'start': '191.241.190.2', 'end': '191.241.190.62'}], 'gateway_ip': '191.241.190.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2026-10-05T02:32:24.719447', 'updated_at': '2026-10-05T02:32:24.719447', 'dns_server_address': '191.241.190.2', 'tags': [], 'project_id': '54c5b73697354a7c9d1fe5d88d05980d'}} 2026-10-05 02:32:24,807 - INFO - Created VN ctest-vn2-98111103 2026-10-05 02:32:24,861 - DEBUG - VN ctest-vn2-98111103 UUID is 3ddb0de7-4718-4999-86a0-b48ea776b70d 2026-10-05 02:32:25,169 - DEBUG - Services list from nova: [, , ] 2026-10-05 02:32:25,581 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6344-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6344-1) 2026-10-05 02:32:26,077 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6344-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6344-1) 2026-10-05 02:32:26,172 - INFO - Adding interface with subnet_id f589f82f-2186-45fa-be1f-4467c7a2b135, port_id None to router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:32:26,515 - INFO - Waiting for VM ctest-vn1-vm1-67111436 to be up.. 2026-10-05 02:32:26,583 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:31,641 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:36,731 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:41,819 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:46,925 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:52,015 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:32:57,102 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:33:02,191 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 02:33:07,281 - DEBUG - VM is in ACTIVE state now 2026-10-05 02:33:07,281 - INFO - VM name : ctest-vn1-vm1-67111436 2026-10-05 02:33:07,374 - DEBUG - VM ctest-vn1-vm1-67111436 ID is 50e54fa7-fc05-4c81-9be7-8e7ffbfae213 2026-10-05 02:33:07,397 - DEBUG - VM ctest-vn1-vm1-67111436 launched on Node cn-jenkins-deploy-platform-ansible-os-6344-1 2026-10-05 02:33:07,487 - DEBUG - Requesting: http://10.0.0.189:8082/virtual-machine/50e54fa7-fc05-4c81-9be7-8e7ffbfae213 2026-10-05 02:33:07,862 - DEBUG - Requesting: http://10.0.0.189:8082/virtual-machine/50e54fa7-fc05-4c81-9be7-8e7ffbfae213 2026-10-05 02:33:07,895 - DEBUG - Requesting: http://10.0.0.189:8082/virtual-machine-interface/ab762817-55e0-4a88-8e6a-870bf032bbb3 2026-10-05 02:33:11,164 - 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 1021ms') 2026-10-05 02:33:11,164 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-67111436 failed! 2026-10-05 02:33:11,225 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-98665619:ctest-vn1-26366181 is 32.42.235.65 and allocation pool is NOT set 2026-10-05 02:33:13,288 - 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.44 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.536 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.536/1.990/3.444/1.454 ms') 2026-10-05 02:33:13,289 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-67111436 passed 2026-10-05 02:33:13,445 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:13,445 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-67111436, IP 32.42.235.67, Port 22 2026-10-05 02:33:13,623 - DEBUG - VM ctest-vn1-vm1-67111436 is ready for SSH connections 2026-10-05 02:33:13,623 - INFO - Waiting for VM ctest-vn2-vm1-72076758 to be up.. 2026-10-05 02:33:13,722 - DEBUG - VM is in ACTIVE state now 2026-10-05 02:33:13,723 - INFO - VM name : ctest-vn2-vm1-72076758 2026-10-05 02:33:13,809 - DEBUG - VM ctest-vn2-vm1-72076758 ID is 45137436-eff3-4384-856e-87fd729fb108 2026-10-05 02:33:13,809 - DEBUG - VM ctest-vn2-vm1-72076758 launched on Node cn-jenkins-deploy-platform-ansible-os-6344-1 2026-10-05 02:33:13,902 - DEBUG - Requesting: http://10.0.0.189:8082/virtual-machine/45137436-eff3-4384-856e-87fd729fb108 2026-10-05 02:33:13,912 - DEBUG - Requesting: http://10.0.0.189:8082/virtual-machine-interface/2e5a2fae-edfd-4b55-a7e9-01047c82f6fa 2026-10-05 02:33:15,162 - 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.48 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.398 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.398/3.438/6.478/3.040 ms') 2026-10-05 02:33:15,162 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-72076758 passed 2026-10-05 02:33:15,317 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:15,317 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-72076758, IP 191.241.190.3, Port 22 2026-10-05 02:33:15,483 - DEBUG - VM ctest-vn2-vm1-72076758 is ready for SSH connections 2026-10-05 02:33:15,483 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:15,483 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 191.241.190.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.189, gateway password: c0ntrail123 2026-10-05 02:33:15,484 - DEBUG - ping -s 56 -c 3 -W 1 191.241.190.3 2026-10-05 02:33:20,507 - DEBUG - PING 191.241.190.3 (191.241.190.3): 56 data bytes --- 191.241.190.3 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-05 02:33:20,507 - WARNING - Ping to IP 191.241.190.3 from VM ctest-vn1-vm1-67111436 failed 2026-10-05 02:33:20,507 - INFO - Adding interface with subnet_id eaf90ad6-05a1-49dc-850d-6fdc53578888, port_id None to router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:33:20,809 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:20,809 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 191.241.190.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.189, gateway password: c0ntrail123 2026-10-05 02:33:20,809 - DEBUG - ping -s 56 -c 3 -W 1 191.241.190.3 2026-10-05 02:33:23,937 - DEBUG - PING 191.241.190.3 (191.241.190.3): 56 data bytes 64 bytes from 191.241.190.3: seq=1 ttl=63 time=3.266 ms 64 bytes from 191.241.190.3: seq=2 ttl=63 time=1.139 ms --- 191.241.190.3 ping statistics --- 3 packets transmitted, 2 packets received, 33% packet loss round-trip min/avg/max = 1.139/2.202/3.266 ms 2026-10-05 02:33:23,937 - WARNING - Ping to IP 191.241.190.3 from VM ctest-vn1-vm1-67111436 failed 2026-10-05 02:33:24,938 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 191.241.190.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.189, gateway password: c0ntrail123 2026-10-05 02:33:24,938 - DEBUG - ping -s 56 -c 3 -W 1 191.241.190.3 2026-10-05 02:33:27,063 - DEBUG - PING 191.241.190.3 (191.241.190.3): 56 data bytes 64 bytes from 191.241.190.3: seq=0 ttl=63 time=1.405 ms 64 bytes from 191.241.190.3: seq=1 ttl=63 time=0.944 ms 64 bytes from 191.241.190.3: seq=2 ttl=63 time=0.994 ms --- 191.241.190.3 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.944/1.114/1.405 ms 2026-10-05 02:33:27,063 - INFO - Ping to IP 191.241.190.3 from VM ctest-vn1-vm1-67111436 passed 2026-10-05 02:33:27,064 - INFO - Deleting interface with subnet_id f589f82f-2186-45fa-be1f-4467c7a2b135, port_id None from router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:33:27,225 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:27,225 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 191.241.190.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.189, gateway password: c0ntrail123 2026-10-05 02:33:27,225 - DEBUG - ping -s 56 -c 3 -W 1 191.241.190.3 2026-10-05 02:33:30,355 - DEBUG - PING 191.241.190.3 (191.241.190.3): 56 data bytes --- 191.241.190.3 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2026-10-05 02:33:30,355 - WARNING - Ping to IP 191.241.190.3 from VM ctest-vn1-vm1-67111436 failed 2026-10-05 02:33:30,355 - INFO - Adding interface with subnet_id f589f82f-2186-45fa-be1f-4467c7a2b135, port_id None to router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:33:30,640 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 02:33:30,640 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 191.241.190.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.189, gateway password: c0ntrail123 2026-10-05 02:33:30,640 - DEBUG - ping -s 56 -c 3 -W 1 191.241.190.3 2026-10-05 02:33:32,767 - DEBUG - PING 191.241.190.3 (191.241.190.3): 56 data bytes 64 bytes from 191.241.190.3: seq=0 ttl=63 time=1.473 ms 64 bytes from 191.241.190.3: seq=1 ttl=63 time=0.939 ms 64 bytes from 191.241.190.3: seq=2 ttl=63 time=1.014 ms --- 191.241.190.3 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.939/1.142/1.473 ms 2026-10-05 02:33:32,767 - INFO - Ping to IP 191.241.190.3 from VM ctest-vn1-vm1-67111436 passed 2026-10-05 02:33:32,767 - INFO - Deleting interface with subnet_id eaf90ad6-05a1-49dc-850d-6fdc53578888, port_id None from router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:33:32,933 - INFO - Deleting interface with subnet_id f589f82f-2186-45fa-be1f-4467c7a2b135, port_id None from router c7664078-1663-42d9-b156-ea7cb757343d 2026-10-05 02:33:33,188 - INFO - Deleting VM ctest-vn2-vm1-72076758 2026-10-05 02:33:33,287 - INFO - Deleting VM ctest-vn1-vm1-67111436 2026-10-05 02:33:33,375 - INFO - Deleting VN ctest-vn2-98111103 2026-10-05 02:33:33,414 - DEBUG - VN 3ddb0de7-4718-4999-86a0-b48ea776b70d still in use: Unable to complete operation on network 3ddb0de7-4718-4999-86a0-b48ea776b70d. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-0aca9f2f-f0e1-438c-98a2-44d3ec4f189e'] 2026-10-05 02:33:33,414 - WARNING - Deleting VN ctest-vn2-98111103 failed..Will retry 2026-10-05 02:33:35,606 - DEBUG - Response for deleting network () 2026-10-05 02:33:35,606 - INFO - Deleting VN ctest-vn1-26366181 2026-10-05 02:33:35,774 - DEBUG - Response for deleting network () 2026-10-05 02:33:36,045 - DEBUG - No XMPP flaps were noticed during the test
2026-10-05 02:33:36,046 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:14]
2026-10-05 02:33:36,046 - INFO - -------------------------------------------------------------------------------- 2026-10-05 02:33:36,861 - INFO - Deleted project: ctest-TestRouters-98665619, ID : 54c5b736-9735-4a7c-9d1f-e5d88d05980d