2025-09-08 09:44:31,539 - INFO - Domain Default found not creating
2025-09-08 09:44:31,680 - INFO - Project ctest-TestRouters-37651768 not found, creating it
2025-09-08 09:44:32,108 - INFO - Created Project:ctest-TestRouters-37651768, ID : 0b3bc3e5-a74f-4519-9d82-ed1cad6042e3
2025-09-08 09:44:33,485 - INFO - ================================================================================
2025-09-08 09:44:33,485 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-08 09:44:33,485 - 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-08 09:44:33,747 - DEBUG - Nothing to compare xmpp stats {'10.0.0.65': {'10.20.0.17': '0'}} with
2025-09-08 09:44:33,747 - INFO - Initial checks done. Running the testcase now
2025-09-08 09:44:33,748 - INFO -
2025-09-08 09:44:34,289 - DEBUG - Response for create_network : {'network': {'id': '0ccf1f80-12fc-4d38-9495-1fa9ea7a7fca', 'name': 'ctest-vn1-05103759', 'tenant_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'project_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-37651768', 'ctest-vn1-05103759'], 'port_security_enabled': True, 'description': ''}}
2025-09-08 09:44:34,511 - DEBUG - Response for create_subnet : {'subnet': {'id': '4739332e-acb4-4c22-b029-ca13216a1526', 'name': '', 'tenant_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'network_id': '0ccf1f80-12fc-4d38-9495-1fa9ea7a7fca', 'ip_version': 4, 'cidr': '29.44.252.64/26', 'allocation_pools': [{'start': '29.44.252.66', 'end': '29.44.252.126'}], 'gateway_ip': '29.44.252.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '29.44.252.66', 'tags': [], 'project_id': '0b3bc3e5a74f45199d82ed1cad6042e3'}}
2025-09-08 09:44:34,526 - INFO - Created VN ctest-vn1-05103759
2025-09-08 09:44:34,578 - DEBUG - VN ctest-vn1-05103759 UUID is 0ccf1f80-12fc-4d38-9495-1fa9ea7a7fca
2025-09-08 09:44:34,898 - DEBUG - Response for create_network : {'network': {'id': '7be33f2a-449a-43de-826b-5e30ae71f9ce', 'name': 'ctest-vn2-56662198', 'tenant_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'project_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-37651768', 'ctest-vn2-56662198'], 'port_security_enabled': True, 'description': ''}}
2025-09-08 09:44:35,089 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c14ded01-72b1-4a9f-915a-fafd573cbe69', 'name': '', 'tenant_id': '0b3bc3e5a74f45199d82ed1cad6042e3', 'network_id': '7be33f2a-449a-43de-826b-5e30ae71f9ce', 'ip_version': 4, 'cidr': '150.36.125.64/26', 'allocation_pools': [{'start': '150.36.125.66', 'end': '150.36.125.126'}], 'gateway_ip': '150.36.125.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '150.36.125.66', 'tags': [], 'project_id': '0b3bc3e5a74f45199d82ed1cad6042e3'}}
2025-09-08 09:44:35,108 - INFO - Created VN ctest-vn2-56662198
2025-09-08 09:44:35,159 - DEBUG - VN ctest-vn2-56662198 UUID is 7be33f2a-449a-43de-826b-5e30ae71f9ce
2025-09-08 09:44:35,377 - DEBUG - Services list from nova: [, , ]
2025-09-08 09:44:36,385 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4043-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4043-1)
2025-09-08 09:44:37,584 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4043-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4043-1)
2025-09-08 09:44:37,660 - INFO - Adding interface with subnet_id 4739332e-acb4-4c22-b029-ca13216a1526, port_id None to router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:44:37,909 - INFO - Waiting for VM ctest-vn1-vm1-30272247 to be up..
2025-09-08 09:44:38,020 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-08 09:44:43,097 - DEBUG - VM is in ACTIVE state now
2025-09-08 09:44:43,097 - INFO - VM name : ctest-vn1-vm1-30272247
2025-09-08 09:44:43,181 - DEBUG - VM ctest-vn1-vm1-30272247 ID is d2bdeb16-0e97-4138-b386-f788be0ee72c
2025-09-08 09:44:43,201 - DEBUG - VM ctest-vn1-vm1-30272247 launched on Node cn-jenkins-deploy-platform-ansible-os-4043-1
2025-09-08 09:44:43,272 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2bdeb16-0e97-4138-b386-f788be0ee72c
2025-09-08 09:44:43,570 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2bdeb16-0e97-4138-b386-f788be0ee72c
2025-09-08 09:44:43,604 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/b3564fdf-86f3-4572-bde3-c8a06ed10649
2025-09-08 09:44:46,870 - 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-09-08 09:44:46,870 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-30272247 failed!
2025-09-08 09:44:46,927 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-37651768:ctest-vn1-05103759 is 29.44.252.65 and allocation pool is NOT set
2025-09-08 09:44:48,990 - 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.20 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.385 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.385/1.792/3.199/1.407 ms')
2025-09-08 09:44:48,990 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-30272247 passed
2025-09-08 09:44:49,143 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:44:49,143 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-30272247, IP 29.44.252.67, Port 22
2025-09-08 09:44:49,298 - DEBUG - VM ctest-vn1-vm1-30272247 is ready for SSH connections
2025-09-08 09:44:49,298 - INFO - Waiting for VM ctest-vn2-vm1-30694754 to be up..
2025-09-08 09:44:49,371 - DEBUG - VM is in ACTIVE state now
2025-09-08 09:44:49,372 - INFO - VM name : ctest-vn2-vm1-30694754
2025-09-08 09:44:49,442 - DEBUG - VM ctest-vn2-vm1-30694754 ID is 0a8410f2-f37d-495f-89c7-2a4a5c70fac3
2025-09-08 09:44:49,442 - DEBUG - VM ctest-vn2-vm1-30694754 launched on Node cn-jenkins-deploy-platform-ansible-os-4043-1
2025-09-08 09:44:49,512 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0a8410f2-f37d-495f-89c7-2a4a5c70fac3
2025-09-08 09:44:49,520 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/199036fd-a01b-4b1b-924e-dc967b6fd943
2025-09-08 09:44:50,767 - 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.41 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.472 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.472/1.939/3.406/1.467 ms')
2025-09-08 09:44:50,767 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-30694754 passed
2025-09-08 09:44:50,919 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:44:50,919 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-30694754, IP 150.36.125.67, Port 22
2025-09-08 09:44:51,090 - DEBUG - VM ctest-vn2-vm1-30694754 is ready for SSH connections
2025-09-08 09:44:51,090 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:44:51,090 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 150.36.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-09-08 09:44:51,091 - DEBUG - ping -s 56 -c 3 -W 1 150.36.125.67
2025-09-08 09:44:55,714 - DEBUG - PING 150.36.125.67 (150.36.125.67): 56 data bytes
--- 150.36.125.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-08 09:44:55,715 - WARNING - Ping to IP 150.36.125.67 from VM ctest-vn1-vm1-30272247 failed
2025-09-08 09:44:55,715 - INFO - Adding interface with subnet_id c14ded01-72b1-4a9f-915a-fafd573cbe69, port_id None to router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:44:55,957 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:44:55,957 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 150.36.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-09-08 09:44:55,957 - DEBUG - ping -s 56 -c 3 -W 1 150.36.125.67
2025-09-08 09:44:58,161 - DEBUG - PING 150.36.125.67 (150.36.125.67): 56 data bytes
64 bytes from 150.36.125.67: seq=0 ttl=63 time=2.770 ms
64 bytes from 150.36.125.67: seq=1 ttl=63 time=0.826 ms
64 bytes from 150.36.125.67: seq=2 ttl=63 time=0.769 ms
--- 150.36.125.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.769/1.455/2.770 ms
2025-09-08 09:44:58,161 - INFO - Ping to IP 150.36.125.67 from VM ctest-vn1-vm1-30272247 passed
2025-09-08 09:44:58,162 - INFO - Deleting interface with subnet_id 4739332e-acb4-4c22-b029-ca13216a1526, port_id None from router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:44:58,262 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:44:58,263 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 150.36.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-09-08 09:44:58,263 - DEBUG - ping -s 56 -c 3 -W 1 150.36.125.67
2025-09-08 09:45:01,466 - DEBUG - PING 150.36.125.67 (150.36.125.67): 56 data bytes
--- 150.36.125.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-08 09:45:01,467 - WARNING - Ping to IP 150.36.125.67 from VM ctest-vn1-vm1-30272247 failed
2025-09-08 09:45:01,467 - INFO - Adding interface with subnet_id 4739332e-acb4-4c22-b029-ca13216a1526, port_id None to router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:45:01,679 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-08 09:45:01,679 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 150.36.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-09-08 09:45:01,679 - DEBUG - ping -s 56 -c 3 -W 1 150.36.125.67
2025-09-08 09:45:04,888 - DEBUG - PING 150.36.125.67 (150.36.125.67): 56 data bytes
64 bytes from 150.36.125.67: seq=1 ttl=63 time=1.504 ms
64 bytes from 150.36.125.67: seq=2 ttl=63 time=0.840 ms
--- 150.36.125.67 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 0.840/1.172/1.504 ms
2025-09-08 09:45:04,888 - WARNING - Ping to IP 150.36.125.67 from VM ctest-vn1-vm1-30272247 failed
2025-09-08 09:45:05,888 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 150.36.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-09-08 09:45:05,889 - DEBUG - ping -s 56 -c 3 -W 1 150.36.125.67
2025-09-08 09:45:08,083 - DEBUG - PING 150.36.125.67 (150.36.125.67): 56 data bytes
64 bytes from 150.36.125.67: seq=0 ttl=63 time=1.764 ms
64 bytes from 150.36.125.67: seq=1 ttl=63 time=1.227 ms
64 bytes from 150.36.125.67: seq=2 ttl=63 time=0.880 ms
--- 150.36.125.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.880/1.290/1.764 ms
2025-09-08 09:45:08,083 - INFO - Ping to IP 150.36.125.67 from VM ctest-vn1-vm1-30272247 passed
2025-09-08 09:45:08,083 - INFO - Deleting interface with subnet_id c14ded01-72b1-4a9f-915a-fafd573cbe69, port_id None from router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:45:08,196 - INFO - Deleting interface with subnet_id 4739332e-acb4-4c22-b029-ca13216a1526, port_id None from router 0964567c-4ccf-4808-a4a9-d8520bc78308
2025-09-08 09:45:08,358 - INFO - Deleting VM ctest-vn2-vm1-30694754
2025-09-08 09:45:08,441 - INFO - Deleting VM ctest-vn1-vm1-30272247
2025-09-08 09:45:08,512 - INFO - Deleting VN ctest-vn2-56662198
2025-09-08 09:45:08,553 - DEBUG - VN 7be33f2a-449a-43de-826b-5e30ae71f9ce still in use: Unable to complete operation on network 7be33f2a-449a-43de-826b-5e30ae71f9ce. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-9c06918c-2fca-40aa-85c9-92d3fcb5bfa7']
2025-09-08 09:45:08,554 - WARNING - Deleting VN ctest-vn2-56662198 failed..Will retry
2025-09-08 09:45:10,667 - DEBUG - Response for deleting network ()
2025-09-08 09:45:10,668 - INFO - Deleting VN ctest-vn1-05103759
2025-09-08 09:45:10,760 - DEBUG - Response for deleting network ()
2025-09-08 09:45:11,011 - DEBUG - No XMPP flaps were noticed during the test
2025-09-08 09:45:11,011 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-09-08 09:45:11,011 - INFO - --------------------------------------------------------------------------------
2025-09-08 09:45:11,688 - INFO - Deleted project: ctest-TestRouters-37651768, ID : 0b3bc3e5-a74f-4519-9d82-ed1cad6042e3