2025-09-11 12:04:01,585 - INFO - Domain Default found not creating
2025-09-11 12:04:01,743 - INFO - Project ctest-TestRouters-91171144 not found, creating it
2025-09-11 12:04:02,209 - INFO - Created Project:ctest-TestRouters-91171144, ID : 98035dda-4a0e-4d2a-9e08-e72cc8aca607
2025-09-11 12:04:03,748 - INFO - ================================================================================
2025-09-11 12:04:03,748 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-11 12:04:03,748 - 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-11 12:04:04,009 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.254': '0'}} with
2025-09-11 12:04:04,009 - INFO - Initial checks done. Running the testcase now
2025-09-11 12:04:04,009 - INFO -
2025-09-11 12:04:04,555 - DEBUG - Response for create_network : {'network': {'id': 'f574601b-9d95-45d1-96dc-d4f680af0f41', 'name': 'ctest-vn1-20783903', 'tenant_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'project_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-91171144', 'ctest-vn1-20783903'], 'port_security_enabled': True, 'description': ''}}
2025-09-11 12:04:04,756 - DEBUG - Response for create_subnet : {'subnet': {'id': '22e82a4d-3454-4a6c-845b-028acb044031', 'name': '', 'tenant_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'network_id': 'f574601b-9d95-45d1-96dc-d4f680af0f41', 'ip_version': 4, 'cidr': '212.22.134.128/26', 'allocation_pools': [{'start': '212.22.134.130', 'end': '212.22.134.190'}], 'gateway_ip': '212.22.134.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '212.22.134.130', 'tags': [], 'project_id': '98035dda4a0e4d2a9e08e72cc8aca607'}}
2025-09-11 12:04:04,775 - INFO - Created VN ctest-vn1-20783903
2025-09-11 12:04:04,828 - DEBUG - VN ctest-vn1-20783903 UUID is f574601b-9d95-45d1-96dc-d4f680af0f41
2025-09-11 12:04:05,131 - DEBUG - Response for create_network : {'network': {'id': '342de450-b45f-420d-b8cc-75822256e253', 'name': 'ctest-vn2-13219604', 'tenant_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'project_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-91171144', 'ctest-vn2-13219604'], 'port_security_enabled': True, 'description': ''}}
2025-09-11 12:04:05,346 - DEBUG - Response for create_subnet : {'subnet': {'id': 'd7fde979-bedb-46bd-aa44-c85e9a5cee6b', 'name': '', 'tenant_id': '98035dda4a0e4d2a9e08e72cc8aca607', 'network_id': '342de450-b45f-420d-b8cc-75822256e253', 'ip_version': 4, 'cidr': '165.28.114.192/26', 'allocation_pools': [{'start': '165.28.114.194', 'end': '165.28.114.254'}], 'gateway_ip': '165.28.114.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '165.28.114.194', 'tags': [], 'project_id': '98035dda4a0e4d2a9e08e72cc8aca607'}}
2025-09-11 12:04:05,366 - INFO - Created VN ctest-vn2-13219604
2025-09-11 12:04:05,423 - DEBUG - VN ctest-vn2-13219604 UUID is 342de450-b45f-420d-b8cc-75822256e253
2025-09-11 12:04:05,624 - DEBUG - Services list from nova: [, , ]
2025-09-11 12:04:06,641 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4091-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4091-1)
2025-09-11 12:04:07,899 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4091-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4091-1)
2025-09-11 12:04:07,972 - INFO - Adding interface with subnet_id 22e82a4d-3454-4a6c-845b-028acb044031, port_id None to router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:08,237 - INFO - Waiting for VM ctest-vn1-vm1-13339118 to be up..
2025-09-11 12:04:08,348 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-11 12:04:13,418 - DEBUG - VM is in ACTIVE state now
2025-09-11 12:04:13,418 - INFO - VM name : ctest-vn1-vm1-13339118
2025-09-11 12:04:13,485 - DEBUG - VM ctest-vn1-vm1-13339118 ID is f8634e7b-5fe0-4143-9135-381164f093be
2025-09-11 12:04:13,501 - DEBUG - VM ctest-vn1-vm1-13339118 launched on Node cn-jenkins-deploy-platform-ansible-os-4091-1
2025-09-11 12:04:13,567 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/f8634e7b-5fe0-4143-9135-381164f093be
2025-09-11 12:04:13,867 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/f8634e7b-5fe0-4143-9135-381164f093be
2025-09-11 12:04:13,896 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/5bce8a07-52c6-4d53-a7d5-f8b6c1df204a
2025-09-11 12:04:17,140 - 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 1012ms')
2025-09-11 12:04:17,140 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-13339118 failed!
2025-09-11 12:04:17,199 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-91171144:ctest-vn1-20783903 is 212.22.134.129 and allocation pool is NOT set
2025-09-11 12:04:19,258 - 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=2.78 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.366 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.366/1.571/2.777/1.205 ms')
2025-09-11 12:04:19,258 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-13339118 passed
2025-09-11 12:04:19,411 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:19,412 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-13339118, IP 212.22.134.131, Port 22
2025-09-11 12:04:19,567 - DEBUG - VM ctest-vn1-vm1-13339118 is ready for SSH connections
2025-09-11 12:04:19,567 - INFO - Waiting for VM ctest-vn2-vm1-54892193 to be up..
2025-09-11 12:04:19,638 - DEBUG - VM is in ACTIVE state now
2025-09-11 12:04:19,638 - INFO - VM name : ctest-vn2-vm1-54892193
2025-09-11 12:04:19,715 - DEBUG - VM ctest-vn2-vm1-54892193 ID is 7ab1f8ba-c4d4-4776-90ef-db42f294f738
2025-09-11 12:04:19,715 - DEBUG - VM ctest-vn2-vm1-54892193 launched on Node cn-jenkins-deploy-platform-ansible-os-4091-1
2025-09-11 12:04:19,785 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/7ab1f8ba-c4d4-4776-90ef-db42f294f738
2025-09-11 12:04:19,793 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/a7d14289-18cc-4d43-b460-27925eee8ff8
2025-09-11 12:04:21,021 - 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=3.14 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.424 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.424/1.781/3.139/1.357 ms')
2025-09-11 12:04:21,022 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-54892193 passed
2025-09-11 12:04:21,171 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:21,172 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-54892193, IP 165.28.114.195, Port 22
2025-09-11 12:04:21,331 - DEBUG - VM ctest-vn2-vm1-54892193 is ready for SSH connections
2025-09-11 12:04:21,331 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:21,332 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 165.28.114.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-11 12:04:21,332 - DEBUG - ping -s 56 -c 3 -W 1 165.28.114.195
2025-09-11 12:04:25,975 - DEBUG - PING 165.28.114.195 (165.28.114.195): 56 data bytes
--- 165.28.114.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-11 12:04:25,976 - WARNING - Ping to IP 165.28.114.195 from VM ctest-vn1-vm1-13339118 failed
2025-09-11 12:04:25,976 - INFO - Adding interface with subnet_id d7fde979-bedb-46bd-aa44-c85e9a5cee6b, port_id None to router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:26,239 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:26,240 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 165.28.114.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-11 12:04:26,240 - DEBUG - ping -s 56 -c 3 -W 1 165.28.114.195
2025-09-11 12:04:29,456 - DEBUG - PING 165.28.114.195 (165.28.114.195): 56 data bytes
64 bytes from 165.28.114.195: seq=1 ttl=63 time=2.788 ms
64 bytes from 165.28.114.195: seq=2 ttl=63 time=0.789 ms
--- 165.28.114.195 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 0.789/1.788/2.788 ms
2025-09-11 12:04:29,456 - WARNING - Ping to IP 165.28.114.195 from VM ctest-vn1-vm1-13339118 failed
2025-09-11 12:04:30,457 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 165.28.114.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-11 12:04:30,457 - DEBUG - ping -s 56 -c 3 -W 1 165.28.114.195
2025-09-11 12:04:32,671 - DEBUG - PING 165.28.114.195 (165.28.114.195): 56 data bytes
64 bytes from 165.28.114.195: seq=0 ttl=63 time=1.403 ms
64 bytes from 165.28.114.195: seq=1 ttl=63 time=0.853 ms
64 bytes from 165.28.114.195: seq=2 ttl=63 time=0.775 ms
--- 165.28.114.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.775/1.010/1.403 ms
2025-09-11 12:04:32,672 - INFO - Ping to IP 165.28.114.195 from VM ctest-vn1-vm1-13339118 passed
2025-09-11 12:04:32,672 - INFO - Deleting interface with subnet_id 22e82a4d-3454-4a6c-845b-028acb044031, port_id None from router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:32,790 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:32,790 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 165.28.114.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-11 12:04:32,790 - DEBUG - ping -s 56 -c 3 -W 1 165.28.114.195
2025-09-11 12:04:36,004 - DEBUG - PING 165.28.114.195 (165.28.114.195): 56 data bytes
--- 165.28.114.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-11 12:04:36,004 - WARNING - Ping to IP 165.28.114.195 from VM ctest-vn1-vm1-13339118 failed
2025-09-11 12:04:36,005 - INFO - Adding interface with subnet_id 22e82a4d-3454-4a6c-845b-028acb044031, port_id None to router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:36,206 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 12:04:36,206 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 165.28.114.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-11 12:04:36,206 - DEBUG - ping -s 56 -c 3 -W 1 165.28.114.195
2025-09-11 12:04:38,428 - DEBUG - PING 165.28.114.195 (165.28.114.195): 56 data bytes
64 bytes from 165.28.114.195: seq=0 ttl=63 time=1.440 ms
64 bytes from 165.28.114.195: seq=1 ttl=63 time=1.048 ms
64 bytes from 165.28.114.195: seq=2 ttl=63 time=1.017 ms
--- 165.28.114.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.017/1.168/1.440 ms
2025-09-11 12:04:38,428 - INFO - Ping to IP 165.28.114.195 from VM ctest-vn1-vm1-13339118 passed
2025-09-11 12:04:38,429 - INFO - Deleting interface with subnet_id d7fde979-bedb-46bd-aa44-c85e9a5cee6b, port_id None from router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:38,550 - INFO - Deleting interface with subnet_id 22e82a4d-3454-4a6c-845b-028acb044031, port_id None from router 36ffc912-e4ff-4bba-ae50-087fff0e9cae
2025-09-11 12:04:38,727 - INFO - Deleting VM ctest-vn2-vm1-54892193
2025-09-11 12:04:38,806 - INFO - Deleting VM ctest-vn1-vm1-13339118
2025-09-11 12:04:38,879 - INFO - Deleting VN ctest-vn2-13219604
2025-09-11 12:04:38,918 - DEBUG - VN 342de450-b45f-420d-b8cc-75822256e253 still in use: Unable to complete operation on network 342de450-b45f-420d-b8cc-75822256e253. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-e459b793-c265-4447-a606-f4c72c882fb6']
2025-09-11 12:04:38,918 - WARNING - Deleting VN ctest-vn2-13219604 failed..Will retry
2025-09-11 12:04:41,014 - DEBUG - Response for deleting network ()
2025-09-11 12:04:41,014 - INFO - Deleting VN ctest-vn1-20783903
2025-09-11 12:04:41,117 - DEBUG - Response for deleting network ()
2025-09-11 12:04:41,372 - DEBUG - No XMPP flaps were noticed during the test
2025-09-11 12:04:41,372 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-09-11 12:04:41,373 - INFO - --------------------------------------------------------------------------------
2025-09-11 12:04:42,094 - INFO - Deleted project: ctest-TestRouters-91171144, ID : 98035dda-4a0e-4d2a-9e08-e72cc8aca607