2025-08-28 02:21:05,521 - INFO - Domain Default found not creating
2025-08-28 02:21:05,661 - INFO - Project ctest-TestRouters-91954293 not found, creating it
2025-08-28 02:21:06,177 - INFO - Created Project:ctest-TestRouters-91954293, ID : 89aa027a-d607-4eab-831e-2c0bc3015173
2025-08-28 02:21:07,748 - INFO - ================================================================================
2025-08-28 02:21:07,749 - INFO - STARTING TEST : test_basic_router_behavior
2025-08-28 02:21:07,749 - 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-08-28 02:21:08,994 - DEBUG - Nothing to compare xmpp stats {'10.0.0.65': {'10.20.0.17': '0', '10.20.0.254': '0'}, '10.0.0.27': {'10.20.0.17': '0', '10.20.0.25': '0'}} with
2025-08-28 02:21:08,994 - INFO - Initial checks done. Running the testcase now
2025-08-28 02:21:08,994 - INFO -
2025-08-28 02:21:09,634 - DEBUG - Response for create_network : {'network': {'id': 'd02bb61b-af21-4cbf-bd29-c796a169fc57', 'name': 'ctest-vn1-49602187', 'tenant_id': '89aa027ad6074eab831e2c0bc3015173', 'project_id': '89aa027ad6074eab831e2c0bc3015173', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-91954293', 'ctest-vn1-49602187'], 'port_security_enabled': True, 'description': ''}}
2025-08-28 02:21:09,898 - DEBUG - Response for create_subnet : {'subnet': {'id': '70c2ec26-2c40-4fc6-9abc-127846458d3a', 'name': '', 'tenant_id': '89aa027ad6074eab831e2c0bc3015173', 'network_id': 'd02bb61b-af21-4cbf-bd29-c796a169fc57', 'ip_version': 4, 'cidr': '122.78.116.128/26', 'allocation_pools': [{'start': '122.78.116.130', 'end': '122.78.116.190'}], 'gateway_ip': '122.78.116.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '122.78.116.130', 'tags': [], 'project_id': '89aa027ad6074eab831e2c0bc3015173'}}
2025-08-28 02:21:09,919 - INFO - Created VN ctest-vn1-49602187
2025-08-28 02:21:09,930 - DEBUG - VN ctest-vn1-49602187 UUID is d02bb61b-af21-4cbf-bd29-c796a169fc57
2025-08-28 02:21:10,317 - DEBUG - Response for create_network : {'network': {'id': '1b5cff95-8b86-4145-92fc-e876ded1d1ae', 'name': 'ctest-vn2-98130771', 'tenant_id': '89aa027ad6074eab831e2c0bc3015173', 'project_id': '89aa027ad6074eab831e2c0bc3015173', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-91954293', 'ctest-vn2-98130771'], 'port_security_enabled': True, 'description': ''}}
2025-08-28 02:21:10,548 - DEBUG - Response for create_subnet : {'subnet': {'id': 'dbd86820-b9d9-406c-98b2-63b981b757db', 'name': '', 'tenant_id': '89aa027ad6074eab831e2c0bc3015173', 'network_id': '1b5cff95-8b86-4145-92fc-e876ded1d1ae', 'ip_version': 4, 'cidr': '106.113.13.192/26', 'allocation_pools': [{'start': '106.113.13.194', 'end': '106.113.13.254'}], 'gateway_ip': '106.113.13.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '106.113.13.194', 'tags': [], 'project_id': '89aa027ad6074eab831e2c0bc3015173'}}
2025-08-28 02:21:10,568 - INFO - Created VN ctest-vn2-98130771
2025-08-28 02:21:10,578 - DEBUG - VN ctest-vn2-98130771 UUID is 1b5cff95-8b86-4145-92fc-e876ded1d1ae
2025-08-28 02:21:10,741 - DEBUG - Services list from nova: [, , , ]
2025-08-28 02:21:12,034 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3956-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3956-1)
2025-08-28 02:21:13,295 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3956-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3956-2)
2025-08-28 02:21:13,400 - INFO - Adding interface with subnet_id 70c2ec26-2c40-4fc6-9abc-127846458d3a, port_id None to router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:13,856 - INFO - Waiting for VM ctest-vn1-vm1-28002267 to be up..
2025-08-28 02:21:14,024 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-28 02:21:19,120 - DEBUG - VM is in ACTIVE state now
2025-08-28 02:21:19,120 - INFO - VM name : ctest-vn1-vm1-28002267
2025-08-28 02:21:19,206 - DEBUG - VM ctest-vn1-vm1-28002267 ID is 31f29b14-f94a-441e-98af-b686491c14ea
2025-08-28 02:21:19,232 - DEBUG - VM ctest-vn1-vm1-28002267 launched on Node an-jenkins-deploy-platform-ansible-os-3956-1
2025-08-28 02:21:19,313 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/31f29b14-f94a-441e-98af-b686491c14ea
2025-08-28 02:21:19,614 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/31f29b14-f94a-441e-98af-b686491c14ea
2025-08-28 02:21:19,649 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/aa107a20-939d-406a-b1f2-9bbbcf9e0f1e
2025-08-28 02:21:22,832 - 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 1023ms')
2025-08-28 02:21:22,832 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-28002267 failed!
2025-08-28 02:21:22,845 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-91954293:ctest-vn1-49602187 is 122.78.116.129 and allocation pool is NOT set
2025-08-28 02:21:24,904 - 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.413 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.413/1.928/3.444/1.515 ms')
2025-08-28 02:21:24,904 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-28002267 passed
2025-08-28 02:21:24,970 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:24,970 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-28002267, IP 122.78.116.131, Port 22
2025-08-28 02:21:25,122 - DEBUG - VM ctest-vn1-vm1-28002267 is ready for SSH connections
2025-08-28 02:21:25,122 - INFO - Waiting for VM ctest-vn2-vm1-22420277 to be up..
2025-08-28 02:21:25,193 - DEBUG - VM is in ACTIVE state now
2025-08-28 02:21:25,193 - INFO - VM name : ctest-vn2-vm1-22420277
2025-08-28 02:21:25,263 - DEBUG - VM ctest-vn2-vm1-22420277 ID is f2aef703-e92c-45b1-afef-ed7faff0d4c2
2025-08-28 02:21:25,263 - DEBUG - VM ctest-vn2-vm1-22420277 launched on Node an-jenkins-deploy-platform-ansible-os-3956-2
2025-08-28 02:21:25,335 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/f2aef703-e92c-45b1-afef-ed7faff0d4c2
2025-08-28 02:21:25,345 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/16562eef-0352-4983-9a09-7ce0aab570d9
2025-08-28 02:21:26,543 - 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=4.58 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.818 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.818/2.697/4.576/1.879 ms')
2025-08-28 02:21:26,543 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2-vm1-22420277 passed
2025-08-28 02:21:26,609 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:26,609 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-22420277, IP 106.113.13.195, Port 22
2025-08-28 02:21:26,779 - DEBUG - VM ctest-vn2-vm1-22420277 is ready for SSH connections
2025-08-28 02:21:26,779 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:26,779 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 106.113.13.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-28 02:21:26,779 - DEBUG - ping -s 56 -c 3 -W 1 106.113.13.195
2025-08-28 02:21:30,664 - DEBUG - PING 106.113.13.195 (106.113.13.195): 56 data bytes
--- 106.113.13.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-08-28 02:21:30,664 - WARNING - Ping to IP 106.113.13.195 from VM ctest-vn1-vm1-28002267 failed
2025-08-28 02:21:30,664 - INFO - Adding interface with subnet_id dbd86820-b9d9-406c-98b2-63b981b757db, port_id None to router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:31,039 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:31,040 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 106.113.13.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-28 02:21:31,040 - DEBUG - ping -s 56 -c 3 -W 1 106.113.13.195
2025-08-28 02:21:34,248 - DEBUG - PING 106.113.13.195 (106.113.13.195): 56 data bytes
64 bytes from 106.113.13.195: seq=1 ttl=63 time=4.258 ms
64 bytes from 106.113.13.195: seq=2 ttl=63 time=1.189 ms
--- 106.113.13.195 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.189/2.723/4.258 ms
2025-08-28 02:21:34,249 - WARNING - Ping to IP 106.113.13.195 from VM ctest-vn1-vm1-28002267 failed
2025-08-28 02:21:35,249 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 106.113.13.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-28 02:21:35,250 - DEBUG - ping -s 56 -c 3 -W 1 106.113.13.195
2025-08-28 02:21:37,452 - DEBUG - PING 106.113.13.195 (106.113.13.195): 56 data bytes
64 bytes from 106.113.13.195: seq=0 ttl=63 time=2.720 ms
64 bytes from 106.113.13.195: seq=1 ttl=63 time=1.186 ms
64 bytes from 106.113.13.195: seq=2 ttl=63 time=1.143 ms
--- 106.113.13.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.143/1.683/2.720 ms
2025-08-28 02:21:37,452 - INFO - Ping to IP 106.113.13.195 from VM ctest-vn1-vm1-28002267 passed
2025-08-28 02:21:37,452 - INFO - Deleting interface with subnet_id 70c2ec26-2c40-4fc6-9abc-127846458d3a, port_id None from router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:37,653 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:37,654 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 106.113.13.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-28 02:21:37,654 - DEBUG - ping -s 56 -c 3 -W 1 106.113.13.195
2025-08-28 02:21:40,873 - DEBUG - PING 106.113.13.195 (106.113.13.195): 56 data bytes
--- 106.113.13.195 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-08-28 02:21:40,873 - WARNING - Ping to IP 106.113.13.195 from VM ctest-vn1-vm1-28002267 failed
2025-08-28 02:21:40,873 - INFO - Adding interface with subnet_id 70c2ec26-2c40-4fc6-9abc-127846458d3a, port_id None to router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:41,196 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-28 02:21:41,196 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 106.113.13.195, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-28 02:21:41,196 - DEBUG - ping -s 56 -c 3 -W 1 106.113.13.195
2025-08-28 02:21:43,413 - DEBUG - PING 106.113.13.195 (106.113.13.195): 56 data bytes
64 bytes from 106.113.13.195: seq=0 ttl=63 time=3.157 ms
64 bytes from 106.113.13.195: seq=1 ttl=63 time=1.182 ms
64 bytes from 106.113.13.195: seq=2 ttl=63 time=1.380 ms
--- 106.113.13.195 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.182/1.906/3.157 ms
2025-08-28 02:21:43,413 - INFO - Ping to IP 106.113.13.195 from VM ctest-vn1-vm1-28002267 passed
2025-08-28 02:21:43,413 - INFO - Deleting interface with subnet_id dbd86820-b9d9-406c-98b2-63b981b757db, port_id None from router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:43,682 - INFO - Deleting interface with subnet_id 70c2ec26-2c40-4fc6-9abc-127846458d3a, port_id None from router c6a73710-75c5-4a27-ae54-d9a1f75ca498
2025-08-28 02:21:43,982 - INFO - Deleting VM ctest-vn2-vm1-22420277
2025-08-28 02:21:44,095 - INFO - Deleting VM ctest-vn1-vm1-28002267
2025-08-28 02:21:44,189 - INFO - Deleting VN ctest-vn2-98130771
2025-08-28 02:21:44,257 - DEBUG - VN 1b5cff95-8b86-4145-92fc-e876ded1d1ae still in use: Unable to complete operation on network 1b5cff95-8b86-4145-92fc-e876ded1d1ae. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-da0f5164-5b9d-41c7-ace5-9dce5ddbbce6']
2025-08-28 02:21:44,258 - WARNING - Deleting VN ctest-vn2-98130771 failed..Will retry
2025-08-28 02:21:46,429 - DEBUG - Response for deleting network ()
2025-08-28 02:21:46,429 - INFO - Deleting VN ctest-vn1-49602187
2025-08-28 02:21:46,588 - DEBUG - Response for deleting network ()
2025-08-28 02:21:47,847 - DEBUG - No XMPP flaps were noticed during the test
2025-08-28 02:21:47,847 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:40]
2025-08-28 02:21:47,847 - INFO - --------------------------------------------------------------------------------
2025-08-28 02:21:48,568 - INFO - Deleted project: ctest-TestRouters-91954293, ID : 89aa027a-d607-4eab-831e-2c0bc3015173