2026-02-26 01:48:04,684 - INFO - Reading existing Domain with UUID f6868889-8458-4392-b4ae-21dc8466dc91
2026-02-26 01:48:04,698 - INFO - Using existing domain ['admin_domain'](f6868889-8458-4392-b4ae-21dc8466dc91)
2026-02-26 01:48:05,006 - INFO - Project ctest-TestRouters-61890484 not found, creating it
2026-02-26 01:48:05,689 - INFO - Created Project:ctest-TestRouters-61890484, ID : 53a399db-6c32-4d36-8d81-9d9b053330ee
2026-02-26 01:48:07,692 - INFO - ================================================================================
2026-02-26 01:48:07,692 - INFO - STARTING TEST : test_basic_router_behavior
2026-02-26 01:48:07,692 - 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
2026-02-26 01:48:08,104 - DEBUG - Nothing to compare xmpp stats {'10.0.0.141': {'10.0.0.141': '0'}} with
2026-02-26 01:48:08,104 - INFO - Initial checks done. Running the testcase now
2026-02-26 01:48:08,104 - INFO -
2026-02-26 01:48:09,037 - DEBUG - Response for create_network : {'network': {'id': '211ae0cb-d21c-49b5-94e6-591b678b827e', 'name': 'ctest-vn1-80462543', 'tenant_id': '53a399db6c324d368d819d9b053330ee', 'project_id': '53a399db6c324d368d819d9b053330ee', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestRouters-61890484', 'ctest-vn1-80462543'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}}
2026-02-26 01:48:09,348 - DEBUG - Response for create_subnet : {'subnet': {'id': '849d61e6-192d-45c9-8362-f7dd66fa0dbc', 'name': '', 'tenant_id': '53a399db6c324d368d819d9b053330ee', 'network_id': '211ae0cb-d21c-49b5-94e6-591b678b827e', 'ip_version': 4, 'cidr': '162.118.203.128/26', 'allocation_pools': [{'start': '162.118.203.130', 'end': '162.118.203.190'}], 'gateway_ip': '162.118.203.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2026-02-26T01:48:09.232056', 'updated_at': '2026-02-26T01:48:09.232056', 'dns_server_address': '162.118.203.130', 'tags': [], 'project_id': '53a399db6c324d368d819d9b053330ee'}}
2026-02-26 01:48:09,417 - INFO - Created VN ctest-vn1-80462543
2026-02-26 01:48:09,474 - DEBUG - VN ctest-vn1-80462543 UUID is 211ae0cb-d21c-49b5-94e6-591b678b827e
2026-02-26 01:48:10,024 - DEBUG - Response for create_network : {'network': {'id': 'faaf8441-a85f-4b14-b9c2-ada7e6a71a3e', 'name': 'ctest-vn2-94003517', 'tenant_id': '53a399db6c324d368d819d9b053330ee', 'project_id': '53a399db6c324d368d819d9b053330ee', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestRouters-61890484', 'ctest-vn2-94003517'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}}
2026-02-26 01:48:10,252 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b65decc9-792d-45fb-a9a3-39dc0b280122', 'name': '', 'tenant_id': '53a399db6c324d368d819d9b053330ee', 'network_id': 'faaf8441-a85f-4b14-b9c2-ada7e6a71a3e', 'ip_version': 4, 'cidr': '202.173.28.0/26', 'allocation_pools': [{'start': '202.173.28.2', 'end': '202.173.28.62'}], 'gateway_ip': '202.173.28.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2026-02-26T01:48:10.127427', 'updated_at': '2026-02-26T01:48:10.127427', 'dns_server_address': '202.173.28.2', 'tags': [], 'project_id': '53a399db6c324d368d819d9b053330ee'}}
2026-02-26 01:48:10,324 - INFO - Created VN ctest-vn2-94003517
2026-02-26 01:48:10,382 - DEBUG - VN ctest-vn2-94003517 UUID is faaf8441-a85f-4b14-b9c2-ada7e6a71a3e
2026-02-26 01:48:10,683 - DEBUG - Services list from nova: [, , ]
2026-02-26 01:48:13,098 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-675-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-675-1)
2026-02-26 01:48:15,197 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-675-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-675-1)
2026-02-26 01:48:15,344 - INFO - Adding interface with subnet_id 849d61e6-192d-45c9-8362-f7dd66fa0dbc, port_id None to router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:15,969 - INFO - Waiting for VM ctest-vn1-vm1-52882434 to be up..
2026-02-26 01:48:16,140 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-02-26 01:48:21,316 - DEBUG - VM is in ACTIVE state now
2026-02-26 01:48:21,317 - INFO - VM name : ctest-vn1-vm1-52882434
2026-02-26 01:48:21,489 - DEBUG - VM ctest-vn1-vm1-52882434 ID is cacbd824-73b9-4ca8-b2fe-77b8421bf7b2
2026-02-26 01:48:21,525 - DEBUG - VM ctest-vn1-vm1-52882434 launched on Node cn-jenkins-deploy-platform-juju-os-675-1
2026-02-26 01:48:21,703 - DEBUG - Requesting: https://10.0.0.141:8082/virtual-machine/cacbd824-73b9-4ca8-b2fe-77b8421bf7b2
2026-02-26 01:48:22,057 - DEBUG - Requesting: https://10.0.0.141:8082/virtual-machine/cacbd824-73b9-4ca8-b2fe-77b8421bf7b2
2026-02-26 01:48:22,152 - DEBUG - Requesting: https://10.0.0.141:8082/virtual-machine-interface/2c13abed-249c-4abb-aca9-530086d43350
2026-02-26 01:48:25,636 - 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 1003ms')
2026-02-26 01:48:25,636 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-52882434 failed!
2026-02-26 01:48:25,694 - DEBUG - Gateway for vn admin_domain:ctest-TestRouters-61890484:ctest-vn1-80462543 is 162.118.203.129 and allocation pool is NOT set
2026-02-26 01:48:27,802 - 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=13.0 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.03 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 = 1.029/6.994/12.959/5.965 ms')
2026-02-26 01:48:27,802 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-52882434 passed
2026-02-26 01:48:27,958 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:27,958 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-52882434, IP 162.118.203.131, Port 22
2026-02-26 01:48:28,184 - DEBUG - VM ctest-vn1-vm1-52882434 is ready for SSH connections
2026-02-26 01:48:28,184 - INFO - Waiting for VM ctest-vn2-vm1-79957385 to be up..
2026-02-26 01:48:28,367 - DEBUG - VM is in ACTIVE state now
2026-02-26 01:48:28,367 - INFO - VM name : ctest-vn2-vm1-79957385
2026-02-26 01:48:28,522 - DEBUG - VM ctest-vn2-vm1-79957385 ID is 7829e913-e3f9-4b78-b462-5e6a94dfba4b
2026-02-26 01:48:28,523 - DEBUG - VM ctest-vn2-vm1-79957385 launched on Node cn-jenkins-deploy-platform-juju-os-675-1
2026-02-26 01:48:28,804 - DEBUG - Requesting: https://10.0.0.141:8082/virtual-machine/7829e913-e3f9-4b78-b462-5e6a94dfba4b
2026-02-26 01:48:28,859 - DEBUG - Requesting: https://10.0.0.141:8082/virtual-machine-interface/43c55053-1582-4e7e-b824-0912abf36a52
2026-02-26 01:48:30,347 - 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.97 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=6.60 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1004ms\r\nrtt min/avg/max/mdev = 3.968/5.284/6.600/1.316 ms')
2026-02-26 01:48:30,347 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-79957385 passed
2026-02-26 01:48:30,510 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:30,510 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-79957385, IP 202.173.28.3, Port 22
2026-02-26 01:48:30,728 - DEBUG - VM ctest-vn2-vm1-79957385 is ready for SSH connections
2026-02-26 01:48:30,728 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:30,728 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 202.173.28.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.141, gateway password: c0ntrail123
2026-02-26 01:48:30,728 - DEBUG - ping -s 56 -c 3 -W 1 202.173.28.3
2026-02-26 01:48:35,439 - DEBUG - PING 202.173.28.3 (202.173.28.3): 56 data bytes
--- 202.173.28.3 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-02-26 01:48:35,439 - WARNING - Ping to IP 202.173.28.3 from VM ctest-vn1-vm1-52882434 failed
2026-02-26 01:48:35,439 - INFO - Adding interface with subnet_id b65decc9-792d-45fb-a9a3-39dc0b280122, port_id None to router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:35,873 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:35,874 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 202.173.28.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.141, gateway password: c0ntrail123
2026-02-26 01:48:35,874 - DEBUG - ping -s 56 -c 3 -W 1 202.173.28.3
2026-02-26 01:48:39,090 - DEBUG - PING 202.173.28.3 (202.173.28.3): 56 data bytes
64 bytes from 202.173.28.3: seq=1 ttl=63 time=3.102 ms
64 bytes from 202.173.28.3: seq=2 ttl=63 time=1.211 ms
--- 202.173.28.3 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.211/2.156/3.102 ms
2026-02-26 01:48:39,090 - WARNING - Ping to IP 202.173.28.3 from VM ctest-vn1-vm1-52882434 failed
2026-02-26 01:48:40,091 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 202.173.28.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.141, gateway password: c0ntrail123
2026-02-26 01:48:40,091 - DEBUG - ping -s 56 -c 3 -W 1 202.173.28.3
2026-02-26 01:48:42,327 - DEBUG - PING 202.173.28.3 (202.173.28.3): 56 data bytes
64 bytes from 202.173.28.3: seq=0 ttl=63 time=1.624 ms
64 bytes from 202.173.28.3: seq=1 ttl=63 time=1.768 ms
64 bytes from 202.173.28.3: seq=2 ttl=63 time=1.197 ms
--- 202.173.28.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.197/1.529/1.768 ms
2026-02-26 01:48:42,327 - INFO - Ping to IP 202.173.28.3 from VM ctest-vn1-vm1-52882434 passed
2026-02-26 01:48:42,327 - INFO - Deleting interface with subnet_id 849d61e6-192d-45c9-8362-f7dd66fa0dbc, port_id None from router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:42,601 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:42,601 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 202.173.28.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.141, gateway password: c0ntrail123
2026-02-26 01:48:42,601 - DEBUG - ping -s 56 -c 3 -W 1 202.173.28.3
2026-02-26 01:48:45,818 - DEBUG - PING 202.173.28.3 (202.173.28.3): 56 data bytes
--- 202.173.28.3 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2026-02-26 01:48:45,818 - WARNING - Ping to IP 202.173.28.3 from VM ctest-vn1-vm1-52882434 failed
2026-02-26 01:48:45,818 - INFO - Adding interface with subnet_id 849d61e6-192d-45c9-8362-f7dd66fa0dbc, port_id None to router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:46,232 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-02-26 01:48:46,233 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 202.173.28.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.141, gateway password: c0ntrail123
2026-02-26 01:48:46,233 - DEBUG - ping -s 56 -c 3 -W 1 202.173.28.3
2026-02-26 01:48:48,492 - DEBUG - PING 202.173.28.3 (202.173.28.3): 56 data bytes
64 bytes from 202.173.28.3: seq=0 ttl=63 time=1.847 ms
64 bytes from 202.173.28.3: seq=1 ttl=63 time=1.063 ms
64 bytes from 202.173.28.3: seq=2 ttl=63 time=1.313 ms
--- 202.173.28.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.063/1.407/1.847 ms
2026-02-26 01:48:48,492 - INFO - Ping to IP 202.173.28.3 from VM ctest-vn1-vm1-52882434 passed
2026-02-26 01:48:48,493 - INFO - Deleting interface with subnet_id b65decc9-792d-45fb-a9a3-39dc0b280122, port_id None from router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:48,742 - INFO - Deleting interface with subnet_id 849d61e6-192d-45c9-8362-f7dd66fa0dbc, port_id None from router 6cc2fafa-6440-463a-a4c4-1111cb2efb80
2026-02-26 01:48:49,170 - INFO - Deleting VM ctest-vn2-vm1-79957385
2026-02-26 01:48:49,327 - INFO - Deleting VM ctest-vn1-vm1-52882434
2026-02-26 01:48:49,463 - INFO - Deleting VN ctest-vn2-94003517
2026-02-26 01:48:49,643 - DEBUG - VN faaf8441-a85f-4b14-b9c2-ada7e6a71a3e still in use: Unable to complete operation on network faaf8441-a85f-4b14-b9c2-ada7e6a71a3e. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-152fa52a-cf86-43d5-bf24-de3f532d9a06']
2026-02-26 01:48:49,643 - WARNING - Deleting VN ctest-vn2-94003517 failed..Will retry
2026-02-26 01:48:51,863 - DEBUG - Response for deleting network ()
2026-02-26 01:48:51,863 - INFO - Deleting VN ctest-vn1-80462543
2026-02-26 01:48:52,092 - DEBUG - Response for deleting network ()
2026-02-26 01:48:52,491 - DEBUG - No XMPP flaps were noticed during the test
2026-02-26 01:48:52,491 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:45]
2026-02-26 01:48:52,492 - INFO - --------------------------------------------------------------------------------
2026-02-26 01:48:53,308 - INFO - Deleted project: ctest-TestRouters-61890484, ID : 53a399db-6c32-4d36-8d81-9d9b053330ee