2025-01-04 21:30:59,282 - INFO - Domain Default found not creating
2025-01-04 21:30:59,473 - INFO - Project ctest-TestRoutersBasic-96871482 not found, creating it
2025-01-04 21:31:00,007 - INFO - Created Project:ctest-TestRoutersBasic-96871482, ID : 754351d5-8251-4713-a09f-1af85d2401b3
2025-01-04 21:31:01,780 - INFO - ================================================================================
2025-01-04 21:31:01,780 - INFO - STARTING TEST : test_basic_snat_behavior_without_external_connectivity
2025-01-04 21:31:01,780 - INFO - TEST DESCRIPTION : Create an external network, a router
set router-gateway to external network
launch a private network and attach it to router
validate left vm pinging right vm through Snat
2025-01-04 21:31:02,052 - DEBUG - Nothing to compare xmpp stats {'10.0.0.54': {'10.20.0.8': '0'}} with
2025-01-04 21:31:02,052 - INFO - Initial checks done. Running the testcase now
2025-01-04 21:31:02,052 - INFO -
2025-01-04 21:31:02,764 - INFO - Default SG to be edited for allow all on project: ctest-TestRoutersBasic-96871482
2025-01-04 21:31:02,869 - INFO - Adding rules to the default security group in Project ctest-TestRoutersBasic-96871482
2025-01-04 21:31:03,205 - DEBUG - Reading firewall policy {'fq_name': ['default-domain', 'ctest-TestRoutersBasic-96871482', 'default']}
2025-01-04 21:31:03,559 - DEBUG - Response for create_network : {'network': {'id': 'e464e0ae-4e84-4bb1-95cb-8ecd1e1cc1fd', 'name': 'ctest-vn-71532023', 'tenant_id': '754351d582514713a09f1af85d2401b3', 'project_id': '754351d582514713a09f1af85d2401b3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-96871482', 'ctest-vn-71532023'], 'port_security_enabled': True, 'description': ''}}
2025-01-04 21:31:03,753 - DEBUG - Response for create_subnet : {'subnet': {'id': '38ae36d3-17c5-4b00-8c5b-d3958b9fd08e', 'name': '', 'tenant_id': '754351d582514713a09f1af85d2401b3', 'network_id': 'e464e0ae-4e84-4bb1-95cb-8ecd1e1cc1fd', 'ip_version': 4, 'cidr': '90.58.178.128/26', 'allocation_pools': [{'start': '90.58.178.130', 'end': '90.58.178.190'}], 'gateway_ip': '90.58.178.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '90.58.178.130', 'tags': [], 'project_id': '754351d582514713a09f1af85d2401b3'}}
2025-01-04 21:31:03,776 - INFO - Created VN ctest-vn-71532023
2025-01-04 21:31:03,833 - DEBUG - VN ctest-vn-71532023 UUID is e464e0ae-4e84-4bb1-95cb-8ecd1e1cc1fd
2025-01-04 21:31:04,215 - DEBUG - Response for create_network : {'network': {'id': 'cd397771-563f-43b2-bbc0-06715ede87d2', 'name': 'ctest-ext_vn-39496558', 'tenant_id': '754351d582514713a09f1af85d2401b3', 'project_id': '754351d582514713a09f1af85d2401b3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': True, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestRoutersBasic-96871482', 'ctest-ext_vn-39496558'], 'port_security_enabled': True, 'description': ''}}
2025-01-04 21:31:04,424 - DEBUG - Response for create_subnet : {'subnet': {'id': '15813656-3e74-406a-867e-a41bcd1047f6', 'name': '', 'tenant_id': '754351d582514713a09f1af85d2401b3', 'network_id': 'cd397771-563f-43b2-bbc0-06715ede87d2', 'ip_version': 4, 'cidr': '157.160.191.64/26', 'allocation_pools': [{'start': '157.160.191.66', 'end': '157.160.191.126'}], 'gateway_ip': '157.160.191.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '157.160.191.66', 'tags': [], 'project_id': '754351d582514713a09f1af85d2401b3'}}
2025-01-04 21:31:04,446 - INFO - Created VN ctest-ext_vn-39496558
2025-01-04 21:31:04,505 - DEBUG - VN ctest-ext_vn-39496558 UUID is cd397771-563f-43b2-bbc0-06715ede87d2
2025-01-04 21:31:04,698 - DEBUG - Services list from nova: [, , ]
2025-01-04 21:31:05,799 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-2531-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-2531-1)
2025-01-04 21:31:07,086 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-2531-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-2531-1)
2025-01-04 21:31:07,178 - INFO - Setting gateway for router e906d6d7-5f44-4dde-9453-c0a579ca5ec7 to network cd397771-563f-43b2-bbc0-06715ede87d2
2025-01-04 21:31:07,253 - INFO - Adding interface with subnet_id 38ae36d3-17c5-4b00-8c5b-d3958b9fd08e, port_id None to router e906d6d7-5f44-4dde-9453-c0a579ca5ec7
2025-01-04 21:31:07,672 - INFO - Waiting for VM ctest-TestRoutersBasic-96871482-71564626 to be up..
2025-01-04 21:31:07,882 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-01-04 21:31:12,976 - DEBUG - VM is in ACTIVE state now
2025-01-04 21:31:12,976 - INFO - VM name : ctest-TestRoutersBasic-96871482-71564626
2025-01-04 21:31:13,061 - DEBUG - VM ctest-TestRoutersBasic-96871482-71564626 ID is be373f7c-c220-4120-9df0-e1085cbe7a8e
2025-01-04 21:31:13,085 - DEBUG - VM ctest-TestRoutersBasic-96871482-71564626 launched on Node cn-jenkins-deploy-platform-ansible-os-2531-1
2025-01-04 21:31:13,185 - DEBUG - Requesting: http://10.0.0.54:8082/virtual-machine/be373f7c-c220-4120-9df0-e1085cbe7a8e
2025-01-04 21:31:13,485 - DEBUG - Requesting: http://10.0.0.54:8082/virtual-machine/be373f7c-c220-4120-9df0-e1085cbe7a8e
2025-01-04 21:31:13,523 - DEBUG - Requesting: http://10.0.0.54:8082/virtual-machine-interface/51285506-7e93-4a15-b376-06cafc8d5934
2025-01-04 21:31:16,789 - 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 1014ms')
2025-01-04 21:31:16,789 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-96871482-71564626 failed!
2025-01-04 21:31:16,845 - DEBUG - Gateway for vn default-domain:ctest-TestRoutersBasic-96871482:ctest-vn-71532023 is 90.58.178.129 and allocation pool is NOT set
2025-01-04 21:31:18,914 - 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=4.47 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.79 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.787/3.130/4.473/1.343 ms')
2025-01-04 21:31:18,914 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestRoutersBasic-96871482-71564626 passed
2025-01-04 21:31:19,077 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-01-04 21:31:19,077 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-96871482-71564626, IP 90.58.178.131, Port 22
2025-01-04 21:31:19,243 - DEBUG - VM ctest-TestRoutersBasic-96871482-71564626 is ready for SSH connections
2025-01-04 21:31:19,243 - INFO - Waiting for VM ctest-TestRoutersBasic-96871482-42596773 to be up..
2025-01-04 21:31:19,331 - DEBUG - VM is in ACTIVE state now
2025-01-04 21:31:19,331 - INFO - VM name : ctest-TestRoutersBasic-96871482-42596773
2025-01-04 21:31:19,418 - DEBUG - VM ctest-TestRoutersBasic-96871482-42596773 ID is 7b5dc0bc-8619-4ef3-b63d-ef8f69a28ed2
2025-01-04 21:31:19,418 - DEBUG - VM ctest-TestRoutersBasic-96871482-42596773 launched on Node cn-jenkins-deploy-platform-ansible-os-2531-1
2025-01-04 21:31:19,500 - DEBUG - Requesting: http://10.0.0.54:8082/virtual-machine/7b5dc0bc-8619-4ef3-b63d-ef8f69a28ed2
2025-01-04 21:31:19,510 - DEBUG - Requesting: http://10.0.0.54:8082/virtual-machine-interface/ee16806d-2c1e-4d2a-a184-b42ea225682e
2025-01-04 21:31:20,756 - 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=5.20 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.67 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 = 2.674/3.939/5.204/1.265 ms')
2025-01-04 21:31:20,756 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestRoutersBasic-96871482-42596773 passed
2025-01-04 21:31:20,913 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-01-04 21:31:20,914 - DEBUG - Waiting to SSH to VM ctest-TestRoutersBasic-96871482-42596773, IP 157.160.191.67, Port 22
2025-01-04 21:31:21,073 - DEBUG - VM ctest-TestRoutersBasic-96871482-42596773 is ready for SSH connections
2025-01-04 21:31:21,073 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-01-04 21:31:21,073 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 157.160.191.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.54, gateway password: c0ntrail123
2025-01-04 21:31:21,074 - DEBUG - ping -s 56 -c 3 -W 1 157.160.191.67
2025-01-04 21:31:25,189 - DEBUG - PING 157.160.191.67 (157.160.191.67): 56 data bytes
64 bytes from 157.160.191.67: seq=0 ttl=62 time=7.308 ms
64 bytes from 157.160.191.67: seq=1 ttl=62 time=1.133 ms
64 bytes from 157.160.191.67: seq=2 ttl=62 time=0.989 ms
--- 157.160.191.67 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.989/3.143/7.308 ms
2025-01-04 21:31:25,190 - INFO - Ping to IP 157.160.191.67 from VM ctest-TestRoutersBasic-96871482-71564626 passed
2025-01-04 21:31:25,190 - INFO - Deleting interface with subnet_id 38ae36d3-17c5-4b00-8c5b-d3958b9fd08e, port_id None from router e906d6d7-5f44-4dde-9453-c0a579ca5ec7
2025-01-04 21:31:25,432 - INFO - Deleting VM ctest-TestRoutersBasic-96871482-42596773
2025-01-04 21:31:25,540 - INFO - Deleting VM ctest-TestRoutersBasic-96871482-71564626
2025-01-04 21:31:25,631 - INFO - Deleting VN ctest-ext_vn-39496558
2025-01-04 21:31:25,715 - DEBUG - VN cd397771-563f-43b2-bbc0-06715ede87d2 still in use: Unable to complete operation on network cd397771-563f-43b2-bbc0-06715ede87d2. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-95c5e5a5-335a-42a1-a709-56eaa36ce261']
2025-01-04 21:31:25,715 - WARNING - Deleting VN ctest-ext_vn-39496558 failed..Will retry
2025-01-04 21:31:27,852 - DEBUG - Response for deleting network ()
2025-01-04 21:31:27,852 - INFO - Deleting VN ctest-vn-71532023
2025-01-04 21:31:28,004 - DEBUG - Response for deleting network ()
2025-01-04 21:31:28,265 - DEBUG - No XMPP flaps were noticed during the test
2025-01-04 21:31:28,265 - INFO - END TEST : test_basic_snat_behavior_without_external_connectivity : PASSED[0:00:27]
2025-01-04 21:31:28,265 - INFO - --------------------------------------------------------------------------------
2025-01-04 21:31:29,018 - INFO - Deleted project: ctest-TestRoutersBasic-96871482, ID : 754351d5-8251-4713-a09f-1af85d2401b3