2025-04-14 18:56:04,841 - INFO - Domain Default found not creating 2025-04-14 18:56:05,022 - INFO - Project ctest-TestBasicPolicy-77510113 not found, creating it 2025-04-14 18:56:05,528 - INFO - Created Project:ctest-TestBasicPolicy-77510113, ID : 145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:07,123 - INFO - ================================================================================ 2025-04-14 18:56:07,123 - INFO - STARTING TEST : test_basic_policy_allow_deny 2025-04-14 18:56:07,123 - INFO - TEST DESCRIPTION : Create 2 Vns and allow icmp traffic between them and validate with pings Update the policy to deny the same traffic Check that pings fail 2025-04-14 18:56:07,384 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.17': '0'}} with 2025-04-14 18:56:07,384 - INFO - Initial checks done. Running the testcase now 2025-04-14 18:56:07,384 - INFO - 2025-04-14 18:56:08,037 - DEBUG - Response for create_network : {'network': {'id': '445daa2c-5af6-4543-9c11-1706281f6f74', 'name': 'ctest-vn-65456290', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'project_id': '145b31fd5fe64da693be9ffd78baa033', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-vn-65456290'], 'port_security_enabled': True, 'description': ''}} 2025-04-14 18:56:08,272 - DEBUG - Response for create_subnet : {'subnet': {'id': '3cf1bc50-7c0f-4f47-a6a6-09e0fb48c7b3', 'name': '', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'network_id': '445daa2c-5af6-4543-9c11-1706281f6f74', 'ip_version': 4, 'cidr': '76.34.78.128/26', 'allocation_pools': [{'start': '76.34.78.130', 'end': '76.34.78.190'}], 'gateway_ip': '76.34.78.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '76.34.78.130', 'tags': [], 'project_id': '145b31fd5fe64da693be9ffd78baa033'}} 2025-04-14 18:56:08,293 - INFO - Created VN ctest-vn-65456290 2025-04-14 18:56:08,348 - DEBUG - VN ctest-vn-65456290 UUID is 445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:08,685 - DEBUG - Response for create_network : {'network': {'id': '249cb6c0-c0a1-405b-992b-d4291b096b18', 'name': 'ctest-vn-88331772', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'project_id': '145b31fd5fe64da693be9ffd78baa033', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-vn-88331772'], 'port_security_enabled': True, 'description': ''}} 2025-04-14 18:56:08,915 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a128824b-ecda-4cc4-a069-a5fed3454e8f', 'name': '', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'network_id': '249cb6c0-c0a1-405b-992b-d4291b096b18', 'ip_version': 4, 'cidr': '60.87.177.64/26', 'allocation_pools': [{'start': '60.87.177.66', 'end': '60.87.177.126'}], 'gateway_ip': '60.87.177.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '60.87.177.66', 'tags': [], 'project_id': '145b31fd5fe64da693be9ffd78baa033'}} 2025-04-14 18:56:08,936 - INFO - Created VN ctest-vn-88331772 2025-04-14 18:56:08,991 - DEBUG - VN ctest-vn-88331772 UUID is 249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:09,124 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None] 2025-04-14 18:56:09,469 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '445daa2c-5af6-4543-9c11-1706281f6f74', 'name': 'ctest-vn-65456290', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'project_id': '145b31fd5fe64da693be9ffd78baa033', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['3cf1bc50-7c0f-4f47-a6a6-09e0fb48c7b3'], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-vn-65456290'], 'policys': [['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-policy-allow-all-64497121']], 'subnet_ipam': [{'subnet_cidr': '76.34.78.128/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': ''}} 2025-04-14 18:56:09,785 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '249cb6c0-c0a1-405b-992b-d4291b096b18', 'name': 'ctest-vn-88331772', 'tenant_id': '145b31fd5fe64da693be9ffd78baa033', 'project_id': '145b31fd5fe64da693be9ffd78baa033', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['a128824b-ecda-4cc4-a069-a5fed3454e8f'], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-vn-88331772'], 'policys': [['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-policy-allow-all-64497121']], 'subnet_ipam': [{'subnet_cidr': '60.87.177.64/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': ''}} 2025-04-14 18:56:09,955 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:10,281 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:10,315 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:10,332 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:10,415 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,427 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,438 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:10,448 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:10,457 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/eb2432d1-7881-43f1-9b0c-3b502a857fe5 2025-04-14 18:56:10,466 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-04-14 18:56:10,466 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,478 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:10,497 - INFO - Verified VN network id 8 for VN 445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,497 - INFO - Verifications in API Server for VN ctest-vn-65456290 passed 2025-04-14 18:56:10,498 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,509 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:10,520 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:10,530 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/eb2432d1-7881-43f1-9b0c-3b502a857fe5 2025-04-14 18:56:10,544 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-77510113', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4926280674894562627', 'uuid-lslong': '11245795059731230580'}, 'enable': 'true', 'created': '2025-04-14T18:56:07', 'last-modified': '2025-04-14T18:56:09', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.110848'} 2025-04-14 18:56:10,552 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-04-14 18:56:10,552 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-65456290 passed 2025-04-14 18:56:10,552 - DEBUG - ====Verifying policy data for ctest-vn-65456290 in API_Server ====== 2025-04-14 18:56:10,552 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:10,559 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:10,573 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:10,653 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/445daa2c-5af6-4543-9c11-1706281f6f74 2025-04-14 18:56:10,664 - DEBUG - ==>Verifying data for policy with id: d27b5a04-c9dc-46ed-b041-9392b322e0fd, fqn: ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-policy-allow-all-64497121'] 2025-04-14 18:56:10,664 - INFO - VN ctest-vn-65456290 Policy verification: verify_vn_policy_in_api_server, status: True 2025-04-14 18:56:10,664 - DEBUG - Verifying the vn in opserver 2025-04-14 18:56:10,664 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290 virtual network link through opserver 10.0.0.50 2025-04-14 18:56:10,664 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-04-14 18:56:10,972 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-04-14 18:56:11,040 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290?flat'} 2025-04-14 18:56:11,040 - INFO - Validated that VN default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290 is found in opserver 2025-04-14 18:56:11,056 - DEBUG - Do not have enough data to verify VN in agent 2025-04-14 18:56:11,064 - DEBUG - VRF ids for VN ctest-vn-65456290: {} 2025-04-14 18:56:11,064 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:11,072 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:11,088 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:11,185 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,202 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,213 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:11,223 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:11,232 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/66100b03-a8d0-4b8d-81e0-0a22e46f7a6f 2025-04-14 18:56:11,240 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-04-14 18:56:11,240 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,251 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:11,270 - INFO - Verified VN network id 9 for VN 249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,270 - INFO - Verifications in API Server for VN ctest-vn-88331772 passed 2025-04-14 18:56:11,270 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,282 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:11,291 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:11,303 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/66100b03-a8d0-4b8d-81e0-0a22e46f7a6f 2025-04-14 18:56:11,325 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-77510113', 'owner-access': '7', 'group': 'admin', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '2638184420714037339', 'uuid-lslong': '11037148584813882136'}, 'enable': 'true', 'created': '2025-04-14T18:56:08', 'last-modified': '2025-04-14T18:56:09', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.607976'} 2025-04-14 18:56:11,333 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-04-14 18:56:11,333 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-88331772 passed 2025-04-14 18:56:11,333 - DEBUG - ====Verifying policy data for ctest-vn-88331772 in API_Server ====== 2025-04-14 18:56:11,333 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:11,341 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:11,356 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:11,434 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/249cb6c0-c0a1-405b-992b-d4291b096b18 2025-04-14 18:56:11,446 - DEBUG - ==>Verifying data for policy with id: d27b5a04-c9dc-46ed-b041-9392b322e0fd, fqn: ['default-domain', 'ctest-TestBasicPolicy-77510113', 'ctest-policy-allow-all-64497121'] 2025-04-14 18:56:11,446 - INFO - VN ctest-vn-88331772 Policy verification: verify_vn_policy_in_api_server, status: True 2025-04-14 18:56:11,446 - DEBUG - Verifying the vn in opserver 2025-04-14 18:56:11,446 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772 virtual network link through opserver 10.0.0.50 2025-04-14 18:56:11,446 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-04-14 18:56:11,459 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772?flat'} 2025-04-14 18:56:11,459 - INFO - Validated that VN default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-88331772 is found in opserver 2025-04-14 18:56:11,474 - DEBUG - Do not have enough data to verify VN in agent 2025-04-14 18:56:11,480 - DEBUG - VRF ids for VN ctest-vn-88331772: {} 2025-04-14 18:56:11,550 - DEBUG - Services list from nova: [, , ] 2025-04-14 18:56:12,808 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3107-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3107-1) 2025-04-14 18:56:14,083 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-3107-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-3107-1) 2025-04-14 18:56:14,083 - INFO - Waiting for VM ctest-TestBasicPolicy-77510113-25909829 to be up.. 2025-04-14 18:56:14,203 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-04-14 18:56:19,301 - DEBUG - VM is in ACTIVE state now 2025-04-14 18:56:19,301 - INFO - VM name : ctest-TestBasicPolicy-77510113-25909829 2025-04-14 18:56:19,402 - DEBUG - VM ctest-TestBasicPolicy-77510113-25909829 ID is d20368f1-b35f-4aed-97c4-d2f65353387a 2025-04-14 18:56:19,425 - DEBUG - VM ctest-TestBasicPolicy-77510113-25909829 launched on Node cn-jenkins-deploy-platform-ansible-os-3107-1 2025-04-14 18:56:19,542 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/d20368f1-b35f-4aed-97c4-d2f65353387a 2025-04-14 18:56:19,555 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/82117bbb-227c-427a-868c-06015a9bd3ff 2025-04-14 18:56:22,807 - 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 1030ms') 2025-04-14 18:56:22,807 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicPolicy-77510113-25909829 failed! 2025-04-14 18:56:22,867 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicy-77510113:ctest-vn-65456290 is 76.34.78.129 and allocation pool is NOT set 2025-04-14 18:56:24,933 - 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=10.1 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.07 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 = 3.066/6.561/10.056/3.495 ms') 2025-04-14 18:56:24,933 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicPolicy-77510113-25909829 passed 2025-04-14 18:56:25,092 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-04-14 18:56:25,092 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-77510113-25909829, IP 76.34.78.131, Port 22 2025-04-14 18:56:25,157 - DEBUG - Error on ssh to cirros@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-04-14 18:56:25,263 - DEBUG - VM ctest-TestBasicPolicy-77510113-25909829 is NOT ready for SSH connections, VM status: ACTIVE 2025-04-14 18:56:30,264 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-04-14 18:56:30,264 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-77510113-25909829, IP 76.34.78.131, Port 22 2025-04-14 18:56:30,419 - DEBUG - VM ctest-TestBasicPolicy-77510113-25909829 is ready for SSH connections 2025-04-14 18:56:30,419 - INFO - Waiting for VM ctest-TestBasicPolicy-77510113-23911422 to be up.. 2025-04-14 18:56:30,512 - DEBUG - VM is in ACTIVE state now 2025-04-14 18:56:30,512 - INFO - VM name : ctest-TestBasicPolicy-77510113-23911422 2025-04-14 18:56:30,603 - DEBUG - VM ctest-TestBasicPolicy-77510113-23911422 ID is 0c09cd6b-b90b-4cbc-891f-e8a885818482 2025-04-14 18:56:30,603 - DEBUG - VM ctest-TestBasicPolicy-77510113-23911422 launched on Node cn-jenkins-deploy-platform-ansible-os-3107-1 2025-04-14 18:56:30,697 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine/0c09cd6b-b90b-4cbc-891f-e8a885818482 2025-04-14 18:56:30,707 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-machine-interface/8125920f-08b2-4c9e-80f7-e08f3f19f1a6 2025-04-14 18:56:31,953 - 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.35 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.540 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.540/1.943/3.346/1.403 ms') 2025-04-14 18:56:31,953 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestBasicPolicy-77510113-23911422 passed 2025-04-14 18:56:32,111 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-04-14 18:56:32,112 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-77510113-23911422, IP 60.87.177.67, Port 22 2025-04-14 18:56:32,286 - DEBUG - VM ctest-TestBasicPolicy-77510113-23911422 is ready for SSH connections 2025-04-14 18:56:32,286 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-04-14 18:56:32,287 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 60.87.177.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2025-04-14 18:56:32,287 - DEBUG - ping -s 56 -c 3 -W 1 60.87.177.67 2025-04-14 18:56:36,377 - DEBUG - PING 60.87.177.67 (60.87.177.67): 56 data bytes 64 bytes from 60.87.177.67: seq=0 ttl=63 time=4.966 ms 64 bytes from 60.87.177.67: seq=1 ttl=63 time=1.374 ms 64 bytes from 60.87.177.67: seq=2 ttl=63 time=1.112 ms --- 60.87.177.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 1.112/2.484/4.966 ms 2025-04-14 18:56:36,377 - INFO - Ping to IP 60.87.177.67 from VM ctest-TestBasicPolicy-77510113-25909829 passed 2025-04-14 18:56:36,567 - DEBUG - Policy Update Response {"network-policy": {"uuid": "d27b5a04-c9dc-46ed-b041-9392b322e0fd", "href": "http://10.0.0.50:8082/network-policy/d27b5a04-c9dc-46ed-b041-9392b322e0fd"}} 2025-04-14 18:56:36,567 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-04-14 18:56:36,567 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 60.87.177.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.50, gateway password: c0ntrail123 2025-04-14 18:56:36,567 - DEBUG - ping -s 56 -c 3 -W 1 60.87.177.67 2025-04-14 18:56:39,790 - DEBUG - PING 60.87.177.67 (60.87.177.67): 56 data bytes --- 60.87.177.67 ping statistics --- 3 packets transmitted, 0 packets received, 100% packet loss 2025-04-14 18:56:39,790 - WARNING - Ping to IP 60.87.177.67 from VM ctest-TestBasicPolicy-77510113-25909829 failed 2025-04-14 18:56:39,790 - INFO - Deleting VM ctest-TestBasicPolicy-77510113-23911422 2025-04-14 18:56:39,881 - INFO - Deleting VM ctest-TestBasicPolicy-77510113-25909829 2025-04-14 18:56:40,350 - INFO - Deleted policy ctest-policy-allow-all-64497121 2025-04-14 18:56:40,351 - INFO - Deleting VN ctest-vn-88331772 2025-04-14 18:56:40,417 - DEBUG - VN 249cb6c0-c0a1-405b-992b-d4291b096b18 still in use: Unable to complete operation on network 249cb6c0-c0a1-405b-992b-d4291b096b18. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-252da7c5-01e0-44a6-b01c-73f8dd8f99d1'] 2025-04-14 18:56:40,417 - WARNING - Deleting VN ctest-vn-88331772 failed..Will retry 2025-04-14 18:56:42,592 - DEBUG - Response for deleting network () 2025-04-14 18:56:42,592 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/6f701371-bc5c-4b5f-b50c-3b0eb9ea4404 2025-04-14 18:56:42,604 - DEBUG - Response Code: 404 2025-04-14 18:56:42,604 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:42,617 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:42,640 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:42,727 - INFO - Validated that VN ctest-vn-88331772 is not found in API Server 2025-04-14 18:56:42,740 - DEBUG - VN ctest-vn-88331772 is not present in Agent 10.0.0.50 2025-04-14 18:56:42,740 - INFO - Validated that VN ctest-vn-88331772 is not in any agent 2025-04-14 18:56:42,760 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-88331772 info 2025-04-14 18:56:42,760 - INFO - Deleting VN ctest-vn-65456290 2025-04-14 18:56:42,899 - DEBUG - Response for deleting network () 2025-04-14 18:56:42,899 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/0db97e45-08cb-4600-ba98-268d6e1a3e5c 2025-04-14 18:56:42,911 - DEBUG - Response Code: 404 2025-04-14 18:56:42,912 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-04-14 18:56:42,920 - DEBUG - Requesting: http://10.0.0.50:8082/domain/db564364-1b1c-41fd-9790-47fbd54991fd 2025-04-14 18:56:42,978 - DEBUG - Requesting: http://10.0.0.50:8082/project/145b31fd-5fe6-4da6-93be-9ffd78baa033 2025-04-14 18:56:43,085 - INFO - Validated that VN ctest-vn-65456290 is not found in API Server 2025-04-14 18:56:43,100 - DEBUG - VN ctest-vn-65456290 is not present in Agent 10.0.0.50 2025-04-14 18:56:43,100 - INFO - Validated that VN ctest-vn-65456290 is not in any agent 2025-04-14 18:56:43,136 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-65456290 info 2025-04-14 18:56:43,410 - DEBUG - No XMPP flaps were noticed during the test
2025-04-14 18:56:43,410 - INFO - END TEST : test_basic_policy_allow_deny : PASSED[0:00:36]
2025-04-14 18:56:43,410 - INFO - -------------------------------------------------------------------------------- 2025-04-14 18:56:44,132 - INFO - Deleted project: ctest-TestBasicPolicy-77510113, ID : 145b31fd-5fe6-4da6-93be-9ffd78baa033