2025-10-11 16:51:37,200 - INFO - Domain Default found not creating 2025-10-11 16:51:37,374 - INFO - Project ctest-TestBasicPolicy-66565019 not found, creating it 2025-10-11 16:51:37,851 - INFO - Created Project:ctest-TestBasicPolicy-66565019, ID : b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:51:39,256 - INFO - ================================================================================ 2025-10-11 16:51:39,257 - INFO - STARTING TEST : test_basic_policy_allow_deny 2025-10-11 16:51:39,257 - 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-11 16:51:39,380 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.254': '0'}} with 2025-10-11 16:51:39,380 - INFO - Initial checks done. Running the testcase now 2025-10-11 16:51:39,380 - INFO - 2025-10-11 16:51:39,919 - DEBUG - Response for create_network : {'network': {'id': '132bc967-2ceb-4894-8431-cceb7d64eb03', 'name': 'ctest-vn-35115337', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-vn-35115337'], 'port_security_enabled': True, 'description': ''}} 2025-10-11 16:51:40,071 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a27761f2-02c6-42e0-8508-d4d29d4727ae', 'name': '', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'network_id': '132bc967-2ceb-4894-8431-cceb7d64eb03', 'ip_version': 4, 'cidr': '135.110.237.128/26', 'allocation_pools': [{'start': '135.110.237.130', 'end': '135.110.237.190'}], 'gateway_ip': '135.110.237.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '135.110.237.130', 'tags': [], 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22'}} 2025-10-11 16:51:40,087 - INFO - Created VN ctest-vn-35115337 2025-10-11 16:51:40,138 - DEBUG - VN ctest-vn-35115337 UUID is 132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:40,453 - DEBUG - Response for create_network : {'network': {'id': '726f9a2d-b71f-4fb7-a38a-8e199a006047', 'name': 'ctest-vn-85900207', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-vn-85900207'], 'port_security_enabled': True, 'description': ''}} 2025-10-11 16:51:40,620 - DEBUG - Response for create_subnet : {'subnet': {'id': '22653df9-e516-4eae-aa65-a9eef9d0387f', 'name': '', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'network_id': '726f9a2d-b71f-4fb7-a38a-8e199a006047', 'ip_version': 4, 'cidr': '22.218.13.0/26', 'allocation_pools': [{'start': '22.218.13.2', 'end': '22.218.13.62'}], 'gateway_ip': '22.218.13.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '22.218.13.2', 'tags': [], 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22'}} 2025-10-11 16:51:40,639 - INFO - Created VN ctest-vn-85900207 2025-10-11 16:51:40,694 - DEBUG - VN ctest-vn-85900207 UUID is 726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:40,838 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337, 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-66565019:ctest-vn-85900207, 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-11 16:51:41,135 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '132bc967-2ceb-4894-8431-cceb7d64eb03', 'name': 'ctest-vn-35115337', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['a27761f2-02c6-42e0-8508-d4d29d4727ae'], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-vn-35115337'], 'policys': [['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-policy-allow-all-37936517']], 'subnet_ipam': [{'subnet_cidr': '135.110.237.128/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': ''}} 2025-10-11 16:51:41,359 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '726f9a2d-b71f-4fb7-a38a-8e199a006047', 'name': 'ctest-vn-85900207', 'tenant_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'project_id': 'b9a047e3a5d745f8a1f54191fada9c22', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['22653df9-e516-4eae-aa65-a9eef9d0387f'], 'fq_name': ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-vn-85900207'], 'policys': [['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-policy-allow-all-37936517']], 'subnet_ipam': [{'subnet_cidr': '22.218.13.0/26', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': ''}} 2025-10-11 16:51:41,526 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:51:41,818 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:51:41,848 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:51:41,859 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:51:41,927 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:41,936 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:41,945 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:51:41,951 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:51:41,957 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/0c7669e2-408f-4e09-8882-d7fbca367a60 2025-10-11 16:51:41,964 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-10-11 16:51:41,964 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:41,972 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:51:41,983 - INFO - Verified VN network id 12 for VN 132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:41,983 - INFO - Verifications in API Server for VN ctest-vn-35115337 passed 2025-10-11 16:51:41,983 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:41,991 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:51:41,996 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:51:42,002 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/0c7669e2-408f-4e09-8882-d7fbca367a60 2025-10-11 16:51:42,012 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-66565019', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1381419155691620500', 'uuid-lslong': '9525619998658456323'}, 'enable': 'true', 'created': '2025-10-11T16:51:39', 'last-modified': '2025-10-11T16:51:41', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.906069'} 2025-10-11 16:51:42,018 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-10-11 16:51:42,018 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-35115337 passed 2025-10-11 16:51:42,018 - DEBUG - ====Verifying policy data for ctest-vn-35115337 in API_Server ====== 2025-10-11 16:51:42,018 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:51:42,024 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:51:42,034 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:51:42,103 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/132bc967-2ceb-4894-8431-cceb7d64eb03 2025-10-11 16:51:42,112 - DEBUG - ==>Verifying data for policy with id: 48bb5aa4-50aa-48e2-80ce-fb7c286dfcf6, fqn: ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-policy-allow-all-37936517'] 2025-10-11 16:51:42,112 - INFO - VN ctest-vn-35115337 Policy verification: verify_vn_policy_in_api_server, status: True 2025-10-11 16:51:42,112 - DEBUG - Verifying the vn in opserver 2025-10-11 16:51:42,112 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337 virtual network link through opserver 10.0.0.254 2025-10-11 16:51:42,112 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks 2025-10-11 16:51:42,408 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks 2025-10-11 16:51:42,458 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337?flat'} 2025-10-11 16:51:42,458 - INFO - Validated that VN default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-35115337 is found in opserver 2025-10-11 16:51:42,468 - DEBUG - Do not have enough data to verify VN in agent 2025-10-11 16:51:42,472 - DEBUG - VRF ids for VN ctest-vn-35115337: {} 2025-10-11 16:51:42,472 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:51:42,477 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:51:42,488 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:51:42,557 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,567 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,576 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:51:42,582 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:51:42,589 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/a617e91a-68b5-46e5-bc89-d4aa97a34516 2025-10-11 16:51:42,594 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-10-11 16:51:42,594 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,602 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:51:42,615 - INFO - Verified VN network id 13 for VN 726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,615 - INFO - Verifications in API Server for VN ctest-vn-85900207 passed 2025-10-11 16:51:42,615 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,624 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:51:42,631 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:51:42,637 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/a617e91a-68b5-46e5-bc89-d4aa97a34516 2025-10-11 16:51:42,647 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-85900207', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicy-66565019', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8245978963875155895', 'uuid-lslong': '11784387615577366599'}, 'enable': 'true', 'created': '2025-10-11T16:51:40', 'last-modified': '2025-10-11T16:51:41', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.311082'} 2025-10-11 16:51:42,652 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-10-11 16:51:42,652 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-85900207 passed 2025-10-11 16:51:42,652 - DEBUG - ====Verifying policy data for ctest-vn-85900207 in API_Server ====== 2025-10-11 16:51:42,652 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:51:42,657 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:51:42,667 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:51:42,732 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/726f9a2d-b71f-4fb7-a38a-8e199a006047 2025-10-11 16:51:42,741 - DEBUG - ==>Verifying data for policy with id: 48bb5aa4-50aa-48e2-80ce-fb7c286dfcf6, fqn: ['default-domain', 'ctest-TestBasicPolicy-66565019', 'ctest-policy-allow-all-37936517'] 2025-10-11 16:51:42,742 - INFO - VN ctest-vn-85900207 Policy verification: verify_vn_policy_in_api_server, status: True 2025-10-11 16:51:42,742 - DEBUG - Verifying the vn in opserver 2025-10-11 16:51:42,742 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-85900207 virtual network link through opserver 10.0.0.254 2025-10-11 16:51:42,742 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks 2025-10-11 16:51:42,751 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-85900207', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-85900207?flat'} 2025-10-11 16:51:42,751 - INFO - Validated that VN default-domain:ctest-TestBasicPolicy-66565019:ctest-vn-85900207 is found in opserver 2025-10-11 16:51:42,761 - DEBUG - Do not have enough data to verify VN in agent 2025-10-11 16:51:42,766 - DEBUG - VRF ids for VN ctest-vn-85900207: {} 2025-10-11 16:51:42,911 - DEBUG - Services list from nova: [, , ] 2025-10-11 16:51:44,001 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4287-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4287-1) 2025-10-11 16:51:45,166 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-4287-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-4287-1) 2025-10-11 16:51:45,166 - INFO - Waiting for VM ctest-TestBasicPolicy-66565019-48322534 to be up.. 2025-10-11 16:51:45,242 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-10-11 16:51:50,310 - DEBUG - VM is in ERROR state now 2025-10-11 16:51:50,310 - ERROR - VM in error state. 2025-10-11 16:51:50,311 - ERROR - VM is not in ACTIVE state 2025-10-11 16:51:50,426 - ERROR - Fatal Nova Exception while getting VM detail 2025-10-11 16:51:50,426 - DEBUG - None 2025-10-11 16:51:50,426 - INFO - Waiting for VM ctest-TestBasicPolicy-66565019-54766510 to be up.. 2025-10-11 16:51:50,483 - DEBUG - VM is in ERROR state now 2025-10-11 16:51:50,483 - ERROR - VM in error state. 2025-10-11 16:51:50,483 - ERROR - VM is not in ACTIVE state 2025-10-11 16:51:50,570 - ERROR - Fatal Nova Exception while getting VM detail 2025-10-11 16:51:50,570 - DEBUG - None 2025-10-11 16:51:50,570 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:51:50,625 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:51:55,685 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:00,747 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:05,809 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:10,871 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:15,932 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:15,932 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:52:17,932 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:52:17,987 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:23,043 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:28,103 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:33,162 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:38,231 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:43,287 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:43,287 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:52:45,288 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:52:45,350 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:50,413 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:52:55,468 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:00,526 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:05,588 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:10,646 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:10,646 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:53:12,647 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:53:12,713 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:17,773 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:22,832 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:27,890 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:32,950 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:38,008 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:38,009 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:53:40,010 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:53:40,067 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:45,131 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:50,190 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:53:55,250 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:00,308 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:05,367 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:05,368 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:54:07,368 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:54:07,426 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:12,480 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:17,550 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:22,603 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:27,662 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:32,725 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:32,725 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:54:32,727 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:54:32,783 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:37,845 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:43,072 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:48,133 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:53,186 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:58,248 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:54:58,248 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:55:00,249 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:55:00,309 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:05,373 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:10,439 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:15,499 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:20,560 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:25,620 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:25,620 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:55:27,621 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:55:27,675 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:32,737 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:37,803 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:42,862 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:47,923 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:52,981 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:55:52,981 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:55:54,982 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:55:55,041 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:00,098 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:05,164 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:10,226 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:15,290 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:20,349 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:20,349 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:56:22,349 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:56:22,403 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:27,463 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:32,525 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:37,588 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:42,694 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:47,763 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:47,763 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:56:49,764 - INFO - VM name : ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:56:49,822 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:54,889 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:56:59,951 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:57:05,015 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:57:10,076 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:57:15,134 - DEBUG - VM ctest-TestBasicPolicy-66565019-54766510 : Status=ERROR, Addresses : {} 2025-10-11 16:57:15,135 - ERROR - VM 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b is not launched yet 2025-10-11 16:57:15,135 - INFO - Skip interface_detach for VM ctest-TestBasicPolicy-66565019-54766510 in state ERROR 2025-10-11 16:57:15,135 - INFO - Deleting VM ctest-TestBasicPolicy-66565019-54766510 2025-10-11 16:57:15,154 - ERROR - VM ctest-TestBasicPolicy-66565019-54766510 has failed to come up 2025-10-11 16:57:15,154 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-10-11T16:51:46Z', 'message': "Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:a3:ca:1d:7b:a2,has_traffic_filtering=True,id=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42,network=Network(726f9a2d-b71f-4fb7-a38a-8e199a006047),plugin='vrouter',port_p", 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 77, in plug\n plugin.plug(vif, instance_info)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 271, in plug\n self._vrouter_port_add(instance_info, vif)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 263, in _vrouter_port_add\n vhostuser_socket, vhostuser_mode)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/priv_context.py", line 272, in _wrap\n r_call_timeout)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/daemon.py", line 215, in remote_call\n raise exc_type(*result[2])\nvif_plug_vrouter.exception.VrouterPortControlError: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42\', \'--instance_uuid=0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b\', \'--vn_uuid=726f9a2d-b71f-4fb7-a38a-8e199a006047\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=22.218.13.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-54766510\', \'--mac=02:a3:ca:1d:7b:a2\', \'--tap_name=tapa3ca1d7b-a2\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 699, in _plug_os_vif\n os_vif.plug(vif, instance_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 82, in plug\n raise os_vif.exception.PlugException(vif=vif, err=err)\nos_vif.exception.PlugException: Failed to plug VIF VIFGeneric(active=True,address=02:a3:ca:1d:7b:a2,has_traffic_filtering=True,id=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42,network=Network(726f9a2d-b71f-4fb7-a38a-8e199a006047),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tapa3ca1d7b-a2\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42\', \'--instance_uuid=0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b\', \'--vn_uuid=726f9a2d-b71f-4fb7-a38a-8e199a006047\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=22.218.13.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-54766510\', \'--mac=02:a3:ca:1d:7b:a2\', \'--tap_name=tapa3ca1d7b-a2\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2521, in _build_and_run_instance\n accel_info=accel_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 4339, in spawn\n cleanup_instance_disks=created_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7523, in _create_guest_with_network\n cleanup_instance_disks=cleanup_instance_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 227, in __exit__\n self.force_reraise()\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 200, in force_reraise\n raise self.value\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7492, in _create_guest_with_network\n self.plug_vifs(instance, network_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 1386, in plug_vifs\n self.vif_driver.plug(instance, vif)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 723, in plug\n self._plug_os_vif(instance, vif_obj)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 703, in _plug_os_vif\n raise exception.InternalError(msg)\nnova.exception.InternalError: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:a3:ca:1d:7b:a2,has_traffic_filtering=True,id=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42,network=Network(726f9a2d-b71f-4fb7-a38a-8e199a006047),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tapa3ca1d7b-a2\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42\', \'--instance_uuid=0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b\', \'--vn_uuid=726f9a2d-b71f-4fb7-a38a-8e199a006047\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=22.218.13.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-54766510\', \'--mac=02:a3:ca:1d:7b:a2\', \'--tap_name=tapa3ca1d7b-a2\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2337, in _do_build_and_run_instance\n filter_properties, request_spec, accel_uuids)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2625, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=str(e))\nnova.exception.RescheduledException: Build of instance 0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b was re-scheduled: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:a3:ca:1d:7b:a2,has_traffic_filtering=True,id=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42,network=Network(726f9a2d-b71f-4fb7-a38a-8e199a006047),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tapa3ca1d7b-a2\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=a3ca1d7b-a2a7-4619-9f7c-b4b1e6722e42\', \'--instance_uuid=0f2c0b1e-2f60-4961-b1ad-8ab42f85e70b\', \'--vn_uuid=726f9a2d-b71f-4fb7-a38a-8e199a006047\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=22.218.13.3\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-54766510\', \'--mac=02:a3:ca:1d:7b:a2\', \'--tap_name=tapa3ca1d7b-a2\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n'} 2025-10-11 16:57:15,155 - INFO - Skip interface_detach for VM ctest-TestBasicPolicy-66565019-48322534 in state ERROR 2025-10-11 16:57:15,155 - INFO - Deleting VM ctest-TestBasicPolicy-66565019-48322534 2025-10-11 16:57:15,155 - ERROR - VM ctest-TestBasicPolicy-66565019-48322534 has failed to come up 2025-10-11 16:57:15,155 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-10-11T16:51:45Z', 'message': "Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:07:40:b9:73:44,has_traffic_filtering=True,id=0740b973-44de-4202-8ee9-75b9a820ecba,network=Network(132bc967-2ceb-4894-8431-cceb7d64eb03),plugin='vrouter',port_p", 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 77, in plug\n plugin.plug(vif, instance_info)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 271, in plug\n self._vrouter_port_add(instance_info, vif)\n File "/opt/plugin/site-packages/vif_plug_vrouter/vrouter.py", line 263, in _vrouter_port_add\n vhostuser_socket, vhostuser_mode)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/priv_context.py", line 272, in _wrap\n r_call_timeout)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_privsep/daemon.py", line 215, in remote_call\n raise exc_type(*result[2])\nvif_plug_vrouter.exception.VrouterPortControlError: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=0740b973-44de-4202-8ee9-75b9a820ecba\', \'--instance_uuid=530bb7c6-dfe3-4a32-b5d1-0fe6f120fb7e\', \'--vn_uuid=132bc967-2ceb-4894-8431-cceb7d64eb03\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=135.110.237.131\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-48322534\', \'--mac=02:07:40:b9:73:44\', \'--tap_name=tap0740b973-44\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 699, in _plug_os_vif\n os_vif.plug(vif, instance_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/os_vif/__init__.py", line 82, in plug\n raise os_vif.exception.PlugException(vif=vif, err=err)\nos_vif.exception.PlugException: Failed to plug VIF VIFGeneric(active=True,address=02:07:40:b9:73:44,has_traffic_filtering=True,id=0740b973-44de-4202-8ee9-75b9a820ecba,network=Network(132bc967-2ceb-4894-8431-cceb7d64eb03),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap0740b973-44\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=0740b973-44de-4202-8ee9-75b9a820ecba\', \'--instance_uuid=530bb7c6-dfe3-4a32-b5d1-0fe6f120fb7e\', \'--vn_uuid=132bc967-2ceb-4894-8431-cceb7d64eb03\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=135.110.237.131\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-48322534\', \'--mac=02:07:40:b9:73:44\', \'--tap_name=tap0740b973-44\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2521, in _build_and_run_instance\n accel_info=accel_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 4339, in spawn\n cleanup_instance_disks=created_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7523, in _create_guest_with_network\n cleanup_instance_disks=cleanup_instance_disks)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 227, in __exit__\n self.force_reraise()\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_utils/excutils.py", line 200, in force_reraise\n raise self.value\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 7492, in _create_guest_with_network\n self.plug_vifs(instance, network_info)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/driver.py", line 1386, in plug_vifs\n self.vif_driver.plug(instance, vif)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 723, in plug\n self._plug_os_vif(instance, vif_obj)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/virt/libvirt/vif.py", line 703, in _plug_os_vif\n raise exception.InternalError(msg)\nnova.exception.InternalError: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:07:40:b9:73:44,has_traffic_filtering=True,id=0740b973-44de-4202-8ee9-75b9a820ecba,network=Network(132bc967-2ceb-4894-8431-cceb7d64eb03),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap0740b973-44\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=0740b973-44de-4202-8ee9-75b9a820ecba\', \'--instance_uuid=530bb7c6-dfe3-4a32-b5d1-0fe6f120fb7e\', \'--vn_uuid=132bc967-2ceb-4894-8431-cceb7d64eb03\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=135.110.237.131\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-48322534\', \'--mac=02:07:40:b9:73:44\', \'--tap_name=tap0740b973-44\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n\nDuring handling of the above exception, another exception occurred:\n\nTraceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2337, in _do_build_and_run_instance\n filter_properties, request_spec, accel_uuids)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/compute/manager.py", line 2625, in _build_and_run_instance\n instance_uuid=instance.uuid, reason=str(e))\nnova.exception.RescheduledException: Build of instance 530bb7c6-dfe3-4a32-b5d1-0fe6f120fb7e was re-scheduled: Failure running os_vif plugin plug method: Failed to plug VIF VIFGeneric(active=True,address=02:07:40:b9:73:44,has_traffic_filtering=True,id=0740b973-44de-4202-8ee9-75b9a820ecba,network=Network(132bc967-2ceb-4894-8431-cceb7d64eb03),plugin=\'vrouter\',port_profile=,preserve_on_delete=False,vif_name=\'tap0740b973-44\'). Got error: Error during the call to vrouter-port-control: (\'vrouter-port-control\', \'--oper=add\', \'--uuid=0740b973-44de-4202-8ee9-75b9a820ecba\', \'--instance_uuid=530bb7c6-dfe3-4a32-b5d1-0fe6f120fb7e\', \'--vn_uuid=132bc967-2ceb-4894-8431-cceb7d64eb03\', \'--vm_project_uuid=b9a047e3a5d745f8a1f54191fada9c22\', \'--ip_address=135.110.237.131\', \'--ipv6_address=None\', \'--vm_name=ctest-TestBasicPolicy-66565019-48322534\', \'--mac=02:07:40:b9:73:44\', \'--tap_name=tap0740b973-44\', \'--port_type=NovaVMPort\', \'--tx_vlan_id=-1\', \'--rx_vlan_id=-1\')\n'} 2025-10-11 16:57:15,451 - INFO - Deleted policy ctest-policy-allow-all-37936517 2025-10-11 16:57:15,451 - INFO - Deleting VN ctest-vn-85900207 2025-10-11 16:57:15,562 - DEBUG - Response for deleting network () 2025-10-11 16:57:15,562 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/b9265c52-aa5f-407f-9375-44f17f43bc96 2025-10-11 16:57:15,590 - DEBUG - Response Code: 404 2025-10-11 16:57:15,590 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:57:15,595 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:57:15,648 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:57:15,716 - INFO - Validated that VN ctest-vn-85900207 is not found in API Server 2025-10-11 16:57:15,726 - DEBUG - VN ctest-vn-85900207 is not present in Agent 10.0.0.254 2025-10-11 16:57:15,726 - INFO - Validated that VN ctest-vn-85900207 is not in any agent 2025-10-11 16:57:15,739 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-85900207 info 2025-10-11 16:57:15,740 - INFO - Deleting VN ctest-vn-35115337 2025-10-11 16:57:15,826 - DEBUG - Response for deleting network () 2025-10-11 16:57:15,826 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/8ad248f6-a2be-456f-9726-cb01d2f89528 2025-10-11 16:57:15,830 - DEBUG - Response Code: 404 2025-10-11 16:57:15,831 - DEBUG - Requesting: http://10.0.0.254:8082/domains 2025-10-11 16:57:15,835 - DEBUG - Requesting: http://10.0.0.254:8082/domain/1c888893-7c1f-46a1-80b1-cf2038627f3c 2025-10-11 16:57:15,893 - DEBUG - Requesting: http://10.0.0.254:8082/project/b9a047e3-a5d7-45f8-a1f5-4191fada9c22 2025-10-11 16:57:15,964 - INFO - Validated that VN ctest-vn-35115337 is not found in API Server 2025-10-11 16:57:15,973 - DEBUG - VN ctest-vn-35115337 is not present in Agent 10.0.0.254 2025-10-11 16:57:15,973 - INFO - Validated that VN ctest-vn-35115337 is not in any agent 2025-10-11 16:57:15,986 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-35115337 info 2025-10-11 16:57:16,117 - ERROR -
Traceback (most recent call last):
  File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
    result = function(self, *args, **kwargs)
  File "/contrail-test/scripts/policy/test_policy_basic.py", line 118, in test_basic_policy_allow_deny
    assert vm1_fixture.ping_with_certainty(vm2_fixture.vm_ip), (
  File "/contrail-test/fixtures/vm_test.py", line 354, in vm_ip
    assert self.verify_vm_launched()
AssertionError
2025-10-11 16:57:16,122 - DEBUG - No XMPP flaps were noticed during the test 2025-10-11 16:57:16,122 - INFO -
2025-10-11 16:57:16,122 - INFO - END TEST : test_basic_policy_allow_deny : FAILED[0:05:37]
2025-10-11 16:57:16,122 - INFO - -------------------------------------------------------------------------------- 2025-10-11 16:57:16,808 - INFO - Deleted project: ctest-TestBasicPolicy-66565019, ID : b9a047e3-a5d7-45f8-a1f5-4191fada9c22