2025-09-11 09:10:41,682 - INFO - Domain Default found not creating
2025-09-11 09:10:41,855 - INFO - Project ctest-TestRouters-61517444 not found, creating it
2025-09-11 09:10:42,355 - INFO - Created Project:ctest-TestRouters-61517444, ID : e9bf7fec-9073-4810-84bc-5c6e63d05d35
2025-09-11 09:10:44,308 - INFO - ================================================================================
2025-09-11 09:10:44,308 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-11 09:10:44,308 - 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 09:10:44,565 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.17': '0'}} with
2025-09-11 09:10:44,566 - INFO - Initial checks done. Running the testcase now
2025-09-11 09:10:44,566 - INFO -
2025-09-11 09:10:45,214 - DEBUG - Response for create_network : {'network': {'id': '9fb1136b-370f-42db-87e4-23c844553186', 'name': 'ctest-vn1-51436532', 'tenant_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'project_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-61517444', 'ctest-vn1-51436532'], 'port_security_enabled': True, 'description': ''}}
2025-09-11 09:10:45,443 - DEBUG - Response for create_subnet : {'subnet': {'id': '15b0e4cf-1b3e-4009-b9de-c85df5a88190', 'name': '', 'tenant_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'network_id': '9fb1136b-370f-42db-87e4-23c844553186', 'ip_version': 4, 'cidr': '83.215.6.128/26', 'allocation_pools': [{'start': '83.215.6.130', 'end': '83.215.6.190'}], 'gateway_ip': '83.215.6.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '83.215.6.130', 'tags': [], 'project_id': 'e9bf7fec9073481084bc5c6e63d05d35'}}
2025-09-11 09:10:45,470 - INFO - Created VN ctest-vn1-51436532
2025-09-11 09:10:45,523 - DEBUG - VN ctest-vn1-51436532 UUID is 9fb1136b-370f-42db-87e4-23c844553186
2025-09-11 09:10:45,881 - DEBUG - Response for create_network : {'network': {'id': 'ba5c48e9-a4b7-4c89-8919-a1d8147f94ec', 'name': 'ctest-vn2-03316117', 'tenant_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'project_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-61517444', 'ctest-vn2-03316117'], 'port_security_enabled': True, 'description': ''}}
2025-09-11 09:10:46,072 - DEBUG - Response for create_subnet : {'subnet': {'id': '27fe6c7c-4896-4630-821b-6023c6711ac6', 'name': '', 'tenant_id': 'e9bf7fec9073481084bc5c6e63d05d35', 'network_id': 'ba5c48e9-a4b7-4c89-8919-a1d8147f94ec', 'ip_version': 4, 'cidr': '187.37.240.64/26', 'allocation_pools': [{'start': '187.37.240.66', 'end': '187.37.240.126'}], 'gateway_ip': '187.37.240.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '187.37.240.66', 'tags': [], 'project_id': 'e9bf7fec9073481084bc5c6e63d05d35'}}
2025-09-11 09:10:46,094 - INFO - Created VN ctest-vn2-03316117
2025-09-11 09:10:46,147 - DEBUG - VN ctest-vn2-03316117 UUID is ba5c48e9-a4b7-4c89-8919-a1d8147f94ec
2025-09-11 09:10:46,334 - DEBUG - Services list from nova: [, , ]
2025-09-11 09:10:47,490 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4086-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4086-1)
2025-09-11 09:10:49,136 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4086-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4086-1)
2025-09-11 09:10:49,234 - INFO - Adding interface with subnet_id 15b0e4cf-1b3e-4009-b9de-c85df5a88190, port_id None to router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:10:49,553 - INFO - Waiting for VM ctest-vn1-vm1-17988834 to be up..
2025-09-11 09:10:49,716 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-11 09:10:54,804 - DEBUG - VM is in ACTIVE state now
2025-09-11 09:10:54,804 - INFO - VM name : ctest-vn1-vm1-17988834
2025-09-11 09:10:54,888 - DEBUG - VM ctest-vn1-vm1-17988834 ID is 29e4e0ab-90de-43a0-913d-75f5565f2ea4
2025-09-11 09:10:54,910 - DEBUG - VM ctest-vn1-vm1-17988834 launched on Node cn-jenkins-deploy-platform-ansible-os-4086-1
2025-09-11 09:10:54,994 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/29e4e0ab-90de-43a0-913d-75f5565f2ea4
2025-09-11 09:10:55,340 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/29e4e0ab-90de-43a0-913d-75f5565f2ea4
2025-09-11 09:10:55,377 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/05e28254-7ca2-4c33-8053-702ce41d843a
2025-09-11 09:10:58,634 - 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 1005ms')
2025-09-11 09:10:58,634 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-17988834 failed!
2025-09-11 09:10:58,691 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-61517444:ctest-vn1-51436532 is 83.215.6.129 and allocation pool is NOT set
2025-09-11 09:11:00,755 - 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.06 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.911 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.911/2.483/4.056/1.572 ms')
2025-09-11 09:11:00,755 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-17988834 passed
2025-09-11 09:11:00,907 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:00,907 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-17988834, IP 83.215.6.131, Port 22
2025-09-11 09:11:01,073 - DEBUG - VM ctest-vn1-vm1-17988834 is ready for SSH connections
2025-09-11 09:11:01,073 - INFO - Waiting for VM ctest-vn2-vm1-14134830 to be up..
2025-09-11 09:11:01,164 - DEBUG - VM is in ACTIVE state now
2025-09-11 09:11:01,165 - INFO - VM name : ctest-vn2-vm1-14134830
2025-09-11 09:11:01,249 - DEBUG - VM ctest-vn2-vm1-14134830 ID is acce3e4b-7c4d-4b9e-beb5-4c1869ef9d7e
2025-09-11 09:11:01,249 - DEBUG - VM ctest-vn2-vm1-14134830 launched on Node cn-jenkins-deploy-platform-ansible-os-4086-1
2025-09-11 09:11:01,331 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine/acce3e4b-7c4d-4b9e-beb5-4c1869ef9d7e
2025-09-11 09:11:01,341 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-machine-interface/03ca87dd-d32b-425f-a86d-ec519bead6ec
2025-09-11 09:11:02,600 - 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=5.14 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.53 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 = 2.534/3.839/5.144/1.305 ms')
2025-09-11 09:11:02,600 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-14134830 passed
2025-09-11 09:11:02,755 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:02,756 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-14134830, IP 187.37.240.67, Port 22
2025-09-11 09:11:02,921 - DEBUG - VM ctest-vn2-vm1-14134830 is ready for SSH connections
2025-09-11 09:11:02,921 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:02,921 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 187.37.240.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-09-11 09:11:02,922 - DEBUG - ping -s 56 -c 3 -W 1 187.37.240.67
2025-09-11 09:11:08,143 - DEBUG - PING 187.37.240.67 (187.37.240.67): 56 data bytes
--- 187.37.240.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-11 09:11:08,143 - WARNING - Ping to IP 187.37.240.67 from VM ctest-vn1-vm1-17988834 failed
2025-09-11 09:11:08,143 - INFO - Adding interface with subnet_id 27fe6c7c-4896-4630-821b-6023c6711ac6, port_id None to router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:11:08,451 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:08,452 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 187.37.240.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-09-11 09:11:08,452 - DEBUG - ping -s 56 -c 3 -W 1 187.37.240.67
2025-09-11 09:11:11,709 - DEBUG - PING 187.37.240.67 (187.37.240.67): 56 data bytes
64 bytes from 187.37.240.67: seq=1 ttl=63 time=3.586 ms
64 bytes from 187.37.240.67: seq=2 ttl=63 time=1.391 ms
--- 187.37.240.67 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.391/2.488/3.586 ms
2025-09-11 09:11:11,709 - WARNING - Ping to IP 187.37.240.67 from VM ctest-vn1-vm1-17988834 failed
2025-09-11 09:11:12,710 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 187.37.240.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-09-11 09:11:12,710 - DEBUG - ping -s 56 -c 3 -W 1 187.37.240.67
2025-09-11 09:11:14,961 - DEBUG - PING 187.37.240.67 (187.37.240.67): 56 data bytes
64 bytes from 187.37.240.67: seq=0 ttl=63 time=1.983 ms
64 bytes from 187.37.240.67: seq=1 ttl=63 time=1.105 ms
64 bytes from 187.37.240.67: seq=2 ttl=63 time=0.846 ms
--- 187.37.240.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.846/1.311/1.983 ms
2025-09-11 09:11:14,961 - INFO - Ping to IP 187.37.240.67 from VM ctest-vn1-vm1-17988834 passed
2025-09-11 09:11:14,961 - INFO - Deleting interface with subnet_id 15b0e4cf-1b3e-4009-b9de-c85df5a88190, port_id None from router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:11:15,092 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:15,092 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 187.37.240.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-09-11 09:11:15,092 - DEBUG - ping -s 56 -c 3 -W 1 187.37.240.67
2025-09-11 09:11:18,363 - DEBUG - PING 187.37.240.67 (187.37.240.67): 56 data bytes
--- 187.37.240.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-11 09:11:18,364 - WARNING - Ping to IP 187.37.240.67 from VM ctest-vn1-vm1-17988834 failed
2025-09-11 09:11:18,364 - INFO - Adding interface with subnet_id 15b0e4cf-1b3e-4009-b9de-c85df5a88190, port_id None to router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:11:18,607 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 09:11:18,607 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 187.37.240.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.254, gateway password: c0ntrail123
2025-09-11 09:11:18,607 - DEBUG - ping -s 56 -c 3 -W 1 187.37.240.67
2025-09-11 09:11:20,854 - DEBUG - PING 187.37.240.67 (187.37.240.67): 56 data bytes
64 bytes from 187.37.240.67: seq=0 ttl=63 time=1.643 ms
64 bytes from 187.37.240.67: seq=1 ttl=63 time=1.007 ms
64 bytes from 187.37.240.67: seq=2 ttl=63 time=0.934 ms
--- 187.37.240.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.934/1.194/1.643 ms
2025-09-11 09:11:20,854 - INFO - Ping to IP 187.37.240.67 from VM ctest-vn1-vm1-17988834 passed
2025-09-11 09:11:20,854 - INFO - Deleting interface with subnet_id 27fe6c7c-4896-4630-821b-6023c6711ac6, port_id None from router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:11:21,004 - INFO - Deleting interface with subnet_id 15b0e4cf-1b3e-4009-b9de-c85df5a88190, port_id None from router 14763c7c-64c8-498c-8fe6-95951d59365a
2025-09-11 09:11:21,209 - INFO - Deleting VM ctest-vn2-vm1-14134830
2025-09-11 09:11:21,310 - INFO - Deleting VM ctest-vn1-vm1-17988834
2025-09-11 09:11:21,397 - INFO - Deleting VN ctest-vn2-03316117
2025-09-11 09:11:21,445 - DEBUG - VN ba5c48e9-a4b7-4c89-8919-a1d8147f94ec still in use: Unable to complete operation on network ba5c48e9-a4b7-4c89-8919-a1d8147f94ec. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-07526ba4-1786-46de-a4e9-8b7f81f76dc3']
2025-09-11 09:11:21,446 - WARNING - Deleting VN ctest-vn2-03316117 failed..Will retry
2025-09-11 09:11:23,583 - DEBUG - Response for deleting network ()
2025-09-11 09:11:23,583 - INFO - Deleting VN ctest-vn1-51436532
2025-09-11 09:11:23,713 - DEBUG - Response for deleting network ()
2025-09-11 09:11:23,978 - DEBUG - No XMPP flaps were noticed during the test
2025-09-11 09:11:23,978 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-09-11 09:11:23,979 - INFO - --------------------------------------------------------------------------------
2025-09-11 09:11:24,732 - INFO - Deleted project: ctest-TestRouters-61517444, ID : e9bf7fec-9073-4810-84bc-5c6e63d05d35