2025-09-25 06:50:36,864 - INFO - Domain Default found not creating
2025-09-25 06:50:37,018 - INFO - Project ctest-TestRouters-24485597 not found, creating it
2025-09-25 06:50:37,470 - INFO - Created Project:ctest-TestRouters-24485597, ID : 75592ecd-f7c2-4669-8f50-ad982732a11e
2025-09-25 06:50:38,939 - INFO - ================================================================================
2025-09-25 06:50:38,939 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-25 06:50:38,940 - 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-25 06:50:39,195 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with
2025-09-25 06:50:39,195 - INFO - Initial checks done. Running the testcase now
2025-09-25 06:50:39,195 - INFO -
2025-09-25 06:50:39,762 - DEBUG - Response for create_network : {'network': {'id': 'ff7133e4-b376-4d2c-86f6-03f1ec702315', 'name': 'ctest-vn1-74608610', 'tenant_id': '75592ecdf7c246698f50ad982732a11e', 'project_id': '75592ecdf7c246698f50ad982732a11e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-24485597', 'ctest-vn1-74608610'], 'port_security_enabled': True, 'description': ''}}
2025-09-25 06:50:39,941 - DEBUG - Response for create_subnet : {'subnet': {'id': '6a638969-fb39-43ed-9d4b-c0d902266e9c', 'name': '', 'tenant_id': '75592ecdf7c246698f50ad982732a11e', 'network_id': 'ff7133e4-b376-4d2c-86f6-03f1ec702315', 'ip_version': 4, 'cidr': '143.247.244.64/26', 'allocation_pools': [{'start': '143.247.244.66', 'end': '143.247.244.126'}], 'gateway_ip': '143.247.244.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '143.247.244.66', 'tags': [], 'project_id': '75592ecdf7c246698f50ad982732a11e'}}
2025-09-25 06:50:39,956 - INFO - Created VN ctest-vn1-74608610
2025-09-25 06:50:40,009 - DEBUG - VN ctest-vn1-74608610 UUID is ff7133e4-b376-4d2c-86f6-03f1ec702315
2025-09-25 06:50:40,377 - DEBUG - Response for create_network : {'network': {'id': 'cd7638e2-ec8b-4b23-819a-8b7dfa6656be', 'name': 'ctest-vn2-18029225', 'tenant_id': '75592ecdf7c246698f50ad982732a11e', 'project_id': '75592ecdf7c246698f50ad982732a11e', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-24485597', 'ctest-vn2-18029225'], 'port_security_enabled': True, 'description': ''}}
2025-09-25 06:50:40,585 - DEBUG - Response for create_subnet : {'subnet': {'id': '9e8a7097-6a0a-4d9f-8268-9da48832c2f6', 'name': '', 'tenant_id': '75592ecdf7c246698f50ad982732a11e', 'network_id': 'cd7638e2-ec8b-4b23-819a-8b7dfa6656be', 'ip_version': 4, 'cidr': '142.159.201.64/26', 'allocation_pools': [{'start': '142.159.201.66', 'end': '142.159.201.126'}], 'gateway_ip': '142.159.201.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '142.159.201.66', 'tags': [], 'project_id': '75592ecdf7c246698f50ad982732a11e'}}
2025-09-25 06:50:40,605 - INFO - Created VN ctest-vn2-18029225
2025-09-25 06:50:40,657 - DEBUG - VN ctest-vn2-18029225 UUID is cd7638e2-ec8b-4b23-819a-8b7dfa6656be
2025-09-25 06:50:40,828 - DEBUG - Services list from nova: [, , ]
2025-09-25 06:50:41,868 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4190-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4190-1)
2025-09-25 06:50:43,145 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4190-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4190-1)
2025-09-25 06:50:43,227 - INFO - Adding interface with subnet_id 6a638969-fb39-43ed-9d4b-c0d902266e9c, port_id None to router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:50:43,540 - INFO - Waiting for VM ctest-vn1-vm1-05288352 to be up..
2025-09-25 06:50:43,638 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-25 06:50:48,770 - DEBUG - VM is in ACTIVE state now
2025-09-25 06:50:48,770 - INFO - VM name : ctest-vn1-vm1-05288352
2025-09-25 06:50:48,864 - DEBUG - VM ctest-vn1-vm1-05288352 ID is 642ed07a-6a5d-4f32-9404-e2b9cba4e439
2025-09-25 06:50:48,911 - DEBUG - VM ctest-vn1-vm1-05288352 launched on Node cn-jenkins-deploy-platform-ansible-os-4190-1
2025-09-25 06:50:49,013 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/642ed07a-6a5d-4f32-9404-e2b9cba4e439
2025-09-25 06:50:49,308 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/642ed07a-6a5d-4f32-9404-e2b9cba4e439
2025-09-25 06:50:49,346 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/85388541-82e7-41f2-99ba-e0ec78ce4669
2025-09-25 06:50:52,627 - 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 1025ms')
2025-09-25 06:50:52,627 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-05288352 failed!
2025-09-25 06:50:52,681 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-24485597:ctest-vn1-74608610 is 143.247.244.65 and allocation pool is NOT set
2025-09-25 06:50:54,751 - 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.82 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.548 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.548/2.183/3.819/1.635 ms')
2025-09-25 06:50:54,751 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-05288352 passed
2025-09-25 06:50:54,901 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:50:54,902 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-05288352, IP 143.247.244.67, Port 22
2025-09-25 06:50:55,057 - DEBUG - VM ctest-vn1-vm1-05288352 is ready for SSH connections
2025-09-25 06:50:55,058 - INFO - Waiting for VM ctest-vn2-vm1-70109739 to be up..
2025-09-25 06:50:55,141 - DEBUG - VM is in ACTIVE state now
2025-09-25 06:50:55,141 - INFO - VM name : ctest-vn2-vm1-70109739
2025-09-25 06:50:55,222 - DEBUG - VM ctest-vn2-vm1-70109739 ID is b03d2203-36bf-4fd1-a524-6d846caceff5
2025-09-25 06:50:55,222 - DEBUG - VM ctest-vn2-vm1-70109739 launched on Node cn-jenkins-deploy-platform-ansible-os-4190-1
2025-09-25 06:50:55,294 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/b03d2203-36bf-4fd1-a524-6d846caceff5
2025-09-25 06:50:55,302 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/93d2f50e-5ad0-4bd3-b5ab-45f79266572d
2025-09-25 06:50:56,532 - 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.42 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.07 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 = 1.065/3.244/5.424/2.179 ms')
2025-09-25 06:50:56,533 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-70109739 passed
2025-09-25 06:50:56,689 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:50:56,690 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-70109739, IP 142.159.201.67, Port 22
2025-09-25 06:50:56,860 - DEBUG - VM ctest-vn2-vm1-70109739 is ready for SSH connections
2025-09-25 06:50:56,860 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:50:56,860 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 142.159.201.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-09-25 06:50:56,860 - DEBUG - ping -s 56 -c 3 -W 1 142.159.201.67
2025-09-25 06:51:01,949 - DEBUG - PING 142.159.201.67 (142.159.201.67): 56 data bytes
--- 142.159.201.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-25 06:51:01,949 - WARNING - Ping to IP 142.159.201.67 from VM ctest-vn1-vm1-05288352 failed
2025-09-25 06:51:01,949 - INFO - Adding interface with subnet_id 9e8a7097-6a0a-4d9f-8268-9da48832c2f6, port_id None to router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:51:02,247 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:51:02,248 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 142.159.201.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-09-25 06:51:02,248 - DEBUG - ping -s 56 -c 3 -W 1 142.159.201.67
2025-09-25 06:51:05,463 - DEBUG - PING 142.159.201.67 (142.159.201.67): 56 data bytes
64 bytes from 142.159.201.67: seq=1 ttl=63 time=2.584 ms
64 bytes from 142.159.201.67: seq=2 ttl=63 time=1.108 ms
--- 142.159.201.67 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.108/1.846/2.584 ms
2025-09-25 06:51:05,463 - WARNING - Ping to IP 142.159.201.67 from VM ctest-vn1-vm1-05288352 failed
2025-09-25 06:51:06,464 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 142.159.201.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-09-25 06:51:06,465 - DEBUG - ping -s 56 -c 3 -W 1 142.159.201.67
2025-09-25 06:51:08,682 - DEBUG - PING 142.159.201.67 (142.159.201.67): 56 data bytes
64 bytes from 142.159.201.67: seq=0 ttl=63 time=1.584 ms
64 bytes from 142.159.201.67: seq=1 ttl=63 time=0.927 ms
64 bytes from 142.159.201.67: seq=2 ttl=63 time=0.871 ms
--- 142.159.201.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.871/1.127/1.584 ms
2025-09-25 06:51:08,682 - INFO - Ping to IP 142.159.201.67 from VM ctest-vn1-vm1-05288352 passed
2025-09-25 06:51:08,682 - INFO - Deleting interface with subnet_id 6a638969-fb39-43ed-9d4b-c0d902266e9c, port_id None from router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:51:08,810 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:51:08,810 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 142.159.201.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-09-25 06:51:08,810 - DEBUG - ping -s 56 -c 3 -W 1 142.159.201.67
2025-09-25 06:51:12,016 - DEBUG - PING 142.159.201.67 (142.159.201.67): 56 data bytes
--- 142.159.201.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-25 06:51:12,016 - WARNING - Ping to IP 142.159.201.67 from VM ctest-vn1-vm1-05288352 failed
2025-09-25 06:51:12,017 - INFO - Adding interface with subnet_id 6a638969-fb39-43ed-9d4b-c0d902266e9c, port_id None to router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:51:12,259 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-25 06:51:12,259 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 142.159.201.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-09-25 06:51:12,260 - DEBUG - ping -s 56 -c 3 -W 1 142.159.201.67
2025-09-25 06:51:14,486 - DEBUG - PING 142.159.201.67 (142.159.201.67): 56 data bytes
64 bytes from 142.159.201.67: seq=0 ttl=63 time=1.817 ms
64 bytes from 142.159.201.67: seq=1 ttl=63 time=0.951 ms
64 bytes from 142.159.201.67: seq=2 ttl=63 time=0.851 ms
--- 142.159.201.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.851/1.206/1.817 ms
2025-09-25 06:51:14,486 - INFO - Ping to IP 142.159.201.67 from VM ctest-vn1-vm1-05288352 passed
2025-09-25 06:51:14,486 - INFO - Deleting interface with subnet_id 9e8a7097-6a0a-4d9f-8268-9da48832c2f6, port_id None from router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:51:14,627 - INFO - Deleting interface with subnet_id 6a638969-fb39-43ed-9d4b-c0d902266e9c, port_id None from router fd5b819c-f950-412a-bb85-ec6164a56390
2025-09-25 06:51:14,839 - INFO - Deleting VM ctest-vn2-vm1-70109739
2025-09-25 06:51:14,918 - INFO - Deleting VM ctest-vn1-vm1-05288352
2025-09-25 06:51:14,997 - INFO - Deleting VN ctest-vn2-18029225
2025-09-25 06:51:15,034 - DEBUG - VN cd7638e2-ec8b-4b23-819a-8b7dfa6656be still in use: Unable to complete operation on network cd7638e2-ec8b-4b23-819a-8b7dfa6656be. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-0b9f8e9e-1072-443b-92e0-09c7fea520a0']
2025-09-25 06:51:15,034 - WARNING - Deleting VN ctest-vn2-18029225 failed..Will retry
2025-09-25 06:51:17,155 - DEBUG - Response for deleting network ()
2025-09-25 06:51:17,155 - INFO - Deleting VN ctest-vn1-74608610
2025-09-25 06:51:17,275 - DEBUG - Response for deleting network ()
2025-09-25 06:51:17,531 - DEBUG - No XMPP flaps were noticed during the test
2025-09-25 06:51:17,532 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-09-25 06:51:17,532 - INFO - --------------------------------------------------------------------------------
2025-09-25 06:51:18,224 - INFO - Deleted project: ctest-TestRouters-24485597, ID : 75592ecd-f7c2-4669-8f50-ad982732a11e