2025-11-15 10:29:01,501 - INFO - Domain Default found not creating
2025-11-15 10:29:01,683 - INFO - Project ctest-TestRouters-01399674 not found, creating it
2025-11-15 10:29:02,231 - INFO - Created Project:ctest-TestRouters-01399674, ID : 52df9042-10e6-484e-9159-5dd92cf94a48
2025-11-15 10:29:03,932 - INFO - ================================================================================
2025-11-15 10:29:03,932 - INFO - STARTING TEST : test_basic_router_behavior
2025-11-15 10:29:03,932 - 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-11-15 10:29:04,210 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with
2025-11-15 10:29:04,210 - INFO - Initial checks done. Running the testcase now
2025-11-15 10:29:04,210 - INFO -
2025-11-15 10:29:04,849 - DEBUG - Response for create_network : {'network': {'id': '08b63fed-d78e-435e-9a85-bafe8c1ffc5b', 'name': 'ctest-vn1-60719330', 'tenant_id': '52df904210e6484e91595dd92cf94a48', 'project_id': '52df904210e6484e91595dd92cf94a48', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-01399674', 'ctest-vn1-60719330'], 'port_security_enabled': True, 'description': ''}}
2025-11-15 10:29:05,070 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f6a073e2-40ac-426b-ad39-8bda63b2d303', 'name': '', 'tenant_id': '52df904210e6484e91595dd92cf94a48', 'network_id': '08b63fed-d78e-435e-9a85-bafe8c1ffc5b', 'ip_version': 4, 'cidr': '46.119.48.128/26', 'allocation_pools': [{'start': '46.119.48.130', 'end': '46.119.48.190'}], 'gateway_ip': '46.119.48.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '46.119.48.130', 'tags': [], 'project_id': '52df904210e6484e91595dd92cf94a48'}}
2025-11-15 10:29:05,091 - INFO - Created VN ctest-vn1-60719330
2025-11-15 10:29:05,152 - DEBUG - VN ctest-vn1-60719330 UUID is 08b63fed-d78e-435e-9a85-bafe8c1ffc5b
2025-11-15 10:29:05,496 - DEBUG - Response for create_network : {'network': {'id': '2cf0829b-a949-4541-9640-a7ead5ff411b', 'name': 'ctest-vn2-21718113', 'tenant_id': '52df904210e6484e91595dd92cf94a48', 'project_id': '52df904210e6484e91595dd92cf94a48', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-01399674', 'ctest-vn2-21718113'], 'port_security_enabled': True, 'description': ''}}
2025-11-15 10:29:05,714 - DEBUG - Response for create_subnet : {'subnet': {'id': '1d89f9b1-20ff-44ec-bfe1-5f4f115a6520', 'name': '', 'tenant_id': '52df904210e6484e91595dd92cf94a48', 'network_id': '2cf0829b-a949-4541-9640-a7ead5ff411b', 'ip_version': 4, 'cidr': '176.114.242.64/26', 'allocation_pools': [{'start': '176.114.242.66', 'end': '176.114.242.126'}], 'gateway_ip': '176.114.242.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '176.114.242.66', 'tags': [], 'project_id': '52df904210e6484e91595dd92cf94a48'}}
2025-11-15 10:29:05,737 - INFO - Created VN ctest-vn2-21718113
2025-11-15 10:29:05,789 - DEBUG - VN ctest-vn2-21718113 UUID is 2cf0829b-a949-4541-9640-a7ead5ff411b
2025-11-15 10:29:06,048 - DEBUG - Services list from nova: [, , ]
2025-11-15 10:29:07,514 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4734-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4734-1)
2025-11-15 10:29:08,977 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4734-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4734-1)
2025-11-15 10:29:09,075 - INFO - Adding interface with subnet_id f6a073e2-40ac-426b-ad39-8bda63b2d303, port_id None to router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:09,344 - INFO - Waiting for VM ctest-vn1-vm1-76494639 to be up..
2025-11-15 10:29:09,421 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-11-15 10:29:14,543 - DEBUG - VM is in ACTIVE state now
2025-11-15 10:29:14,543 - INFO - VM name : ctest-vn1-vm1-76494639
2025-11-15 10:29:14,678 - DEBUG - VM ctest-vn1-vm1-76494639 ID is 88bb2cec-44f3-410e-9070-05842553be51
2025-11-15 10:29:14,702 - DEBUG - VM ctest-vn1-vm1-76494639 launched on Node cn-jenkins-deploy-platform-ansible-os-4734-1
2025-11-15 10:29:14,807 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/88bb2cec-44f3-410e-9070-05842553be51
2025-11-15 10:29:15,132 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/88bb2cec-44f3-410e-9070-05842553be51
2025-11-15 10:29:15,193 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/23576ab1-b4f8-4617-b003-e5fd5f0f1b78
2025-11-15 10:29:18,498 - 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 1015ms')
2025-11-15 10:29:18,498 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-76494639 failed!
2025-11-15 10:29:18,570 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-01399674:ctest-vn1-60719330 is 46.119.48.129 and allocation pool is NOT set
2025-11-15 10:29:20,653 - 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.69 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.612 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.612/2.148/3.685/1.536 ms')
2025-11-15 10:29:20,653 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-76494639 passed
2025-11-15 10:29:20,822 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:20,822 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-76494639, IP 46.119.48.131, Port 22
2025-11-15 10:29:21,012 - DEBUG - VM ctest-vn1-vm1-76494639 is ready for SSH connections
2025-11-15 10:29:21,013 - INFO - Waiting for VM ctest-vn2-vm1-55911548 to be up..
2025-11-15 10:29:21,203 - DEBUG - VM is in ACTIVE state now
2025-11-15 10:29:21,203 - INFO - VM name : ctest-vn2-vm1-55911548
2025-11-15 10:29:21,356 - DEBUG - VM ctest-vn2-vm1-55911548 ID is 3b9f0cc5-6eab-4908-9c92-0b2e6d683cae
2025-11-15 10:29:21,356 - DEBUG - VM ctest-vn2-vm1-55911548 launched on Node cn-jenkins-deploy-platform-ansible-os-4734-1
2025-11-15 10:29:21,502 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/3b9f0cc5-6eab-4908-9c92-0b2e6d683cae
2025-11-15 10:29:21,520 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/b6279f7e-6507-4a61-a3c1-45b748d06880
2025-11-15 10:29:22,833 - 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=8.43 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.697 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.697/4.563/8.430/3.866 ms')
2025-11-15 10:29:22,833 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-55911548 passed
2025-11-15 10:29:22,990 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:22,990 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-55911548, IP 176.114.242.67, Port 22
2025-11-15 10:29:23,178 - DEBUG - VM ctest-vn2-vm1-55911548 is ready for SSH connections
2025-11-15 10:29:23,178 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:23,178 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 176.114.242.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-11-15 10:29:23,178 - DEBUG - ping -s 56 -c 3 -W 1 176.114.242.67
2025-11-15 10:29:28,700 - DEBUG - PING 176.114.242.67 (176.114.242.67): 56 data bytes
--- 176.114.242.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-11-15 10:29:28,700 - WARNING - Ping to IP 176.114.242.67 from VM ctest-vn1-vm1-76494639 failed
2025-11-15 10:29:28,700 - INFO - Adding interface with subnet_id 1d89f9b1-20ff-44ec-bfe1-5f4f115a6520, port_id None to router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:29,103 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:29,103 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 176.114.242.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-11-15 10:29:29,103 - DEBUG - ping -s 56 -c 3 -W 1 176.114.242.67
2025-11-15 10:29:31,380 - DEBUG - PING 176.114.242.67 (176.114.242.67): 56 data bytes
64 bytes from 176.114.242.67: seq=0 ttl=63 time=7.716 ms
64 bytes from 176.114.242.67: seq=1 ttl=63 time=1.770 ms
64 bytes from 176.114.242.67: seq=2 ttl=63 time=1.702 ms
--- 176.114.242.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.702/3.729/7.716 ms
2025-11-15 10:29:31,380 - INFO - Ping to IP 176.114.242.67 from VM ctest-vn1-vm1-76494639 passed
2025-11-15 10:29:31,381 - INFO - Deleting interface with subnet_id f6a073e2-40ac-426b-ad39-8bda63b2d303, port_id None from router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:31,576 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:31,576 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 176.114.242.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-11-15 10:29:31,576 - DEBUG - ping -s 56 -c 3 -W 1 176.114.242.67
2025-11-15 10:29:34,910 - DEBUG - PING 176.114.242.67 (176.114.242.67): 56 data bytes
--- 176.114.242.67 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-11-15 10:29:34,910 - WARNING - Ping to IP 176.114.242.67 from VM ctest-vn1-vm1-76494639 failed
2025-11-15 10:29:34,910 - INFO - Adding interface with subnet_id f6a073e2-40ac-426b-ad39-8bda63b2d303, port_id None to router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:35,304 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-11-15 10:29:35,304 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 176.114.242.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-11-15 10:29:35,304 - DEBUG - ping -s 56 -c 3 -W 1 176.114.242.67
2025-11-15 10:29:37,558 - DEBUG - PING 176.114.242.67 (176.114.242.67): 56 data bytes
64 bytes from 176.114.242.67: seq=0 ttl=63 time=1.783 ms
64 bytes from 176.114.242.67: seq=1 ttl=63 time=1.588 ms
64 bytes from 176.114.242.67: seq=2 ttl=63 time=1.908 ms
--- 176.114.242.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.588/1.759/1.908 ms
2025-11-15 10:29:37,558 - INFO - Ping to IP 176.114.242.67 from VM ctest-vn1-vm1-76494639 passed
2025-11-15 10:29:37,558 - INFO - Deleting interface with subnet_id 1d89f9b1-20ff-44ec-bfe1-5f4f115a6520, port_id None from router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:37,806 - INFO - Deleting interface with subnet_id f6a073e2-40ac-426b-ad39-8bda63b2d303, port_id None from router 3d99155c-736e-4ce5-a577-032d5bc0a799
2025-11-15 10:29:37,980 - INFO - Deleting VM ctest-vn2-vm1-55911548
2025-11-15 10:29:38,050 - INFO - Deleting VM ctest-vn1-vm1-76494639
2025-11-15 10:29:38,153 - INFO - Deleting VN ctest-vn2-21718113
2025-11-15 10:29:38,211 - DEBUG - VN 2cf0829b-a949-4541-9640-a7ead5ff411b still in use: Unable to complete operation on network 2cf0829b-a949-4541-9640-a7ead5ff411b. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-3c9b651f-a417-42d0-8c94-62e239de9488']
2025-11-15 10:29:38,211 - WARNING - Deleting VN ctest-vn2-21718113 failed..Will retry
2025-11-15 10:29:40,455 - DEBUG - Response for deleting network ()
2025-11-15 10:29:40,455 - INFO - Deleting VN ctest-vn1-60719330
2025-11-15 10:29:40,571 - DEBUG - Response for deleting network ()
2025-11-15 10:29:40,888 - DEBUG - No XMPP flaps were noticed during the test
2025-11-15 10:29:40,888 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:37]
2025-11-15 10:29:40,888 - INFO - --------------------------------------------------------------------------------
2025-11-15 10:29:41,751 - INFO - Deleted project: ctest-TestRouters-01399674, ID : 52df9042-10e6-484e-9159-5dd92cf94a48