2025-10-22 18:16:32,568 - INFO - Reading existing Domain with UUID 76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:16:32,585 - INFO - Using existing domain ['admin_domain'](76186d71-3699-4707-98f1-3afabb9db250) 2025-10-22 18:16:32,838 - INFO - Project ctest-TestBasicPolicy-10446514 not found, creating it 2025-10-22 18:16:33,411 - INFO - Created Project:ctest-TestBasicPolicy-10446514, ID : a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:16:35,516 - INFO - ================================================================================ 2025-10-22 18:16:35,516 - INFO - STARTING TEST : test_basic_policy_allow_deny 2025-10-22 18:16:35,516 - 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-10-22 18:16:35,924 - DEBUG - Nothing to compare xmpp stats {'10.0.0.240': {'10.0.0.240': '0'}} with 2025-10-22 18:16:35,924 - INFO - Initial checks done. Running the testcase now 2025-10-22 18:16:35,924 - INFO - 2025-10-22 18:16:36,909 - DEBUG - Response for create_network : {'network': {'id': 'b19db30b-d40d-408e-b9b1-946fa8e8b816', 'name': 'ctest-vn-19435663', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-vn-19435663'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}} 2025-10-22 18:16:37,156 - DEBUG - Response for create_subnet : {'subnet': {'id': '0e33312c-ae90-4ecd-a0b9-4f26fb29beca', 'name': '', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'network_id': 'b19db30b-d40d-408e-b9b1-946fa8e8b816', 'ip_version': 4, 'cidr': '51.67.252.128/26', 'allocation_pools': [{'start': '51.67.252.130', 'end': '51.67.252.190'}], 'gateway_ip': '51.67.252.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2025-10-22T18:16:37.038060', 'updated_at': '2025-10-22T18:16:37.038060', 'dns_server_address': '51.67.252.130', 'tags': [], 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801'}} 2025-10-22 18:16:37,225 - INFO - Created VN ctest-vn-19435663 2025-10-22 18:16:37,287 - DEBUG - VN ctest-vn-19435663 UUID is b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:37,992 - DEBUG - Response for create_network : {'network': {'id': '304e99be-2b1e-4023-ac45-a2188a247e7f', 'name': 'ctest-vn-24572386', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-vn-24572386'], 'port_security_enabled': True, 'description': '', 'created_at': None, 'updated_at': None}} 2025-10-22 18:16:38,227 - DEBUG - Response for create_subnet : {'subnet': {'id': '8e2f6767-e929-4228-b4bb-6edbb2d9f52e', 'name': '', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'network_id': '304e99be-2b1e-4023-ac45-a2188a247e7f', 'ip_version': 4, 'cidr': '79.207.125.64/26', 'allocation_pools': [{'start': '79.207.125.66', 'end': '79.207.125.126'}], 'gateway_ip': '79.207.125.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'created_at': '2025-10-22T18:16:38.122865', 'updated_at': '2025-10-22T18:16:38.122865', 'dns_server_address': '79.207.125.66', 'tags': [], 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801'}} 2025-10-22 18:16:38,297 - INFO - Created VN ctest-vn-24572386 2025-10-22 18:16:38,354 - DEBUG - VN ctest-vn-24572386 UUID is 304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:38,651 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386, 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-10-22 18:16:39,130 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': 'b19db30b-d40d-408e-b9b1-946fa8e8b816', 'name': 'ctest-vn-19435663', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['0e33312c-ae90-4ecd-a0b9-4f26fb29beca'], 'fq_name': ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-vn-19435663'], 'policys': [['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-policy-allow-all-67721592']], 'subnet_ipam': [{'subnet_cidr': '51.67.252.128/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': '', 'created_at': '2025-10-22T18:16:36.810403', 'updated_at': '2025-10-22T18:16:37.056106'}} 2025-10-22 18:16:39,502 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '304e99be-2b1e-4023-ac45-a2188a247e7f', 'name': 'ctest-vn-24572386', 'tenant_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'project_id': 'a5577614b55d4bcdbe07f2f03a97c801', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['8e2f6767-e929-4228-b4bb-6edbb2d9f52e'], 'fq_name': ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-vn-24572386'], 'policys': [['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-policy-allow-all-67721592']], 'subnet_ipam': [{'subnet_cidr': '79.207.125.64/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': '', 'created_at': '2025-10-22T18:16:37.902252', 'updated_at': '2025-10-22T18:16:38.137386'}} 2025-10-22 18:16:39,682 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:16:40,038 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:16:40,139 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:16:40,200 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:16:40,303 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:40,364 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:40,427 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:16:40,489 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:16:40,551 - DEBUG - Requesting: https://10.0.0.240:8082/route-target/783fafd2-fe4e-4215-9532-849d2f8151fc 2025-10-22 18:16:40,611 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-10-22 18:16:40,611 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:40,698 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:16:40,768 - INFO - Verified VN network id 11 for VN b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:40,768 - INFO - Verifications in API Server for VN ctest-vn-19435663 passed 2025-10-22 18:16:40,768 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:40,825 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:16:40,891 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:16:40,953 - DEBUG - Requesting: https://10.0.0.240:8082/route-target/783fafd2-fe4e-4215-9532-849d2f8151fc 2025-10-22 18:16:41,079 - DEBUG - Control-node 10.0.0.240 : VN object is : {'node_name': 'virtual-network:admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-10446514', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12798582579440468110', 'uuid-lslong': '13380639175190558742'}, 'enable': 'true', 'created': '2025-10-22T18:16:36', 'last-modified': '2025-10-22T18:16:39', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.977161'} 2025-10-22 18:16:41,134 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-10-22 18:16:41,134 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-19435663 passed 2025-10-22 18:16:41,134 - DEBUG - ====Verifying policy data for ctest-vn-19435663 in API_Server ====== 2025-10-22 18:16:41,134 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:16:41,199 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:16:41,260 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:16:41,360 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/b19db30b-d40d-408e-b9b1-946fa8e8b816 2025-10-22 18:16:41,421 - DEBUG - ==>Verifying data for policy with id: 840df933-cb21-4dcd-a07c-445c0dc2d5dd, fqn: ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-policy-allow-all-67721592'] 2025-10-22 18:16:41,421 - INFO - VN ctest-vn-19435663 Policy verification: verify_vn_policy_in_api_server, status: True 2025-10-22 18:16:41,422 - DEBUG - Verifying the vn in opserver 2025-10-22 18:16:41,422 - DEBUG - Verifying the admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663 virtual network link through opserver 10.0.0.240 2025-10-22 18:16:41,422 - DEBUG - Requesting: https://10.0.0.240:8081/analytics/uves/virtual-networks 2025-10-22 18:16:41,822 - DEBUG - Requesting: https://10.0.0.240:8081/analytics/uves/virtual-networks 2025-10-22 18:16:42,015 - DEBUG - vn link and name as {'name': 'admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663', 'href': 'https://10.0.0.240:8081/analytics/uves/virtual-network/admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663?flat'} 2025-10-22 18:16:42,016 - INFO - Validated that VN admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663 is found in opserver 2025-10-22 18:16:42,124 - DEBUG - Do not have enough data to verify VN in agent 2025-10-22 18:16:42,179 - DEBUG - VRF ids for VN ctest-vn-19435663: {} 2025-10-22 18:16:42,180 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:16:42,245 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:16:42,321 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:16:42,437 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:42,508 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:42,576 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:16:42,635 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:16:42,688 - DEBUG - Requesting: https://10.0.0.240:8082/route-target/08eadb49-4c2f-4539-9bb7-145e5406c3ae 2025-10-22 18:16:42,747 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-10-22 18:16:42,747 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:42,819 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:16:42,905 - INFO - Verified VN network id 12 for VN 304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:42,906 - INFO - Verifications in API Server for VN ctest-vn-24572386 passed 2025-10-22 18:16:42,906 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:42,986 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:16:43,055 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:16:43,121 - DEBUG - Requesting: https://10.0.0.240:8082/route-target/08eadb49-4c2f-4539-9bb7-145e5406c3ae 2025-10-22 18:16:43,252 - DEBUG - Control-node 10.0.0.240 : VN object is : {'node_name': 'virtual-network:admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-10446514', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '3480888604050210851', 'uuid-lslong': '12413506174197202559'}, 'enable': 'true', 'created': '2025-10-22T18:16:37', 'last-modified': '2025-10-22T18:16:39', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:03.774732'} 2025-10-22 18:16:43,316 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-10-22 18:16:43,316 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-24572386 passed 2025-10-22 18:16:43,317 - DEBUG - ====Verifying policy data for ctest-vn-24572386 in API_Server ====== 2025-10-22 18:16:43,317 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:16:43,387 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:16:43,464 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:16:43,564 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-network/304e99be-2b1e-4023-ac45-a2188a247e7f 2025-10-22 18:16:43,629 - DEBUG - ==>Verifying data for policy with id: 840df933-cb21-4dcd-a07c-445c0dc2d5dd, fqn: ['admin_domain', 'ctest-TestBasicPolicy-10446514', 'ctest-policy-allow-all-67721592'] 2025-10-22 18:16:43,629 - INFO - VN ctest-vn-24572386 Policy verification: verify_vn_policy_in_api_server, status: True 2025-10-22 18:16:43,629 - DEBUG - Verifying the vn in opserver 2025-10-22 18:16:43,629 - DEBUG - Verifying the admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386 virtual network link through opserver 10.0.0.240 2025-10-22 18:16:43,629 - DEBUG - Requesting: https://10.0.0.240:8081/analytics/uves/virtual-networks 2025-10-22 18:16:43,691 - DEBUG - vn link and name as {'name': 'admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386', 'href': 'https://10.0.0.240:8081/analytics/uves/virtual-network/admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386?flat'} 2025-10-22 18:16:43,691 - INFO - Validated that VN admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-24572386 is found in opserver 2025-10-22 18:16:43,805 - DEBUG - Do not have enough data to verify VN in agent 2025-10-22 18:16:43,864 - DEBUG - VRF ids for VN ctest-vn-24572386: {} 2025-10-22 18:16:43,958 - DEBUG - Services list from nova: [, , ] 2025-10-22 18:16:45,816 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-604-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-604-1) 2025-10-22 18:16:47,168 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-juju-os-604-1), Zone: (nova:cn-jenkins-deploy-platform-juju-os-604-1) 2025-10-22 18:16:47,168 - INFO - Waiting for VM ctest-TestBasicPolicy-10446514-97338266 to be up.. 2025-10-22 18:16:47,354 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-10-22 18:16:52,591 - DEBUG - VM is in ACTIVE state now 2025-10-22 18:16:52,591 - INFO - VM name : ctest-TestBasicPolicy-10446514-97338266 2025-10-22 18:16:52,787 - DEBUG - VM ctest-TestBasicPolicy-10446514-97338266 ID is bc3fc6d7-87d7-4b93-b62a-5fbfe8845385 2025-10-22 18:16:52,812 - DEBUG - VM ctest-TestBasicPolicy-10446514-97338266 launched on Node cn-jenkins-deploy-platform-juju-os-604-1 2025-10-22 18:16:52,976 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-machine/bc3fc6d7-87d7-4b93-b62a-5fbfe8845385 2025-10-22 18:16:53,035 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-machine-interface/ffa57ef2-9651-41ec-af36-bcbee68b4b27 2025-10-22 18:16:56,550 - 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 1016ms') 2025-10-22 18:16:56,550 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicPolicy-10446514-97338266 failed! 2025-10-22 18:16:56,618 - DEBUG - Gateway for vn admin_domain:ctest-TestBasicPolicy-10446514:ctest-vn-19435663 is 51.67.252.129 and allocation pool is NOT set 2025-10-22 18:17:00,769 - 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=2 ttl=63 time=6.01 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1031ms\r\nrtt min/avg/max/mdev = 6.011/6.011/6.011/0.000 ms') 2025-10-22 18:17:00,769 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicPolicy-10446514-97338266 passed 2025-10-22 18:17:00,930 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 18:17:00,930 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-10446514-97338266, IP 51.67.252.131, Port 22 2025-10-22 18:17:01,040 - 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-10-22 18:17:01,266 - DEBUG - VM ctest-TestBasicPolicy-10446514-97338266 is NOT ready for SSH connections, VM status: ACTIVE 2025-10-22 18:17:06,269 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 18:17:06,270 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-10446514-97338266, IP 51.67.252.131, Port 22 2025-10-22 18:17:06,583 - DEBUG - VM ctest-TestBasicPolicy-10446514-97338266 is ready for SSH connections 2025-10-22 18:17:06,583 - INFO - Waiting for VM ctest-TestBasicPolicy-10446514-84366500 to be up.. 2025-10-22 18:17:06,965 - DEBUG - VM is in ACTIVE state now 2025-10-22 18:17:06,965 - INFO - VM name : ctest-TestBasicPolicy-10446514-84366500 2025-10-22 18:17:07,386 - DEBUG - VM ctest-TestBasicPolicy-10446514-84366500 ID is 673702b2-2357-4367-be71-cc38d5fb643a 2025-10-22 18:17:07,386 - DEBUG - VM ctest-TestBasicPolicy-10446514-84366500 launched on Node cn-jenkins-deploy-platform-juju-os-604-1 2025-10-22 18:17:07,686 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-machine/673702b2-2357-4367-be71-cc38d5fb643a 2025-10-22 18:17:07,755 - DEBUG - Requesting: https://10.0.0.240:8082/virtual-machine-interface/607745ff-7155-469e-8231-58e09a290a44 2025-10-22 18:17:09,488 - 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=4.79 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.658 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.658/2.722/4.787/2.064 ms') 2025-10-22 18:17:09,488 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestBasicPolicy-10446514-84366500 passed 2025-10-22 18:17:09,646 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 18:17:09,646 - DEBUG - Waiting to SSH to VM ctest-TestBasicPolicy-10446514-84366500, IP 79.207.125.67, Port 22 2025-10-22 18:17:09,865 - DEBUG - VM ctest-TestBasicPolicy-10446514-84366500 is ready for SSH connections 2025-10-22 18:17:09,865 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 18:17:09,865 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 79.207.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2025-10-22 18:17:09,865 - DEBUG - ping -s 56 -c 3 -W 1 79.207.125.67 2025-10-22 18:17:13,735 - DEBUG - PING 79.207.125.67 (79.207.125.67): 56 data bytes 64 bytes from 79.207.125.67: seq=0 ttl=63 time=6.362 ms 64 bytes from 79.207.125.67: seq=1 ttl=63 time=0.905 ms 64 bytes from 79.207.125.67: seq=2 ttl=63 time=1.047 ms --- 79.207.125.67 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.905/2.771/6.362 ms 2025-10-22 18:17:13,735 - INFO - Ping to IP 79.207.125.67 from VM ctest-TestBasicPolicy-10446514-97338266 passed 2025-10-22 18:17:13,978 - DEBUG - Policy Update Response {"network-policy": {"uuid": "840df933-cb21-4dcd-a07c-445c0dc2d5dd", "href": "https://10.0.0.240:8082/network-policy/840df933-cb21-4dcd-a07c-445c0dc2d5dd"}} 2025-10-22 18:17:13,978 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-10-22 18:17:13,978 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 79.207.125.67, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.240, gateway password: c0ntrail123 2025-10-22 18:17:13,978 - DEBUG - ping -s 56 -c 3 -W 1 79.207.125.67 2025-10-22 18:17:17,242 - DEBUG - PING 79.207.125.67 (79.207.125.67): 56 data bytes 64 bytes from 79.207.125.67: seq=0 ttl=63 time=1.979 ms --- 79.207.125.67 ping statistics --- 3 packets transmitted, 1 packets received, 66% packet loss round-trip min/avg/max = 1.979/1.979/1.979 ms 2025-10-22 18:17:17,242 - WARNING - Ping to IP 79.207.125.67 from VM ctest-TestBasicPolicy-10446514-97338266 failed 2025-10-22 18:17:17,243 - INFO - Deleting VM ctest-TestBasicPolicy-10446514-84366500 2025-10-22 18:17:17,396 - INFO - Deleting VM ctest-TestBasicPolicy-10446514-97338266 2025-10-22 18:17:18,275 - INFO - Deleted policy ctest-policy-allow-all-67721592 2025-10-22 18:17:18,276 - INFO - Deleting VN ctest-vn-24572386 2025-10-22 18:17:18,449 - DEBUG - VN 304e99be-2b1e-4023-ac45-a2188a247e7f still in use: Unable to complete operation on network 304e99be-2b1e-4023-ac45-a2188a247e7f. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-ed8d750d-5f96-4aca-aec0-376ccc791231'] 2025-10-22 18:17:18,449 - WARNING - Deleting VN ctest-vn-24572386 failed..Will retry 2025-10-22 18:17:20,681 - DEBUG - Response for deleting network () 2025-10-22 18:17:20,681 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/f941c373-4c66-4cc0-8975-5d1c6919968f 2025-10-22 18:17:20,743 - DEBUG - Response Code: 404 2025-10-22 18:17:20,744 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:17:20,795 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:17:20,864 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:17:20,967 - INFO - Validated that VN ctest-vn-24572386 is not found in API Server 2025-10-22 18:17:21,075 - DEBUG - VN ctest-vn-24572386 is not present in Agent 10.0.0.240 2025-10-22 18:17:21,075 - INFO - Validated that VN ctest-vn-24572386 is not in any agent 2025-10-22 18:17:21,243 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-24572386 info 2025-10-22 18:17:21,243 - INFO - Deleting VN ctest-vn-19435663 2025-10-22 18:17:21,463 - DEBUG - Response for deleting network () 2025-10-22 18:17:21,463 - DEBUG - Requesting: https://10.0.0.240:8082/routing-instance/9f9b24cd-94f1-4ce6-97cd-b54aa5a2f4c6 2025-10-22 18:17:21,518 - DEBUG - Response Code: 404 2025-10-22 18:17:21,519 - DEBUG - Requesting: https://10.0.0.240:8082/domains 2025-10-22 18:17:21,571 - DEBUG - Requesting: https://10.0.0.240:8082/domain/76186d71-3699-4707-98f1-3afabb9db250 2025-10-22 18:17:21,632 - DEBUG - Requesting: https://10.0.0.240:8082/project/a5577614-b55d-4bcd-be07-f2f03a97c801 2025-10-22 18:17:21,720 - INFO - Validated that VN ctest-vn-19435663 is not found in API Server 2025-10-22 18:17:21,828 - DEBUG - VN ctest-vn-19435663 is not present in Agent 10.0.0.240 2025-10-22 18:17:21,828 - INFO - Validated that VN ctest-vn-19435663 is not in any agent 2025-10-22 18:17:21,999 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-19435663 info 2025-10-22 18:17:22,420 - DEBUG - No XMPP flaps were noticed during the test
2025-10-22 18:17:22,421 - INFO - END TEST : test_basic_policy_allow_deny : PASSED[0:00:47]
2025-10-22 18:17:22,421 - INFO - -------------------------------------------------------------------------------- 2025-10-22 18:17:23,313 - INFO - Deleted project: ctest-TestBasicPolicy-10446514, ID : a5577614-b55d-4bcd-be07-f2f03a97c801