2026-10-07 09:58:37,331 - INFO - Domain Default found not creating
2026-10-07 09:58:37,487 - INFO - Project ctest-TestRouters-42829759 not found, creating it
2026-10-07 09:58:37,968 - INFO - Created Project:ctest-TestRouters-42829759, ID : 714aaed5-9113-40d4-b92c-23b14a9e111f
2026-10-07 09:58:39,655 - INFO - ================================================================================
2026-10-07 09:58:39,655 - INFO - STARTING TEST : test_basic_router_behavior
2026-10-07 09:58:39,655 - 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-07 09:58:39,914 - DEBUG - Nothing to compare xmpp stats {'10.0.0.161': {'10.20.0.17': '0'}} with
2026-10-07 09:58:39,914 - INFO - Initial checks done. Running the testcase now
2026-10-07 09:58:39,914 - INFO -
2026-10-07 09:58:40,580 - DEBUG - Response for create_network : {'network': {'id': 'f4b1f65e-6f20-4685-b26b-998583548db4', 'name': 'ctest-vn1-64666357', 'tenant_id': '714aaed5911340d4b92c23b14a9e111f', 'project_id': '714aaed5911340d4b92c23b14a9e111f', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-42829759', 'ctest-vn1-64666357'], 'port_security_enabled': True, 'description': ''}}
2026-10-07 09:58:40,797 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f3be8fc8-a9fc-4511-a5b3-1e4a3798e6d1', 'name': '', 'tenant_id': '714aaed5911340d4b92c23b14a9e111f', 'network_id': 'f4b1f65e-6f20-4685-b26b-998583548db4', 'ip_version': 4, 'cidr': '172.99.223.0/26', 'allocation_pools': [{'start': '172.99.223.2', 'end': '172.99.223.62'}], 'gateway_ip': '172.99.223.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '172.99.223.2', 'tags': [], 'project_id': '714aaed5911340d4b92c23b14a9e111f'}}
2026-10-07 09:58:40,824 - INFO - Created VN ctest-vn1-64666357
2026-10-07 09:58:40,878 - DEBUG - VN ctest-vn1-64666357 UUID is f4b1f65e-6f20-4685-b26b-998583548db4
2026-10-07 09:58:41,185 - DEBUG - Response for create_network : {'network': {'id': '1445328f-b58d-48c8-9079-eff1f062eb1b', 'name': 'ctest-vn2-53660115', 'tenant_id': '714aaed5911340d4b92c23b14a9e111f', 'project_id': '714aaed5911340d4b92c23b14a9e111f', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-42829759', 'ctest-vn2-53660115'], 'port_security_enabled': True, 'description': ''}}
2026-10-07 09:58:41,445 - DEBUG - Response for create_subnet : {'subnet': {'id': '2fcdd7c9-ec89-42d9-af07-9a0bf3a506ab', 'name': '', 'tenant_id': '714aaed5911340d4b92c23b14a9e111f', 'network_id': '1445328f-b58d-48c8-9079-eff1f062eb1b', 'ip_version': 4, 'cidr': '93.108.40.128/26', 'allocation_pools': [{'start': '93.108.40.130', 'end': '93.108.40.190'}], 'gateway_ip': '93.108.40.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '93.108.40.130', 'tags': [], 'project_id': '714aaed5911340d4b92c23b14a9e111f'}}
2026-10-07 09:58:41,461 - INFO - Created VN ctest-vn2-53660115
2026-10-07 09:58:41,514 - DEBUG - VN ctest-vn2-53660115 UUID is 1445328f-b58d-48c8-9079-eff1f062eb1b
2026-10-07 09:58:41,787 - DEBUG - Services list from nova: [, , ]
2026-10-07 09:58:42,163 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6354-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6354-1)
2026-10-07 09:58:42,760 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6354-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6354-1)
2026-10-07 09:58:42,824 - INFO - Adding interface with subnet_id f3be8fc8-a9fc-4511-a5b3-1e4a3798e6d1, port_id None to router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:58:43,079 - INFO - Waiting for VM ctest-vn1-vm1-91425559 to be up..
2026-10-07 09:58:43,128 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:58:48,202 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:58:53,345 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:58:58,421 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:59:03,501 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:59:08,581 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:59:13,664 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-07 09:59:18,738 - DEBUG - VM is in ACTIVE state now
2026-10-07 09:59:18,738 - INFO - VM name : ctest-vn1-vm1-91425559
2026-10-07 09:59:18,808 - DEBUG - VM ctest-vn1-vm1-91425559 ID is 32afef65-e953-4c36-b2bc-94c89ec8da6d
2026-10-07 09:59:18,827 - DEBUG - VM ctest-vn1-vm1-91425559 launched on Node cn-jenkins-deploy-platform-ansible-os-6354-1
2026-10-07 09:59:18,892 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/32afef65-e953-4c36-b2bc-94c89ec8da6d
2026-10-07 09:59:19,261 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/32afef65-e953-4c36-b2bc-94c89ec8da6d
2026-10-07 09:59:19,288 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/2b2f38df-7e47-4222-9d4c-e4d362f45f2c
2026-10-07 09:59:22,548 - 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 1026ms')
2026-10-07 09:59:22,548 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-91425559 failed!
2026-10-07 09:59:22,606 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-42829759:ctest-vn1-64666357 is 172.99.223.1 and allocation pool is NOT set
2026-10-07 09:59:24,681 - 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=6.48 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.80 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 = 1.803/4.140/6.477/2.337 ms')
2026-10-07 09:59:24,681 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-91425559 passed
2026-10-07 09:59:24,842 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:24,842 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-91425559, IP 172.99.223.3, Port 22
2026-10-07 09:59:24,908 - DEBUG - Error on ssh to cirros@169.254.0.3:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-07 09:59:24,986 - DEBUG - VM ctest-vn1-vm1-91425559 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-07 09:59:29,987 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:29,987 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-91425559, IP 172.99.223.3, Port 22
2026-10-07 09:59:30,153 - DEBUG - VM ctest-vn1-vm1-91425559 is ready for SSH connections
2026-10-07 09:59:30,153 - INFO - Waiting for VM ctest-vn2-vm1-01667399 to be up..
2026-10-07 09:59:30,229 - DEBUG - VM is in ACTIVE state now
2026-10-07 09:59:30,229 - INFO - VM name : ctest-vn2-vm1-01667399
2026-10-07 09:59:30,299 - DEBUG - VM ctest-vn2-vm1-01667399 ID is 378c2801-dfe8-4263-a26f-fbc4d6e09e5d
2026-10-07 09:59:30,299 - DEBUG - VM ctest-vn2-vm1-01667399 launched on Node cn-jenkins-deploy-platform-ansible-os-6354-1
2026-10-07 09:59:30,393 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine/378c2801-dfe8-4263-a26f-fbc4d6e09e5d
2026-10-07 09:59:30,402 - DEBUG - Requesting: http://10.0.0.161:8082/virtual-machine-interface/3df90d28-4f5f-48a3-a6eb-084629b9c9f5
2026-10-07 09:59:31,639 - 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=8.45 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.489 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.489/4.467/8.445/3.978 ms')
2026-10-07 09:59:31,640 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-01667399 passed
2026-10-07 09:59:31,790 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:31,790 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-01667399, IP 93.108.40.131, Port 22
2026-10-07 09:59:31,947 - DEBUG - VM ctest-vn2-vm1-01667399 is ready for SSH connections
2026-10-07 09:59:31,947 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:31,947 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 93.108.40.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123
2026-10-07 09:59:31,947 - DEBUG - ping -s 56 -c 3 -W 1 93.108.40.131
2026-10-07 09:59:36,962 - DEBUG - PING 93.108.40.131 (93.108.40.131): 56 data bytes
--- 93.108.40.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-10-07 09:59:36,963 - WARNING - Ping to IP 93.108.40.131 from VM ctest-vn1-vm1-91425559 failed
2026-10-07 09:59:36,963 - INFO - Adding interface with subnet_id 2fcdd7c9-ec89-42d9-af07-9a0bf3a506ab, port_id None to router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:59:37,232 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:37,232 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 93.108.40.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123
2026-10-07 09:59:37,232 - DEBUG - ping -s 56 -c 3 -W 1 93.108.40.131
2026-10-07 09:59:40,369 - DEBUG - PING 93.108.40.131 (93.108.40.131): 56 data bytes
64 bytes from 93.108.40.131: seq=1 ttl=63 time=2.956 ms
64 bytes from 93.108.40.131: seq=2 ttl=63 time=0.891 ms
--- 93.108.40.131 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 0.891/1.923/2.956 ms
2026-10-07 09:59:40,369 - WARNING - Ping to IP 93.108.40.131 from VM ctest-vn1-vm1-91425559 failed
2026-10-07 09:59:41,370 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 93.108.40.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123
2026-10-07 09:59:41,370 - DEBUG - ping -s 56 -c 3 -W 1 93.108.40.131
2026-10-07 09:59:43,490 - DEBUG - PING 93.108.40.131 (93.108.40.131): 56 data bytes
64 bytes from 93.108.40.131: seq=0 ttl=63 time=1.524 ms
64 bytes from 93.108.40.131: seq=1 ttl=63 time=1.062 ms
64 bytes from 93.108.40.131: seq=2 ttl=63 time=0.960 ms
--- 93.108.40.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.960/1.182/1.524 ms
2026-10-07 09:59:43,490 - INFO - Ping to IP 93.108.40.131 from VM ctest-vn1-vm1-91425559 passed
2026-10-07 09:59:43,491 - INFO - Deleting interface with subnet_id f3be8fc8-a9fc-4511-a5b3-1e4a3798e6d1, port_id None from router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:59:43,620 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:43,620 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 93.108.40.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123
2026-10-07 09:59:43,620 - DEBUG - ping -s 56 -c 3 -W 1 93.108.40.131
2026-10-07 09:59:46,750 - DEBUG - PING 93.108.40.131 (93.108.40.131): 56 data bytes
--- 93.108.40.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-10-07 09:59:46,750 - WARNING - Ping to IP 93.108.40.131 from VM ctest-vn1-vm1-91425559 failed
2026-10-07 09:59:46,750 - INFO - Adding interface with subnet_id f3be8fc8-a9fc-4511-a5b3-1e4a3798e6d1, port_id None to router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:59:46,970 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-07 09:59:46,970 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 93.108.40.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.161, gateway password: c0ntrail123
2026-10-07 09:59:46,970 - DEBUG - ping -s 56 -c 3 -W 1 93.108.40.131
2026-10-07 09:59:49,102 - DEBUG - PING 93.108.40.131 (93.108.40.131): 56 data bytes
64 bytes from 93.108.40.131: seq=0 ttl=63 time=1.505 ms
64 bytes from 93.108.40.131: seq=1 ttl=63 time=1.134 ms
64 bytes from 93.108.40.131: seq=2 ttl=63 time=1.207 ms
--- 93.108.40.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.134/1.282/1.505 ms
2026-10-07 09:59:49,102 - INFO - Ping to IP 93.108.40.131 from VM ctest-vn1-vm1-91425559 passed
2026-10-07 09:59:49,103 - INFO - Deleting interface with subnet_id 2fcdd7c9-ec89-42d9-af07-9a0bf3a506ab, port_id None from router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:59:49,248 - INFO - Deleting interface with subnet_id f3be8fc8-a9fc-4511-a5b3-1e4a3798e6d1, port_id None from router c93660ee-49e9-4f70-8685-6121d9d6eaec
2026-10-07 09:59:49,453 - INFO - Deleting VM ctest-vn2-vm1-01667399
2026-10-07 09:59:49,535 - INFO - Deleting VM ctest-vn1-vm1-91425559
2026-10-07 09:59:49,602 - INFO - Deleting VN ctest-vn2-53660115
2026-10-07 09:59:49,635 - DEBUG - VN 1445328f-b58d-48c8-9079-eff1f062eb1b still in use: Unable to complete operation on network 1445328f-b58d-48c8-9079-eff1f062eb1b. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-f7e8dc02-5a37-46ea-87c2-b60720a66e89']
2026-10-07 09:59:49,636 - WARNING - Deleting VN ctest-vn2-53660115 failed..Will retry
2026-10-07 09:59:51,799 - DEBUG - Response for deleting network ()
2026-10-07 09:59:51,799 - INFO - Deleting VN ctest-vn1-64666357
2026-10-07 09:59:51,897 - DEBUG - Response for deleting network ()
2026-10-07 09:59:52,153 - DEBUG - No XMPP flaps were noticed during the test
2026-10-07 09:59:52,153 - INFO - END TEST : test_basic_router_behavior : PASSED[0:01:13]
2026-10-07 09:59:52,153 - INFO - --------------------------------------------------------------------------------
2026-10-07 09:59:52,908 - INFO - Deleted project: ctest-TestRouters-42829759, ID : 714aaed5-9113-40d4-b92c-23b14a9e111f