2026-05-29 12:57:35,570 - INFO - Domain Default found not creating
2026-05-29 12:57:35,732 - INFO - Project ctest-TestRouters-10085391 not found, creating it
2026-05-29 12:57:36,204 - INFO - Created Project:ctest-TestRouters-10085391, ID : eaf4b014-1f32-4802-bd22-de35b79f4a81
2026-05-29 12:57:37,775 - INFO - ================================================================================
2026-05-29 12:57:37,775 - INFO - STARTING TEST : test_basic_router_behavior
2026-05-29 12:57:37,775 - 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-05-29 12:57:38,031 - DEBUG - Nothing to compare xmpp stats {'10.0.0.33': {'10.20.0.254': '0'}} with
2026-05-29 12:57:38,031 - INFO - Initial checks done. Running the testcase now
2026-05-29 12:57:38,031 - INFO -
2026-05-29 12:57:38,591 - DEBUG - Response for create_network : {'network': {'id': 'cc5ed613-9421-4a3d-92a3-29de13463614', 'name': 'ctest-vn1-19302690', 'tenant_id': 'eaf4b0141f324802bd22de35b79f4a81', 'project_id': 'eaf4b0141f324802bd22de35b79f4a81', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-10085391', 'ctest-vn1-19302690'], 'port_security_enabled': True, 'description': ''}}
2026-05-29 12:57:38,816 - DEBUG - Response for create_subnet : {'subnet': {'id': 'e8743705-e6ce-484b-b5d0-7351d5773ced', 'name': '', 'tenant_id': 'eaf4b0141f324802bd22de35b79f4a81', 'network_id': 'cc5ed613-9421-4a3d-92a3-29de13463614', 'ip_version': 4, 'cidr': '202.167.199.64/26', 'allocation_pools': [{'start': '202.167.199.66', 'end': '202.167.199.126'}], 'gateway_ip': '202.167.199.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '202.167.199.66', 'tags': [], 'project_id': 'eaf4b0141f324802bd22de35b79f4a81'}}
2026-05-29 12:57:38,834 - INFO - Created VN ctest-vn1-19302690
2026-05-29 12:57:38,886 - DEBUG - VN ctest-vn1-19302690 UUID is cc5ed613-9421-4a3d-92a3-29de13463614
2026-05-29 12:57:39,233 - DEBUG - Response for create_network : {'network': {'id': '9262212d-def9-4742-9723-1d00a6c04405', 'name': 'ctest-vn2-27151179', 'tenant_id': 'eaf4b0141f324802bd22de35b79f4a81', 'project_id': 'eaf4b0141f324802bd22de35b79f4a81', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-10085391', 'ctest-vn2-27151179'], 'port_security_enabled': True, 'description': ''}}
2026-05-29 12:57:39,434 - DEBUG - Response for create_subnet : {'subnet': {'id': '7e130aac-d8ca-465d-9c4e-447602a2e179', 'name': '', 'tenant_id': 'eaf4b0141f324802bd22de35b79f4a81', 'network_id': '9262212d-def9-4742-9723-1d00a6c04405', 'ip_version': 4, 'cidr': '123.125.44.128/26', 'allocation_pools': [{'start': '123.125.44.130', 'end': '123.125.44.190'}], 'gateway_ip': '123.125.44.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '123.125.44.130', 'tags': [], 'project_id': 'eaf4b0141f324802bd22de35b79f4a81'}}
2026-05-29 12:57:39,450 - INFO - Created VN ctest-vn2-27151179
2026-05-29 12:57:39,506 - DEBUG - VN ctest-vn2-27151179 UUID is 9262212d-def9-4742-9723-1d00a6c04405
2026-05-29 12:57:39,673 - DEBUG - Services list from nova: [, , ]
2026-05-29 12:57:40,712 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5850-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5850-1)
2026-05-29 12:57:42,335 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-5850-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-5850-1)
2026-05-29 12:57:42,414 - INFO - Adding interface with subnet_id e8743705-e6ce-484b-b5d0-7351d5773ced, port_id None to router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:57:42,733 - INFO - Waiting for VM ctest-vn1-vm1-17741329 to be up..
2026-05-29 12:57:42,856 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-05-29 12:57:47,935 - DEBUG - VM is in ACTIVE state now
2026-05-29 12:57:47,936 - INFO - VM name : ctest-vn1-vm1-17741329
2026-05-29 12:57:48,022 - DEBUG - VM ctest-vn1-vm1-17741329 ID is afebbe26-d4c7-4d96-9a74-3fc7b6b50ef0
2026-05-29 12:57:48,043 - DEBUG - VM ctest-vn1-vm1-17741329 launched on Node cn-jenkins-deploy-platform-ansible-os-5850-1
2026-05-29 12:57:48,127 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/afebbe26-d4c7-4d96-9a74-3fc7b6b50ef0
2026-05-29 12:57:48,423 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/afebbe26-d4c7-4d96-9a74-3fc7b6b50ef0
2026-05-29 12:57:48,457 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/50db88e1-adaa-4bac-99ec-ed5f3815f55b
2026-05-29 12:57:51,704 - 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 1006ms')
2026-05-29 12:57:51,704 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-17741329 failed!
2026-05-29 12:57:51,758 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-10085391:ctest-vn1-19302690 is 202.167.199.65 and allocation pool is NOT set
2026-05-29 12:57:53,824 - 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=5.20 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.97 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 = 1.974/3.586/5.199/1.612 ms')
2026-05-29 12:57:53,824 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-17741329 passed
2026-05-29 12:57:53,974 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:57:53,974 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-17741329, IP 202.167.199.67, Port 22
2026-05-29 12:57:54,129 - DEBUG - VM ctest-vn1-vm1-17741329 is ready for SSH connections
2026-05-29 12:57:54,129 - INFO - Waiting for VM ctest-vn2-vm1-23256322 to be up..
2026-05-29 12:57:54,203 - DEBUG - VM is in ACTIVE state now
2026-05-29 12:57:54,204 - INFO - VM name : ctest-vn2-vm1-23256322
2026-05-29 12:57:54,275 - DEBUG - VM ctest-vn2-vm1-23256322 ID is c9c793f3-7cf9-45d1-91a8-df121d71ce60
2026-05-29 12:57:54,275 - DEBUG - VM ctest-vn2-vm1-23256322 launched on Node cn-jenkins-deploy-platform-ansible-os-5850-1
2026-05-29 12:57:54,360 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine/c9c793f3-7cf9-45d1-91a8-df121d71ce60
2026-05-29 12:57:54,369 - DEBUG - Requesting: http://10.0.0.33:8082/virtual-machine-interface/0545f002-1a5c-4548-b4e1-3bde219f6b7b
2026-05-29 12:57:55,609 - 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=2.91 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.504 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.504/1.708/2.912/1.204 ms')
2026-05-29 12:57:55,610 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-23256322 passed
2026-05-29 12:57:55,766 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:57:55,766 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-23256322, IP 123.125.44.131, Port 22
2026-05-29 12:57:55,925 - DEBUG - VM ctest-vn2-vm1-23256322 is ready for SSH connections
2026-05-29 12:57:55,925 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:57:55,925 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.125.44.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2026-05-29 12:57:55,926 - DEBUG - ping -s 56 -c 3 -W 1 123.125.44.131
2026-05-29 12:58:01,224 - DEBUG - PING 123.125.44.131 (123.125.44.131): 56 data bytes
--- 123.125.44.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-05-29 12:58:01,224 - WARNING - Ping to IP 123.125.44.131 from VM ctest-vn1-vm1-17741329 failed
2026-05-29 12:58:01,225 - INFO - Adding interface with subnet_id 7e130aac-d8ca-465d-9c4e-447602a2e179, port_id None to router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:58:01,475 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:58:01,475 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.125.44.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2026-05-29 12:58:01,475 - DEBUG - ping -s 56 -c 3 -W 1 123.125.44.131
2026-05-29 12:58:04,681 - DEBUG - PING 123.125.44.131 (123.125.44.131): 56 data bytes
64 bytes from 123.125.44.131: seq=1 ttl=63 time=2.929 ms
64 bytes from 123.125.44.131: seq=2 ttl=63 time=0.742 ms
--- 123.125.44.131 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 0.742/1.835/2.929 ms
2026-05-29 12:58:04,682 - WARNING - Ping to IP 123.125.44.131 from VM ctest-vn1-vm1-17741329 failed
2026-05-29 12:58:05,682 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.125.44.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2026-05-29 12:58:05,683 - DEBUG - ping -s 56 -c 3 -W 1 123.125.44.131
2026-05-29 12:58:07,922 - DEBUG - PING 123.125.44.131 (123.125.44.131): 56 data bytes
64 bytes from 123.125.44.131: seq=0 ttl=63 time=1.697 ms
64 bytes from 123.125.44.131: seq=1 ttl=63 time=1.080 ms
64 bytes from 123.125.44.131: seq=2 ttl=63 time=0.952 ms
--- 123.125.44.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.952/1.243/1.697 ms
2026-05-29 12:58:07,923 - INFO - Ping to IP 123.125.44.131 from VM ctest-vn1-vm1-17741329 passed
2026-05-29 12:58:07,923 - INFO - Deleting interface with subnet_id e8743705-e6ce-484b-b5d0-7351d5773ced, port_id None from router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:58:08,036 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:58:08,036 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.125.44.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2026-05-29 12:58:08,036 - DEBUG - ping -s 56 -c 3 -W 1 123.125.44.131
2026-05-29 12:58:11,247 - DEBUG - PING 123.125.44.131 (123.125.44.131): 56 data bytes
--- 123.125.44.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-05-29 12:58:11,247 - WARNING - Ping to IP 123.125.44.131 from VM ctest-vn1-vm1-17741329 failed
2026-05-29 12:58:11,247 - INFO - Adding interface with subnet_id e8743705-e6ce-484b-b5d0-7351d5773ced, port_id None to router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:58:11,464 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-05-29 12:58:11,464 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.125.44.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.33, gateway password: c0ntrail123
2026-05-29 12:58:11,464 - DEBUG - ping -s 56 -c 3 -W 1 123.125.44.131
2026-05-29 12:58:13,687 - DEBUG - PING 123.125.44.131 (123.125.44.131): 56 data bytes
64 bytes from 123.125.44.131: seq=0 ttl=63 time=1.471 ms
64 bytes from 123.125.44.131: seq=1 ttl=63 time=1.059 ms
64 bytes from 123.125.44.131: seq=2 ttl=63 time=0.822 ms
--- 123.125.44.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.822/1.117/1.471 ms
2026-05-29 12:58:13,687 - INFO - Ping to IP 123.125.44.131 from VM ctest-vn1-vm1-17741329 passed
2026-05-29 12:58:13,687 - INFO - Deleting interface with subnet_id 7e130aac-d8ca-465d-9c4e-447602a2e179, port_id None from router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:58:13,816 - INFO - Deleting interface with subnet_id e8743705-e6ce-484b-b5d0-7351d5773ced, port_id None from router 722563aa-50ad-4780-b28c-22afc039c9d2
2026-05-29 12:58:14,001 - INFO - Deleting VM ctest-vn2-vm1-23256322
2026-05-29 12:58:14,077 - INFO - Deleting VM ctest-vn1-vm1-17741329
2026-05-29 12:58:14,159 - INFO - Deleting VN ctest-vn2-27151179
2026-05-29 12:58:14,194 - DEBUG - VN 9262212d-def9-4742-9723-1d00a6c04405 still in use: Unable to complete operation on network 9262212d-def9-4742-9723-1d00a6c04405. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-74abe106-92fb-4cef-af2d-f9633c47a8f1']
2026-05-29 12:58:14,194 - WARNING - Deleting VN ctest-vn2-27151179 failed..Will retry
2026-05-29 12:58:16,292 - DEBUG - Response for deleting network ()
2026-05-29 12:58:16,293 - INFO - Deleting VN ctest-vn1-19302690
2026-05-29 12:58:16,388 - DEBUG - Response for deleting network ()
2026-05-29 12:58:16,646 - DEBUG - No XMPP flaps were noticed during the test
2026-05-29 12:58:16,646 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2026-05-29 12:58:16,646 - INFO - --------------------------------------------------------------------------------
2026-05-29 12:58:17,338 - INFO - Deleted project: ctest-TestRouters-10085391, ID : eaf4b014-1f32-4802-bd22-de35b79f4a81