2025-09-13 17:08:56,584 - INFO - Domain Default found not creating
2025-09-13 17:08:56,748 - INFO - Project ctest-TestRouters-79404926 not found, creating it
2025-09-13 17:08:57,211 - INFO - Created Project:ctest-TestRouters-79404926, ID : e57d5a49-fa67-4f18-8d08-fc0ec416cbcf
2025-09-13 17:08:58,711 - INFO - ================================================================================
2025-09-13 17:08:58,712 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-13 17:08:58,712 - 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-13 17:08:58,979 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.254': '0'}} with
2025-09-13 17:08:58,979 - INFO - Initial checks done. Running the testcase now
2025-09-13 17:08:58,979 - INFO -
2025-09-13 17:08:59,563 - DEBUG - Response for create_network : {'network': {'id': '0556578a-bea0-4b99-9df3-1342440da92f', 'name': 'ctest-vn1-70217660', 'tenant_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'project_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-79404926', 'ctest-vn1-70217660'], 'port_security_enabled': True, 'description': ''}}
2025-09-13 17:08:59,791 - DEBUG - Response for create_subnet : {'subnet': {'id': 'ba3e6e24-e6e3-45f8-8ea4-a66a6f2e4107', 'name': '', 'tenant_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'network_id': '0556578a-bea0-4b99-9df3-1342440da92f', 'ip_version': 4, 'cidr': '183.44.65.192/26', 'allocation_pools': [{'start': '183.44.65.194', 'end': '183.44.65.254'}], 'gateway_ip': '183.44.65.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '183.44.65.194', 'tags': [], 'project_id': 'e57d5a49fa674f188d08fc0ec416cbcf'}}
2025-09-13 17:08:59,823 - INFO - Created VN ctest-vn1-70217660
2025-09-13 17:08:59,877 - DEBUG - VN ctest-vn1-70217660 UUID is 0556578a-bea0-4b99-9df3-1342440da92f
2025-09-13 17:09:00,221 - DEBUG - Response for create_network : {'network': {'id': '22560294-81e1-4191-ae9b-80886c4faa6f', 'name': 'ctest-vn2-83398078', 'tenant_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'project_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-79404926', 'ctest-vn2-83398078'], 'port_security_enabled': True, 'description': ''}}
2025-09-13 17:09:00,426 - DEBUG - Response for create_subnet : {'subnet': {'id': '2c1aa78a-b05a-4635-8ac7-419cacb7a253', 'name': '', 'tenant_id': 'e57d5a49fa674f188d08fc0ec416cbcf', 'network_id': '22560294-81e1-4191-ae9b-80886c4faa6f', 'ip_version': 4, 'cidr': '83.66.26.128/26', 'allocation_pools': [{'start': '83.66.26.130', 'end': '83.66.26.190'}], 'gateway_ip': '83.66.26.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '83.66.26.130', 'tags': [], 'project_id': 'e57d5a49fa674f188d08fc0ec416cbcf'}}
2025-09-13 17:09:00,446 - INFO - Created VN ctest-vn2-83398078
2025-09-13 17:09:00,501 - DEBUG - VN ctest-vn2-83398078 UUID is 22560294-81e1-4191-ae9b-80886c4faa6f
2025-09-13 17:09:00,681 - DEBUG - Services list from nova: [, , ]
2025-09-13 17:09:01,758 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4104-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4104-1)
2025-09-13 17:09:03,288 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4104-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4104-1)
2025-09-13 17:09:03,456 - INFO - Adding interface with subnet_id ba3e6e24-e6e3-45f8-8ea4-a66a6f2e4107, port_id None to router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:03,795 - INFO - Waiting for VM ctest-vn1-vm1-86693317 to be up..
2025-09-13 17:09:03,924 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-13 17:09:09,012 - DEBUG - VM is in ACTIVE state now
2025-09-13 17:09:09,012 - INFO - VM name : ctest-vn1-vm1-86693317
2025-09-13 17:09:09,092 - DEBUG - VM ctest-vn1-vm1-86693317 ID is fb8038ab-7de3-4ae8-9c5a-a6eff558516e
2025-09-13 17:09:09,114 - DEBUG - VM ctest-vn1-vm1-86693317 launched on Node cn-jenkins-deploy-platform-ansible-os-4104-1
2025-09-13 17:09:09,210 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/fb8038ab-7de3-4ae8-9c5a-a6eff558516e
2025-09-13 17:09:09,524 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/fb8038ab-7de3-4ae8-9c5a-a6eff558516e
2025-09-13 17:09:09,558 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/ffa56d35-52d8-4410-8e54-8d7cf2032356
2025-09-13 17:09:12,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 1025ms')
2025-09-13 17:09:12,833 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-86693317 failed!
2025-09-13 17:09:12,889 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-79404926:ctest-vn1-70217660 is 183.44.65.193 and allocation pool is NOT set
2025-09-13 17:09:14,959 - 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=2.89 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.451 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.451/1.671/2.891/1.220 ms')
2025-09-13 17:09:14,959 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-86693317 passed
2025-09-13 17:09:15,117 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:15,117 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-86693317, IP 183.44.65.195, Port 22
2025-09-13 17:09:15,286 - DEBUG - VM ctest-vn1-vm1-86693317 is ready for SSH connections
2025-09-13 17:09:15,287 - INFO - Waiting for VM ctest-vn2-vm1-95466120 to be up..
2025-09-13 17:09:15,371 - DEBUG - VM is in ACTIVE state now
2025-09-13 17:09:15,371 - INFO - VM name : ctest-vn2-vm1-95466120
2025-09-13 17:09:15,464 - DEBUG - VM ctest-vn2-vm1-95466120 ID is fbdcba41-6c33-4fa0-b97b-7c31be0a10ed
2025-09-13 17:09:15,464 - DEBUG - VM ctest-vn2-vm1-95466120 launched on Node cn-jenkins-deploy-platform-ansible-os-4104-1
2025-09-13 17:09:15,558 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine/fbdcba41-6c33-4fa0-b97b-7c31be0a10ed
2025-09-13 17:09:15,568 - DEBUG - Requesting: http://10.0.0.22:8082/virtual-machine-interface/68b9ff58-baeb-4f84-844f-1fe5cec07a89
2025-09-13 17:09:16,815 - 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=3.82 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.498 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.498/2.159/3.820/1.661 ms')
2025-09-13 17:09:16,815 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-95466120 passed
2025-09-13 17:09:16,965 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:16,965 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-95466120, IP 83.66.26.131, Port 22
2025-09-13 17:09:17,138 - DEBUG - VM ctest-vn2-vm1-95466120 is ready for SSH connections
2025-09-13 17:09:17,138 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:17,138 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 83.66.26.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-13 17:09:17,139 - DEBUG - ping -s 56 -c 3 -W 1 83.66.26.131
2025-09-13 17:09:22,226 - DEBUG - PING 83.66.26.131 (83.66.26.131): 56 data bytes
--- 83.66.26.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-13 17:09:22,226 - WARNING - Ping to IP 83.66.26.131 from VM ctest-vn1-vm1-86693317 failed
2025-09-13 17:09:22,227 - INFO - Adding interface with subnet_id 2c1aa78a-b05a-4635-8ac7-419cacb7a253, port_id None to router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:22,495 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:22,495 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 83.66.26.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-13 17:09:22,495 - DEBUG - ping -s 56 -c 3 -W 1 83.66.26.131
2025-09-13 17:09:25,713 - DEBUG - PING 83.66.26.131 (83.66.26.131): 56 data bytes
64 bytes from 83.66.26.131: seq=1 ttl=63 time=3.272 ms
64 bytes from 83.66.26.131: seq=2 ttl=63 time=1.047 ms
--- 83.66.26.131 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.047/2.159/3.272 ms
2025-09-13 17:09:25,713 - WARNING - Ping to IP 83.66.26.131 from VM ctest-vn1-vm1-86693317 failed
2025-09-13 17:09:26,714 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 83.66.26.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-13 17:09:26,714 - DEBUG - ping -s 56 -c 3 -W 1 83.66.26.131
2025-09-13 17:09:28,932 - DEBUG - PING 83.66.26.131 (83.66.26.131): 56 data bytes
64 bytes from 83.66.26.131: seq=0 ttl=63 time=1.646 ms
64 bytes from 83.66.26.131: seq=1 ttl=63 time=0.840 ms
64 bytes from 83.66.26.131: seq=2 ttl=63 time=0.985 ms
--- 83.66.26.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.840/1.157/1.646 ms
2025-09-13 17:09:28,932 - INFO - Ping to IP 83.66.26.131 from VM ctest-vn1-vm1-86693317 passed
2025-09-13 17:09:28,932 - INFO - Deleting interface with subnet_id ba3e6e24-e6e3-45f8-8ea4-a66a6f2e4107, port_id None from router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:29,053 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:29,053 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 83.66.26.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-13 17:09:29,053 - DEBUG - ping -s 56 -c 3 -W 1 83.66.26.131
2025-09-13 17:09:32,278 - DEBUG - PING 83.66.26.131 (83.66.26.131): 56 data bytes
--- 83.66.26.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-13 17:09:32,278 - WARNING - Ping to IP 83.66.26.131 from VM ctest-vn1-vm1-86693317 failed
2025-09-13 17:09:32,278 - INFO - Adding interface with subnet_id ba3e6e24-e6e3-45f8-8ea4-a66a6f2e4107, port_id None to router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:32,513 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-13 17:09:32,514 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 83.66.26.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.22, gateway password: c0ntrail123
2025-09-13 17:09:32,514 - DEBUG - ping -s 56 -c 3 -W 1 83.66.26.131
2025-09-13 17:09:34,731 - DEBUG - PING 83.66.26.131 (83.66.26.131): 56 data bytes
64 bytes from 83.66.26.131: seq=0 ttl=63 time=1.871 ms
64 bytes from 83.66.26.131: seq=1 ttl=63 time=0.896 ms
64 bytes from 83.66.26.131: seq=2 ttl=63 time=1.294 ms
--- 83.66.26.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.896/1.353/1.871 ms
2025-09-13 17:09:34,731 - INFO - Ping to IP 83.66.26.131 from VM ctest-vn1-vm1-86693317 passed
2025-09-13 17:09:34,731 - INFO - Deleting interface with subnet_id 2c1aa78a-b05a-4635-8ac7-419cacb7a253, port_id None from router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:34,867 - INFO - Deleting interface with subnet_id ba3e6e24-e6e3-45f8-8ea4-a66a6f2e4107, port_id None from router 743c706b-7d89-4104-8e1a-d685e7d76b63
2025-09-13 17:09:35,081 - INFO - Deleting VM ctest-vn2-vm1-95466120
2025-09-13 17:09:35,174 - INFO - Deleting VM ctest-vn1-vm1-86693317
2025-09-13 17:09:35,266 - INFO - Deleting VN ctest-vn2-83398078
2025-09-13 17:09:35,309 - DEBUG - VN 22560294-81e1-4191-ae9b-80886c4faa6f still in use: Unable to complete operation on network 22560294-81e1-4191-ae9b-80886c4faa6f. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-afd5f3ba-36d6-4f7e-b762-54249339842e']
2025-09-13 17:09:35,309 - WARNING - Deleting VN ctest-vn2-83398078 failed..Will retry
2025-09-13 17:09:37,418 - DEBUG - Response for deleting network ()
2025-09-13 17:09:37,419 - INFO - Deleting VN ctest-vn1-70217660
2025-09-13 17:09:37,521 - DEBUG - Response for deleting network ()
2025-09-13 17:09:37,780 - DEBUG - No XMPP flaps were noticed during the test
2025-09-13 17:09:37,780 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:39]
2025-09-13 17:09:37,780 - INFO - --------------------------------------------------------------------------------
2025-09-13 17:09:38,493 - INFO - Deleted project: ctest-TestRouters-79404926, ID : e57d5a49-fa67-4f18-8d08-fc0ec416cbcf