2025-07-31 02:25:22,866 - INFO - Domain Default found not creating
2025-07-31 02:25:23,047 - INFO - Project ctest-TestRouters-00426084 not found, creating it
2025-07-31 02:25:23,529 - INFO - Created Project:ctest-TestRouters-00426084, ID : f4711b74-cded-4106-a028-c6f127589cf3
2025-07-31 02:25:25,161 - INFO - ================================================================================
2025-07-31 02:25:25,162 - INFO - STARTING TEST : test_basic_router_behavior
2025-07-31 02:25:25,162 - 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-07-31 02:25:25,437 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.14': '0'}} with
2025-07-31 02:25:25,437 - INFO - Initial checks done. Running the testcase now
2025-07-31 02:25:25,438 - INFO -
2025-07-31 02:25:26,024 - DEBUG - Response for create_network : {'network': {'id': 'ab99ac75-ef7a-4f6e-8843-d7f421271ca1', 'name': 'ctest-vn1-96537049', 'tenant_id': 'f4711b74cded4106a028c6f127589cf3', 'project_id': 'f4711b74cded4106a028c6f127589cf3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-00426084', 'ctest-vn1-96537049'], 'port_security_enabled': True, 'description': ''}}
2025-07-31 02:25:26,213 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b4b21ba3-c47b-4956-8697-5d816a496bcc', 'name': '', 'tenant_id': 'f4711b74cded4106a028c6f127589cf3', 'network_id': 'ab99ac75-ef7a-4f6e-8843-d7f421271ca1', 'ip_version': 4, 'cidr': '221.141.174.128/26', 'allocation_pools': [{'start': '221.141.174.130', 'end': '221.141.174.190'}], 'gateway_ip': '221.141.174.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '221.141.174.130', 'tags': [], 'project_id': 'f4711b74cded4106a028c6f127589cf3'}}
2025-07-31 02:25:26,233 - INFO - Created VN ctest-vn1-96537049
2025-07-31 02:25:26,286 - DEBUG - VN ctest-vn1-96537049 UUID is ab99ac75-ef7a-4f6e-8843-d7f421271ca1
2025-07-31 02:25:26,617 - DEBUG - Response for create_network : {'network': {'id': '4a3cf5a8-f9f9-44ff-a636-181606ddb343', 'name': 'ctest-vn2-75020074', 'tenant_id': 'f4711b74cded4106a028c6f127589cf3', 'project_id': 'f4711b74cded4106a028c6f127589cf3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRouters-00426084', 'ctest-vn2-75020074'], 'port_security_enabled': True, 'description': ''}}
2025-07-31 02:25:26,832 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f6077599-c1df-45ac-bac1-382601b0305c', 'name': '', 'tenant_id': 'f4711b74cded4106a028c6f127589cf3', 'network_id': '4a3cf5a8-f9f9-44ff-a636-181606ddb343', 'ip_version': 4, 'cidr': '123.41.159.0/26', 'allocation_pools': [{'start': '123.41.159.2', 'end': '123.41.159.62'}], 'gateway_ip': '123.41.159.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '123.41.159.2', 'tags': [], 'project_id': 'f4711b74cded4106a028c6f127589cf3'}}
2025-07-31 02:25:26,854 - INFO - Created VN ctest-vn2-75020074
2025-07-31 02:25:26,906 - DEBUG - VN ctest-vn2-75020074 UUID is 4a3cf5a8-f9f9-44ff-a636-181606ddb343
2025-07-31 02:25:27,093 - DEBUG - Services list from nova: [, , ]
2025-07-31 02:25:28,246 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3729-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3729-1)
2025-07-31 02:25:29,441 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3729-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3729-1)
2025-07-31 02:25:29,528 - INFO - Adding interface with subnet_id b4b21ba3-c47b-4956-8697-5d816a496bcc, port_id None to router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:25:29,899 - INFO - Waiting for VM ctest-vn1-vm1-34903754 to be up..
2025-07-31 02:25:30,025 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-07-31 02:25:35,110 - DEBUG - VM is in ACTIVE state now
2025-07-31 02:25:35,111 - INFO - VM name : ctest-vn1-vm1-34903754
2025-07-31 02:25:35,188 - DEBUG - VM ctest-vn1-vm1-34903754 ID is 56d33582-a45c-446d-91b8-b2223a3a388c
2025-07-31 02:25:35,216 - DEBUG - VM ctest-vn1-vm1-34903754 launched on Node cn-jenkins-deploy-platform-ansible-os-3729-1
2025-07-31 02:25:35,306 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/56d33582-a45c-446d-91b8-b2223a3a388c
2025-07-31 02:25:35,606 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/56d33582-a45c-446d-91b8-b2223a3a388c
2025-07-31 02:25:35,642 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/2523b785-61f1-400b-be67-f61a581a2534
2025-07-31 02:25:38,899 - 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 1006ms')
2025-07-31 02:25:38,899 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-34903754 failed!
2025-07-31 02:25:38,954 - DEBUG - Gateway for vn default-domain:ctest-TestRouters-00426084:ctest-vn1-96537049 is 221.141.174.129 and allocation pool is NOT set
2025-07-31 02:25:41,014 - 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.62 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.41 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 = 1.411/2.515/3.619/1.104 ms')
2025-07-31 02:25:41,014 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-34903754 passed
2025-07-31 02:25:41,170 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:41,170 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-34903754, IP 221.141.174.131, Port 22
2025-07-31 02:25:41,326 - DEBUG - VM ctest-vn1-vm1-34903754 is ready for SSH connections
2025-07-31 02:25:41,326 - INFO - Waiting for VM ctest-vn2-vm1-94591040 to be up..
2025-07-31 02:25:41,421 - DEBUG - VM is in ACTIVE state now
2025-07-31 02:25:41,421 - INFO - VM name : ctest-vn2-vm1-94591040
2025-07-31 02:25:41,503 - DEBUG - VM ctest-vn2-vm1-94591040 ID is 69d4d5ec-b09e-48f5-93ef-a161d961b60e
2025-07-31 02:25:41,503 - DEBUG - VM ctest-vn2-vm1-94591040 launched on Node cn-jenkins-deploy-platform-ansible-os-3729-1
2025-07-31 02:25:41,586 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/69d4d5ec-b09e-48f5-93ef-a161d961b60e
2025-07-31 02:25:41,597 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/d52f66f4-5df8-4d4a-95f3-5b7729016e64
2025-07-31 02:25:42,855 - 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.56 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.575 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.575/2.065/3.555/1.490 ms')
2025-07-31 02:25:42,855 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2-vm1-94591040 passed
2025-07-31 02:25:43,010 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:43,010 - DEBUG - Waiting to SSH to VM ctest-vn2-vm1-94591040, IP 123.41.159.3, Port 22
2025-07-31 02:25:43,170 - DEBUG - VM ctest-vn2-vm1-94591040 is ready for SSH connections
2025-07-31 02:25:43,171 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:43,171 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.41.159.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-07-31 02:25:43,171 - DEBUG - ping -s 56 -c 3 -W 1 123.41.159.3
2025-07-31 02:25:48,257 - DEBUG - PING 123.41.159.3 (123.41.159.3): 56 data bytes
--- 123.41.159.3 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-07-31 02:25:48,257 - WARNING - Ping to IP 123.41.159.3 from VM ctest-vn1-vm1-34903754 failed
2025-07-31 02:25:48,257 - INFO - Adding interface with subnet_id f6077599-c1df-45ac-bac1-382601b0305c, port_id None to router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:25:48,534 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:48,534 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.41.159.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-07-31 02:25:48,534 - DEBUG - ping -s 56 -c 3 -W 1 123.41.159.3
2025-07-31 02:25:51,742 - DEBUG - PING 123.41.159.3 (123.41.159.3): 56 data bytes
64 bytes from 123.41.159.3: seq=1 ttl=63 time=4.049 ms
64 bytes from 123.41.159.3: seq=2 ttl=63 time=1.106 ms
--- 123.41.159.3 ping statistics ---
3 packets transmitted, 2 packets received, 33% packet loss
round-trip min/avg/max = 1.106/2.577/4.049 ms
2025-07-31 02:25:51,742 - WARNING - Ping to IP 123.41.159.3 from VM ctest-vn1-vm1-34903754 failed
2025-07-31 02:25:52,743 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.41.159.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-07-31 02:25:52,743 - DEBUG - ping -s 56 -c 3 -W 1 123.41.159.3
2025-07-31 02:25:54,969 - DEBUG - PING 123.41.159.3 (123.41.159.3): 56 data bytes
64 bytes from 123.41.159.3: seq=0 ttl=63 time=1.821 ms
64 bytes from 123.41.159.3: seq=1 ttl=63 time=0.875 ms
64 bytes from 123.41.159.3: seq=2 ttl=63 time=0.935 ms
--- 123.41.159.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.875/1.210/1.821 ms
2025-07-31 02:25:54,969 - INFO - Ping to IP 123.41.159.3 from VM ctest-vn1-vm1-34903754 passed
2025-07-31 02:25:54,969 - INFO - Deleting interface with subnet_id b4b21ba3-c47b-4956-8697-5d816a496bcc, port_id None from router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:25:55,098 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:55,098 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.41.159.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-07-31 02:25:55,098 - DEBUG - ping -s 56 -c 3 -W 1 123.41.159.3
2025-07-31 02:25:58,313 - DEBUG - PING 123.41.159.3 (123.41.159.3): 56 data bytes
--- 123.41.159.3 ping statistics ---
3 packets transmitted, 0 packets received, 100% packet loss
2025-07-31 02:25:58,314 - WARNING - Ping to IP 123.41.159.3 from VM ctest-vn1-vm1-34903754 failed
2025-07-31 02:25:58,314 - INFO - Adding interface with subnet_id b4b21ba3-c47b-4956-8697-5d816a496bcc, port_id None to router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:25:58,561 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-31 02:25:58,561 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 123.41.159.3, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123
2025-07-31 02:25:58,562 - DEBUG - ping -s 56 -c 3 -W 1 123.41.159.3
2025-07-31 02:26:00,776 - DEBUG - PING 123.41.159.3 (123.41.159.3): 56 data bytes
64 bytes from 123.41.159.3: seq=0 ttl=63 time=1.294 ms
64 bytes from 123.41.159.3: seq=1 ttl=63 time=1.003 ms
64 bytes from 123.41.159.3: seq=2 ttl=63 time=1.003 ms
--- 123.41.159.3 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 1.003/1.100/1.294 ms
2025-07-31 02:26:00,776 - INFO - Ping to IP 123.41.159.3 from VM ctest-vn1-vm1-34903754 passed
2025-07-31 02:26:00,776 - INFO - Deleting interface with subnet_id f6077599-c1df-45ac-bac1-382601b0305c, port_id None from router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:26:00,904 - INFO - Deleting interface with subnet_id b4b21ba3-c47b-4956-8697-5d816a496bcc, port_id None from router 255f8e7a-d9e1-4798-801f-001dad37c647
2025-07-31 02:26:01,126 - INFO - Deleting VM ctest-vn2-vm1-94591040
2025-07-31 02:26:01,207 - INFO - Deleting VM ctest-vn1-vm1-34903754
2025-07-31 02:26:01,284 - INFO - Deleting VN ctest-vn2-75020074
2025-07-31 02:26:01,333 - DEBUG - VN 4a3cf5a8-f9f9-44ff-a636-181606ddb343 still in use: Unable to complete operation on network 4a3cf5a8-f9f9-44ff-a636-181606ddb343. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-7922fbf7-2432-40d0-ab79-23432811cd32']
2025-07-31 02:26:01,333 - WARNING - Deleting VN ctest-vn2-75020074 failed..Will retry
2025-07-31 02:26:03,453 - DEBUG - Response for deleting network ()
2025-07-31 02:26:03,454 - INFO - Deleting VN ctest-vn1-96537049
2025-07-31 02:26:03,573 - DEBUG - Response for deleting network ()
2025-07-31 02:26:03,831 - DEBUG - No XMPP flaps were noticed during the test
2025-07-31 02:26:03,831 - INFO - END TEST : test_basic_router_behavior : PASSED[0:00:38]
2025-07-31 02:26:03,831 - INFO - --------------------------------------------------------------------------------
2025-07-31 02:26:04,538 - INFO - Deleted project: ctest-TestRouters-00426084, ID : f4711b74-cded-4106-a028-c6f127589cf3