2025-09-18 21:37:17,714 - INFO - Domain Default found not creating
2025-09-18 21:37:17,842 - INFO - Project ctest-TestRouters-14567571 not found, creating it
2025-09-18 21:37:18,270 - INFO - Created Project:ctest-TestRouters-14567571, ID : 53ed5e92-3024-4bb1-be87-e2a9960babc9
2025-09-18 21:37:19,647 - INFO - ================================================================================
2025-09-18 21:37:19,648 - INFO - STARTING TEST : test_basic_router_behavior
2025-09-18 21:37:19,648 - 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-18 21:37:19,912 - DEBUG - Nothing to compare xmpp stats {'10.0.0.49': {'10.20.0.17': '0'}} with
2025-09-18 21:37:19,912 - INFO - Initial checks done. Running the testcase now
2025-09-18 21:37:19,912 - INFO -
2025-09-18 21:37:20,425 - DEBUG - Response for create_network : {'network': {'id': '3c6ea2de-3940-4c92-ae72-4bb61f479d9a', 'name': 'ctest-vn1-89180572', 'tenant_id': '53ed5e9230244bb1be87e2a9960babc9', 'project_id': '53ed5e9230244bb1be87e2a9960babc9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-14567571', 'ctest-vn1-89180572'], 'port_security_enabled': True, 'description': ''}}
2025-09-18 21:37:20,633 - DEBUG - Response for create_subnet : {'subnet': {'id': '47758585-5eff-4bdf-9d39-02f6fa0a3fc0', 'name': '', 'tenant_id': '53ed5e9230244bb1be87e2a9960babc9', 'network_id': '3c6ea2de-3940-4c92-ae72-4bb61f479d9a', 'ip_version': 4, 'cidr': '90.207.97.0/26', 'allocation_pools': [{'start': '90.207.97.2', 'end': '90.207.97.62'}], 'gateway_ip': '90.207.97.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '90.207.97.2', 'tags': [], 'project_id': '53ed5e9230244bb1be87e2a9960babc9'}}
2025-09-18 21:37:20,650 - INFO - Created VN ctest-vn1-89180572
2025-09-18 21:37:20,702 - DEBUG - VN ctest-vn1-89180572 UUID is 3c6ea2de-3940-4c92-ae72-4bb61f479d9a
2025-09-18 21:37:21,006 - DEBUG - Response for create_network : {'network': {'id': '26e65efa-052b-434d-8776-8106c743c286', 'name': 'ctest-vn2-37730631', 'tenant_id': '53ed5e9230244bb1be87e2a9960babc9', 'project_id': '53ed5e9230244bb1be87e2a9960babc9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-14567571', 'ctest-vn2-37730631'], 'port_security_enabled': True, 'description': ''}}
2025-09-18 21:37:21,216 - DEBUG - Response for create_subnet : {'subnet': {'id': '47e1b8d8-f0a6-44b3-b8c4-1ac13e65aa21', 'name': '', 'tenant_id': '53ed5e9230244bb1be87e2a9960babc9', 'network_id': '26e65efa-052b-434d-8776-8106c743c286', 'ip_version': 4, 'cidr': '102.130.190.128/26', 'allocation_pools': [{'start': '102.130.190.130', 'end': '102.130.190.190'}], 'gateway_ip': '102.130.190.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '102.130.190.130', 'tags': [], 'project_id': '53ed5e9230244bb1be87e2a9960babc9'}}
2025-09-18 21:37:21,232 - INFO - Created VN ctest-vn2-37730631
2025-09-18 21:37:21,281 - DEBUG - VN ctest-vn2-37730631 UUID is 26e65efa-052b-434d-8776-8106c743c286
2025-09-18 21:37:21,522 - DEBUG - Services list from nova: [, , ]
2025-09-18 21:37:22,479 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4142-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4142-1)
2025-09-18 21:37:23,616 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4142-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4142-1)
2025-09-18 21:37:23,680 - INFO - Adding interface with subnet_id 47758585-5eff-4bdf-9d39-02f6fa0a3fc0, port_id None to router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:23,953 - INFO - Waiting for VM ctest-vn1-vm1-88288281 to be up..
2025-09-18 21:37:24,048 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-18 21:37:29,115 - DEBUG - VM is in ACTIVE state now
2025-09-18 21:37:29,115 - INFO - VM name : ctest-vn1-vm1-88288281
2025-09-18 21:37:29,184 - DEBUG - VM ctest-vn1-vm1-88288281 ID is ef138dd8-053d-40cb-87cd-5a03dbe6ad9e
2025-09-18 21:37:29,201 - DEBUG - VM ctest-vn1-vm1-88288281 launched on Node cn-jenkins-deploy-platform-ansible-os-4142-1
2025-09-18 21:37:29,265 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/ef138dd8-053d-40cb-87cd-5a03dbe6ad9e
2025-09-18 21:37:29,557 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/ef138dd8-053d-40cb-87cd-5a03dbe6ad9e
2025-09-18 21:37:29,587 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/491ed62a-fdff-400b-a8f4-b30649600fde
2025-09-18 21:37:32,839 - 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 1024ms')
2025-09-18 21:37:32,839 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-88288281 failed!
2025-09-18 21:37:32,890 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-14567571:ctest-vn1-89180572 is 90.207.97.1 and allocation pool is NOT set
2025-09-18 21:37:34,946 - 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.16 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.477 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.477/1.819/3.162/1.342 ms')
2025-09-18 21:37:34,946 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-88288281 passed
2025-09-18 21:37:35,094 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:35,094 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-88288281, IP 90.207.97.3, Port 22
2025-09-18 21:37:35,261 - DEBUG - VM ctest-vn1-vm1-88288281 is ready for SSH connections
2025-09-18 21:37:35,261 - INFO - Waiting for VM ctest-vn2-vm1-20988941 to be up..
2025-09-18 21:37:35,327 - DEBUG - VM is in ACTIVE state now
2025-09-18 21:37:35,327 - INFO - VM name : ctest-vn2-vm1-20988941
2025-09-18 21:37:35,394 - DEBUG - VM ctest-vn2-vm1-20988941 ID is 6a304adf-a024-4d83-bb67-e9092a8b8153
2025-09-18 21:37:35,394 - DEBUG - VM ctest-vn2-vm1-20988941 launched on Node cn-jenkins-deploy-platform-ansible-os-4142-1
2025-09-18 21:37:35,457 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/6a304adf-a024-4d83-bb67-e9092a8b8153
2025-09-18 21:37:35,464 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/a0819579-3384-4a2a-8640-b7fb4de411bf
2025-09-18 21:37:36,697 - 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=2.56 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.429 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.429/1.494/2.559/1.065 ms')
2025-09-18 21:37:36,697 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-20988941 passed
2025-09-18 21:37:36,845 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:36,846 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-20988941, IP 102.130.190.131, Port 22
2025-09-18 21:37:37,001 - DEBUG - VM ctest-vn2-vm1-20988941 is ready for SSH connections
2025-09-18 21:37:37,001 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:37,001 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 102.130.190.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:37:37,002 - DEBUG - ping -s 56 -c 3 -W 1 102.130.190.131
2025-09-18 21:37:41,942 - DEBUG - PING 102.130.190.131 (102.130.190.131): 56 data bytes
--- 102.130.190.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-18 21:37:41,942 - WARNING - Ping to IP 102.130.190.131 from VM ctest-vn1-vm1-88288281 failed
2025-09-18 21:37:41,942 - INFO - Adding interface with subnet_id 47e1b8d8-f0a6-44b3-b8c4-1ac13e65aa21, port_id None to router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:42,195 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:42,196 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 102.130.190.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:37:42,196 - DEBUG - ping -s 56 -c 3 -W 1 102.130.190.131
2025-09-18 21:37:44,392 - DEBUG - PING 102.130.190.131 (102.130.190.131): 56 data bytes
64 bytes from 102.130.190.131: seq=0 ttl=63 time=2.568 ms
64 bytes from 102.130.190.131: seq=1 ttl=63 time=0.872 ms
64 bytes from 102.130.190.131: seq=2 ttl=63 time=0.734 ms
--- 102.130.190.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.734/1.391/2.568 ms
2025-09-18 21:37:44,392 - INFO - Ping to IP 102.130.190.131 from VM ctest-vn1-vm1-88288281 passed
2025-09-18 21:37:44,392 - INFO - Deleting interface with subnet_id 47758585-5eff-4bdf-9d39-02f6fa0a3fc0, port_id None from router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:44,498 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:44,498 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 102.130.190.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:37:44,498 - DEBUG - ping -s 56 -c 3 -W 1 102.130.190.131
2025-09-18 21:37:47,697 - DEBUG - PING 102.130.190.131 (102.130.190.131): 56 data bytes
--- 102.130.190.131 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-09-18 21:37:47,698 - WARNING - Ping to IP 102.130.190.131 from VM ctest-vn1-vm1-88288281 failed
2025-09-18 21:37:47,698 - INFO - Adding interface with subnet_id 47758585-5eff-4bdf-9d39-02f6fa0a3fc0, port_id None to router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:47,896 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-18 21:37:47,896 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 102.130.190.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:37:47,896 - DEBUG - ping -s 56 -c 3 -W 1 102.130.190.131
2025-09-18 21:37:51,091 - DEBUG - PING 102.130.190.131 (102.130.190.131): 56 data bytes
64 bytes from 102.130.190.131: seq=1 ttl=63 time=2.298 ms
64 bytes from 102.130.190.131: seq=2 ttl=63 time=0.724 ms
--- 102.130.190.131 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 0.724/1.511/2.298 ms
2025-09-18 21:37:51,092 - WARNING - Ping to IP 102.130.190.131 from VM ctest-vn1-vm1-88288281 failed
2025-09-18 21:37:52,092 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 102.130.190.131, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.49, gateway password: c0ntrail123
2025-09-18 21:37:52,092 - DEBUG - ping -s 56 -c 3 -W 1 102.130.190.131
2025-09-18 21:37:54,286 - DEBUG - PING 102.130.190.131 (102.130.190.131): 56 data bytes
64 bytes from 102.130.190.131: seq=0 ttl=63 time=1.359 ms
64 bytes from 102.130.190.131: seq=1 ttl=63 time=0.707 ms
64 bytes from 102.130.190.131: seq=2 ttl=63 time=0.860 ms
--- 102.130.190.131 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.707/0.975/1.359 ms
2025-09-18 21:37:54,286 - INFO - Ping to IP 102.130.190.131 from VM ctest-vn1-vm1-88288281 passed
2025-09-18 21:37:54,287 - INFO - Deleting interface with subnet_id 47e1b8d8-f0a6-44b3-b8c4-1ac13e65aa21, port_id None from router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:54,383 - INFO - Deleting interface with subnet_id 47758585-5eff-4bdf-9d39-02f6fa0a3fc0, port_id None from router 0592888e-df33-4639-9944-51f056971c0e
2025-09-18 21:37:54,532 - INFO - Deleting VM ctest-vn2-vm1-20988941
2025-09-18 21:37:54,606 - INFO - Deleting VM ctest-vn1-vm1-88288281
2025-09-18 21:37:54,669 - INFO - Deleting VN ctest-vn2-37730631
2025-09-18 21:37:54,701 - DEBUG - VN 26e65efa-052b-434d-8776-8106c743c286 still in use: Unable to complete operation on network 26e65efa-052b-434d-8776-8106c743c286. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-8088a714-72c7-461e-9d73-27a2b79ca08e']
2025-09-18 21:37:54,701 - WARNING - Deleting VN ctest-vn2-37730631 failed..Will retry
2025-09-18 21:37:56,788 - DEBUG - Response for deleting network ()
2025-09-18 21:37:56,788 - INFO - Deleting VN ctest-vn1-89180572
2025-09-18 21:37:56,876 - DEBUG - Response for deleting network ()
2025-09-18 21:37:57,136 - DEBUG - No XMPP flaps were noticed during the test
2025-09-18 21:37:57,136 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-09-18 21:37:57,136 - INFO - --------------------------------------------------------------------------------
2025-09-18 21:37:57,791 - INFO - Deleted project: ctest-TestRouters-14567571, ID : 53ed5e92-3024-4bb1-be87-e2a9960babc9