2025-12-15 02:44:59,796 - INFO - Domain Default found not creating
2025-12-15 02:45:00,242 - INFO - Project ctest-TestPolicyAclIpv4v6-99364654 not found, creating it
2025-12-15 02:45:01,315 - INFO - Created Project:ctest-TestPolicyAclIpv4v6-99364654, ID : ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:02,866 - INFO - ================================================================================
2025-12-15 02:45:02,866 - INFO - STARTING TEST : test_policy_inheritance_src_pol_dst_any
2025-12-15 02:45:04,167 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.254': '0', '10.20.0.129': '0'}, '10.0.0.27': {'10.20.0.254': '0', '10.20.0.18': '0'}} with
2025-12-15 02:45:04,167 - INFO - Initial checks done. Running the testcase now
2025-12-15 02:45:04,167 - INFO -
2025-12-15 02:45:04,167 - INFO - ================================================================================
2025-12-15 02:45:04,167 - INFO - STARTING TEST : test_policy_inheritance_src_pol_dst_any
2025-12-15 02:45:04,167 - INFO - TEST DESCRIPTION : Test cases to test policy inheritance
2025-12-15 02:45:05,453 - DEBUG - Nothing to compare xmpp stats {'10.0.0.22': {'10.20.0.254': '0', '10.20.0.129': '0'}, '10.0.0.27': {'10.20.0.254': '0', '10.20.0.18': '0'}} with
2025-12-15 02:45:05,453 - INFO - Initial checks done. Running the testcase now
2025-12-15 02:45:05,453 - INFO -
2025-12-15 02:45:06,771 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:07,062 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:07,092 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:07,111 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:07,226 - DEBUG - Requesting: http://10.0.0.23:8082/network-ipam/9f4a06a8-b6e6-440c-bbe2-72732cc2e48f
2025-12-15 02:45:07,234 - INFO - Verifications in API Server for IPAM: ipam1 passed
2025-12-15 02:45:07,239 - DEBUG - Control-node 10.0.0.23 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam1', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11477993921999946764', 'uuid-lslong': '13538509268826907791'}, 'enable': 'true', 'created': '2025-12-15T02:45:05', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.187932'}
2025-12-15 02:45:07,244 - DEBUG - Control-node 10.0.0.50 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam1', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11477993921999946764', 'uuid-lslong': '13538509268826907791'}, 'enable': 'true', 'created': '2025-12-15T02:45:05', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.193558'}
2025-12-15 02:45:07,249 - DEBUG - Control-node 10.0.0.65 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam1', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11477993921999946764', 'uuid-lslong': '13538509268826907791'}, 'enable': 'true', 'created': '2025-12-15T02:45:05', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.198902'}
2025-12-15 02:45:07,249 - INFO - Verifications in Control node for IPAM: ipam1 passed
2025-12-15 02:45:07,249 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:07,255 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:07,266 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:07,370 - DEBUG - Requesting: http://10.0.0.23:8082/network-ipam/ddf801d7-6708-432d-894f-9fb49a6f6791
2025-12-15 02:45:07,377 - INFO - Verifications in API Server for IPAM: ipam2 passed
2025-12-15 02:45:07,382 - DEBUG - Control-node 10.0.0.23 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam2', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '15994536101264507693', 'uuid-lslong': '9894302504390190993'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.978478'}
2025-12-15 02:45:07,389 - DEBUG - Control-node 10.0.0.50 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam2', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '15994536101264507693', 'uuid-lslong': '9894302504390190993'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.993522'}
2025-12-15 02:45:07,394 - DEBUG - Control-node 10.0.0.65 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam2', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '15994536101264507693', 'uuid-lslong': '9894302504390190993'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.992870'}
2025-12-15 02:45:07,394 - INFO - Verifications in Control node for IPAM: ipam2 passed
2025-12-15 02:45:07,394 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:07,400 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:07,411 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:07,511 - DEBUG - Requesting: http://10.0.0.23:8082/network-ipam/eae2b10e-8135-4792-97ff-321f9ed0bb43
2025-12-15 02:45:07,525 - INFO - Verifications in API Server for IPAM: ipam3 passed
2025-12-15 02:45:07,532 - DEBUG - Control-node 10.0.0.23 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam3', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '16925285025467156370', 'uuid-lslong': '10952527930178190147'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.791962'}
2025-12-15 02:45:07,539 - DEBUG - Control-node 10.0.0.50 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam3', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '16925285025467156370', 'uuid-lslong': '10952527930178190147'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.792253'}
2025-12-15 02:45:07,545 - DEBUG - Control-node 10.0.0.65 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ipam3', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '16925285025467156370', 'uuid-lslong': '10952527930178190147'}, 'enable': 'true', 'created': '2025-12-15T02:45:06', 'last-modified': '2025-12-15T02:45:06', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.808315'}
2025-12-15 02:45:07,545 - INFO - Verifications in Control node for IPAM: ipam3 passed
2025-12-15 02:45:07,865 - DEBUG - Response for create_network : {'network': {'id': '669d6e32-9031-420b-a7d3-e54b1b53d88f', 'name': 'ctest-VN1-00107366', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-VN1-00107366'], 'port_security_enabled': True, 'description': ''}}
2025-12-15 02:45:08,165 - DEBUG - Response for create_subnet : {'subnet': {'id': '7e6b6d8d-c7d5-4878-b945-d4ce302c0bc8', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': '669d6e32-9031-420b-a7d3-e54b1b53d88f', 'ip_version': 4, 'cidr': '85.104.11.0/26', 'allocation_pools': [{'start': '85.104.11.2', 'end': '85.104.11.62'}], 'gateway_ip': '85.104.11.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '85.104.11.2', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:08,379 - DEBUG - Response for create_subnet : {'subnet': {'id': 'a95cdb0e-0797-40dc-91a8-55614d0567e7', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': '669d6e32-9031-420b-a7d3-e54b1b53d88f', 'ip_version': 6, 'cidr': '332e:6146:1a2a:12f6:b0fb:a249::/96', 'allocation_pools': [{'start': '332e:6146:1a2a:12f6:b0fb:a249:0:2', 'end': '332e:6146:1a2a:12f6:b0fb:a249:ffff:fffe'}], 'gateway_ip': '332e:6146:1a2a:12f6:b0fb:a249:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '332e:6146:1a2a:12f6:b0fb:a249:0:2', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:08,403 - INFO - Created VN ctest-VN1-00107366
2025-12-15 02:45:08,414 - DEBUG - VN ctest-VN1-00107366 UUID is 669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:08,595 - DEBUG - Fetched VN: default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366(669d6e32-9031-420b-a7d3-e54b1b53d88f) with subnets ['85.104.11.0/26', '332e:6146:1a2a:12f6:b0fb:a249::/96']
2025-12-15 02:45:08,916 - DEBUG - Response for create_network : {'network': {'id': '5bb54abe-d161-487d-be61-712c6781f1bc', 'name': 'ctest-VN2-50643407', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-VN2-50643407'], 'port_security_enabled': True, 'description': ''}}
2025-12-15 02:45:09,179 - DEBUG - Response for create_subnet : {'subnet': {'id': '66d4a62b-fbf1-4885-85c9-993bf366ad18', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': '5bb54abe-d161-487d-be61-712c6781f1bc', 'ip_version': 4, 'cidr': '73.186.102.0/26', 'allocation_pools': [{'start': '73.186.102.2', 'end': '73.186.102.62'}], 'gateway_ip': '73.186.102.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '73.186.102.2', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:09,421 - DEBUG - Response for create_subnet : {'subnet': {'id': '1b7f4e95-cf21-4503-bf04-c0ca9ef2307e', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': '5bb54abe-d161-487d-be61-712c6781f1bc', 'ip_version': 6, 'cidr': '28a7:17e2:11e8:17b1:194a:43f4::/96', 'allocation_pools': [{'start': '28a7:17e2:11e8:17b1:194a:43f4:0:2', 'end': '28a7:17e2:11e8:17b1:194a:43f4:ffff:fffe'}], 'gateway_ip': '28a7:17e2:11e8:17b1:194a:43f4:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '28a7:17e2:11e8:17b1:194a:43f4:0:2', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:09,457 - INFO - Created VN ctest-VN2-50643407
2025-12-15 02:45:09,480 - DEBUG - VN ctest-VN2-50643407 UUID is 5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:09,833 - DEBUG - Response for create_network : {'network': {'id': 'b941587d-57ed-4b2e-a5ac-e630c432018a', 'name': 'ctest-VN3-83860196', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-VN3-83860196'], 'port_security_enabled': True, 'description': ''}}
2025-12-15 02:45:10,088 - DEBUG - Response for create_subnet : {'subnet': {'id': '3440f4a2-7d5a-46c0-900e-3a45d1060021', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': 'b941587d-57ed-4b2e-a5ac-e630c432018a', 'ip_version': 4, 'cidr': '18.46.17.64/26', 'allocation_pools': [{'start': '18.46.17.66', 'end': '18.46.17.126'}], 'gateway_ip': '18.46.17.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '18.46.17.66', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:10,333 - DEBUG - Response for create_subnet : {'subnet': {'id': '4589c71a-5df7-4609-93d7-b36358b2543e', 'name': '', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'network_id': 'b941587d-57ed-4b2e-a5ac-e630c432018a', 'ip_version': 6, 'cidr': '2ec7:92ea:56aa:3f67:4289:8f20::/96', 'allocation_pools': [{'start': '2ec7:92ea:56aa:3f67:4289:8f20:0:2', 'end': '2ec7:92ea:56aa:3f67:4289:8f20:ffff:fffe'}], 'gateway_ip': '2ec7:92ea:56aa:3f67:4289:8f20:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '2ec7:92ea:56aa:3f67:4289:8f20:0:2', 'tags': [], 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64'}}
2025-12-15 02:45:10,359 - INFO - Created VN ctest-VN3-83860196
2025-12-15 02:45:10,370 - DEBUG - VN ctest-VN3-83860196 UUID is b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:10,507 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:10,514 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:10,528 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:10,616 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,628 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,636 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:45:10,643 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:45:10,649 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/2f3a1cc0-0060-4d7b-a9f7-6cd7c3d7cfc2
2025-12-15 02:45:10,654 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-15 02:45:10,655 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,662 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:45:10,681 - INFO - Verified VN network id 11 for VN 669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,681 - INFO - Verifications in API Server for VN ctest-VN1-00107366 passed
2025-12-15 02:45:10,682 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,691 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:45:10,699 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:45:10,705 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/2f3a1cc0-0060-4d7b-a9f7-6cd7c3d7cfc2
2025-12-15 02:45:10,716 - DEBUG - Control-node 10.0.0.23 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '7394187326658789899', 'uuid-lslong': '12093261535163701391'}, 'enable': 'true', 'created': '2025-12-15T02:45:07', 'last-modified': '2025-12-15T02:45:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.395229'}
2025-12-15 02:45:10,721 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-15 02:45:10,726 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '7394187326658789899', 'uuid-lslong': '12093261535163701391'}, 'enable': 'true', 'created': '2025-12-15T02:45:07', 'last-modified': '2025-12-15T02:45:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.399991'}
2025-12-15 02:45:10,732 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-15 02:45:10,738 - DEBUG - Control-node 10.0.0.65 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '7394187326658789899', 'uuid-lslong': '12093261535163701391'}, 'enable': 'true', 'created': '2025-12-15T02:45:07', 'last-modified': '2025-12-15T02:45:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.418626'}
2025-12-15 02:45:10,746 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-15 02:45:10,746 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-VN1-00107366 passed
2025-12-15 02:45:10,746 - DEBUG - ====Verifying policy data for ctest-VN1-00107366 in API_Server ======
2025-12-15 02:45:10,746 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:10,752 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:10,763 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:10,853 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:10,863 - DEBUG - =>VN ctest-VN1-00107366 has no policy to be verified
2025-12-15 02:45:10,863 - DEBUG - Verifying the vn in opserver
2025-12-15 02:45:10,863 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 virtual network link through opserver 10.0.0.23
2025-12-15 02:45:10,863 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,153 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,208 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366?flat'}
2025-12-15 02:45:11,208 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 virtual network link through opserver 10.0.0.50
2025-12-15 02:45:11,208 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,495 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,547 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366?flat'}
2025-12-15 02:45:11,547 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 virtual network link through opserver 10.0.0.65
2025-12-15 02:45:11,547 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,838 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2025-12-15 02:45:11,892 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366?flat'}
2025-12-15 02:45:11,892 - INFO - Validated that VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is found in opserver
2025-12-15 02:45:11,915 - DEBUG - Do not have enough data to verify VN in agent
2025-12-15 02:45:11,925 - DEBUG - VRF ids for VN ctest-VN1-00107366: {}
2025-12-15 02:45:11,925 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:11,931 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:11,940 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:12,026 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,039 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,052 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:45:12,060 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:45:12,067 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/2b0ebc77-87bc-4e34-b633-3141efee9b80
2025-12-15 02:45:12,072 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-15 02:45:12,073 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,081 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:45:12,099 - INFO - Verified VN network id 12 for VN 5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,099 - INFO - Verifications in API Server for VN ctest-VN2-50643407 passed
2025-12-15 02:45:12,099 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,108 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:45:12,115 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:45:12,121 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/2b0ebc77-87bc-4e34-b633-3141efee9b80
2025-12-15 02:45:12,132 - DEBUG - Control-node 10.0.0.23 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6608270211653126269', 'uuid-lslong': '13718370375476310460'}, 'enable': 'true', 'created': '2025-12-15T02:45:08', 'last-modified': '2025-12-15T02:45:09', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.760183'}
2025-12-15 02:45:12,137 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-15 02:45:12,144 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6608270211653126269', 'uuid-lslong': '13718370375476310460'}, 'enable': 'true', 'created': '2025-12-15T02:45:08', 'last-modified': '2025-12-15T02:45:09', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.770974'}
2025-12-15 02:45:12,151 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-15 02:45:12,157 - DEBUG - Control-node 10.0.0.65 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6608270211653126269', 'uuid-lslong': '13718370375476310460'}, 'enable': 'true', 'created': '2025-12-15T02:45:08', 'last-modified': '2025-12-15T02:45:09', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.786704'}
2025-12-15 02:45:12,163 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-15 02:45:12,163 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-VN2-50643407 passed
2025-12-15 02:45:12,163 - DEBUG - ====Verifying policy data for ctest-VN2-50643407 in API_Server ======
2025-12-15 02:45:12,164 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:12,169 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:12,181 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:12,288 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:12,299 - DEBUG - =>VN ctest-VN2-50643407 has no policy to be verified
2025-12-15 02:45:12,299 - DEBUG - Verifying the vn in opserver
2025-12-15 02:45:12,299 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 virtual network link through opserver 10.0.0.23
2025-12-15 02:45:12,299 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-networks
2025-12-15 02:45:12,356 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407?flat'}
2025-12-15 02:45:12,356 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 virtual network link through opserver 10.0.0.50
2025-12-15 02:45:12,356 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks
2025-12-15 02:45:12,413 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407?flat'}
2025-12-15 02:45:12,413 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 virtual network link through opserver 10.0.0.65
2025-12-15 02:45:12,414 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2025-12-15 02:45:12,468 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407?flat'}
2025-12-15 02:45:12,468 - INFO - Validated that VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 is found in opserver
2025-12-15 02:45:12,489 - DEBUG - Do not have enough data to verify VN in agent
2025-12-15 02:45:12,499 - DEBUG - VRF ids for VN ctest-VN2-50643407: {}
2025-12-15 02:45:12,499 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:12,505 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:12,516 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:12,611 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,625 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,636 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:45:12,649 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:45:12,655 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/0d282066-10ab-4d89-aa97-fd49a4f2cea8
2025-12-15 02:45:12,662 - DEBUG - Route Targets: ['target:64512:8000007']
2025-12-15 02:45:12,662 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,670 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:45:12,690 - INFO - Verified VN network id 13 for VN b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,690 - INFO - Verifications in API Server for VN ctest-VN3-83860196 passed
2025-12-15 02:45:12,690 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,700 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:45:12,708 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:45:12,715 - DEBUG - Requesting: http://10.0.0.23:8082/route-target/0d282066-10ab-4d89-aa97-fd49a4f2cea8
2025-12-15 02:45:12,727 - DEBUG - Control-node 10.0.0.23 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13349048065872186158', 'uuid-lslong': '11938169809376772490'}, 'enable': 'true', 'created': '2025-12-15T02:45:09', 'last-modified': '2025-12-15T02:45:10', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.439020'}
2025-12-15 02:45:12,733 - DEBUG - Route Targets: ['target:64512:8000007']
2025-12-15 02:45:12,738 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13349048065872186158', 'uuid-lslong': '11938169809376772490'}, 'enable': 'true', 'created': '2025-12-15T02:45:09', 'last-modified': '2025-12-15T02:45:10', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.447344'}
2025-12-15 02:45:12,744 - DEBUG - Route Targets: ['target:64512:8000007']
2025-12-15 02:45:12,750 - DEBUG - Control-node 10.0.0.65 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestPolicyAclIpv4v6-99364654', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13349048065872186158', 'uuid-lslong': '11938169809376772490'}, 'enable': 'true', 'created': '2025-12-15T02:45:09', 'last-modified': '2025-12-15T02:45:10', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:02.462005'}
2025-12-15 02:45:12,755 - DEBUG - Route Targets: ['target:64512:8000007']
2025-12-15 02:45:12,755 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-VN3-83860196 passed
2025-12-15 02:45:12,755 - DEBUG - ====Verifying policy data for ctest-VN3-83860196 in API_Server ======
2025-12-15 02:45:12,755 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:12,761 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:12,773 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:12,884 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/b941587d-57ed-4b2e-a5ac-e630c432018a
2025-12-15 02:45:12,893 - DEBUG - =>VN ctest-VN3-83860196 has no policy to be verified
2025-12-15 02:45:12,893 - DEBUG - Verifying the vn in opserver
2025-12-15 02:45:12,893 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 virtual network link through opserver 10.0.0.23
2025-12-15 02:45:12,893 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-networks
2025-12-15 02:45:12,956 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196?flat'}
2025-12-15 02:45:12,956 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 virtual network link through opserver 10.0.0.50
2025-12-15 02:45:12,956 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks
2025-12-15 02:45:13,015 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196?flat'}
2025-12-15 02:45:13,015 - DEBUG - Verifying the default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 virtual network link through opserver 10.0.0.65
2025-12-15 02:45:13,015 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-networks
2025-12-15 02:45:13,074 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196?flat'}
2025-12-15 02:45:13,074 - INFO - Validated that VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 is found in opserver
2025-12-15 02:45:13,097 - DEBUG - Do not have enough data to verify VN in agent
2025-12-15 02:45:13,108 - DEBUG - VRF ids for VN ctest-VN3-83860196: {}
2025-12-15 02:45:13,115 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = any, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366, 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-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = deny, 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-12-15 02:45:13,407 - DEBUG - No source network defined
2025-12-15 02:45:13,407 - DEBUG - No source network defined
2025-12-15 02:45:13,407 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = None, security_group = None, network_policy = default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-policy13-44122466, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = any, 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, rule_sequence = None, rule_uuid = None, direction = <>, protocol = 58, src_addresses = [subnet = None, virtual_network = None, security_group = None, network_policy = default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-policy13-44122466, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = any, 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-12-15 02:45:13,683 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407, 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-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366, 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, rule_sequence = None, rule_uuid = None, direction = <>, protocol = 58, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407, 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-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366, 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-12-15 02:45:13,908 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:13,913 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:13,923 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:14,025 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:45:14,034 - DEBUG - Setup step: Associating the policy to VN'
2025-12-15 02:45:14,162 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '669d6e32-9031-420b-a7d3-e54b1b53d88f', 'name': 'ctest-VN1-00107366', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['7e6b6d8d-c7d5-4878-b945-d4ce302c0bc8', 'a95cdb0e-0797-40dc-91a8-55614d0567e7'], 'fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-VN1-00107366'], 'policys': [['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy12-03344844'], ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy13-44122466']], 'subnet_ipam': [{'subnet_cidr': '85.104.11.0/26', 'ipam_fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ipam1']}, {'subnet_cidr': '332e:6146:1a2a:12f6:b0fb:a249::/96', 'ipam_fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ipam1']}], 'port_security_enabled': True, 'description': ''}}
2025-12-15 02:45:14,327 - DEBUG - Associated Policy:[['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy12-03344844'], ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy13-44122466']] to ctest-VN1-00107366
2025-12-15 02:45:14,327 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:45:14,333 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:45:14,344 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:45:14,433 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:45:14,444 - DEBUG - Setup step: Associating the policy to VN'
2025-12-15 02:45:14,552 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '5bb54abe-d161-487d-be61-712c6781f1bc', 'name': 'ctest-VN2-50643407', 'tenant_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'project_id': 'ff1377e7bbdc42ce9ed9998cc8e12a64', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['66d4a62b-fbf1-4885-85c9-993bf366ad18', '1b7f4e95-cf21-4503-bf04-c0ca9ef2307e'], 'fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-VN2-50643407'], 'policys': [['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy21-78881754']], 'subnet_ipam': [{'subnet_cidr': '73.186.102.0/26', 'ipam_fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ipam2']}, {'subnet_cidr': '28a7:17e2:11e8:17b1:194a:43f4::/96', 'ipam_fq_name': ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ipam2']}], 'port_security_enabled': True, 'description': ''}}
2025-12-15 02:45:14,647 - DEBUG - Associated Policy:[['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy21-78881754']] to ctest-VN2-50643407
2025-12-15 02:45:14,774 - DEBUG - Services list from nova: [, , , ]
2025-12-15 02:45:15,851 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4894-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4894-2)
2025-12-15 02:45:17,263 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4894-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4894-1)
2025-12-15 02:45:18,688 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4894-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4894-2)
2025-12-15 02:45:18,778 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:45:18,779 - INFO - VM name : ctest-VM11-89586208
2025-12-15 02:45:18,866 - DEBUG - VM ctest-VM11-89586208 ID is 41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:18,957 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:45:18,987 - DEBUG - VM ctest-VM11-89586208 launched on Node an-jenkins-deploy-platform-ansible-os-4894-2
2025-12-15 02:45:19,132 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:19,563 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:19,627 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:19,637 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/3fbad784-fbf3-4c04-b58d-22b602ad848e
2025-12-15 02:45:19,663 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:19,679 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/3fbad784-fbf3-4c04-b58d-22b602ad848e
2025-12-15 02:45:19,690 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/5651547a-ab2e-4808-ad78-d879be150088
2025-12-15 02:45:19,702 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/5f430db7-b6a0-4598-8531-16fb6c6815e2
2025-12-15 02:45:19,715 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:45:19,715 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:45:19,724 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/3fbad784-fbf3-4c04-b58d-22b602ad848e
2025-12-15 02:45:19,733 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/5651547a-ab2e-4808-ad78-d879be150088
2025-12-15 02:45:19,742 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/5f430db7-b6a0-4598-8531-16fb6c6815e2
2025-12-15 02:45:19,751 - INFO - VM ctest-VM11-89586208 verfication in all API Servers passed
2025-12-15 02:45:19,770 - DEBUG - VM ctest-VM11-89586208 Tap interface: {'index': '3', 'name': 'tap3fbad784-fb', 'uuid': '3fbad784-fbf3-4c04-b58d-22b602ad848e', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366:ctest-VN1-00107366', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '11', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'vm_uuid': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'vm_name': 'ctest-VM11-89586208', 'ip_addr': '85.104.11.3', 'mac_addr': '02:3f:ba:d7:84:fb', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '50', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '31', 'allowed_address_pair_list': None, 'ip6_addr': '332e:6146:1a2a:12f6:b0fb:a249:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:45:19,770 - DEBUG - Agent 10.0.0.27 vrf name: default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366:ctest-VN1-00107366
2025-12-15 02:45:19,784 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366:ctest-VN1-00107366', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'table_label': '-1', 'vxlan_id': '11', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.19:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-15 02:45:19,882 - DEBUG - VM ctest-VM11-89586208 : Tap interface tap3fbad784-fb is set to Active
2025-12-15 02:45:19,882 - DEBUG - Tap interface tap3fbad784-fb detail : {'index': '3', 'name': 'tap3fbad784-fb', 'uuid': '3fbad784-fbf3-4c04-b58d-22b602ad848e', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366:ctest-VN1-00107366', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '11', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', 'vm_uuid': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'vm_name': 'ctest-VM11-89586208', 'ip_addr': '85.104.11.3', 'mac_addr': '02:3f:ba:d7:84:fb', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '50', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '31', 'allowed_address_pair_list': None, 'ip6_addr': '332e:6146:1a2a:12f6:b0fb:a249:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:45:20,000 - DEBUG - Starting Layer 2 verification in Agent
2025-12-15 02:45:20,020 - DEBUG - Layer 2 path is seen for VM MAC 02:3f:ba:d7:84:fb in agent 10.0.0.27
2025-12-15 02:45:20,021 - DEBUG - Active layer 2 route in agent is present for VMI tap3fbad784-fb
2025-12-15 02:45:20,021 - DEBUG - L2 label(29) matches bw route table and interface table
2025-12-15 02:45:20,053 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is found in Agent of node 10.0.0.27
2025-12-15 02:45:20,253 - DEBUG - VRF IDs of VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is consistent in agent 10.0.0.27
2025-12-15 02:45:20,253 - DEBUG - Route for VM IP ['85.104.11.3', '332e:6146:1a2a:12f6:b0fb:a249:0:3'] is consistent in agent 10.0.0.27
2025-12-15 02:45:20,253 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 verification for VM ctest-VM11-89586208 in Agent 10.0.0.27 passed
2025-12-15 02:45:20,327 - DEBUG - Starting all layer 2 verification in agent 10.0.0.27
2025-12-15 02:45:20,344 - DEBUG - Route for VM MAC 02:3f:ba:d7:84:fb is consistent in agent 10.0.0.27
2025-12-15 02:45:23,535 - 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 1018ms')
2025-12-15 02:45:23,535 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:23,591 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:23,591 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:27,667 - 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 1017ms')
2025-12-15 02:45:27,668 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:27,724 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:27,724 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:31,799 - 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 1008ms')
2025-12-15 02:45:31,799 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:31,813 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:31,813 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:35,894 - 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 1018ms')
2025-12-15 02:45:35,894 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:35,952 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:35,952 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:40,020 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1006ms')
2025-12-15 02:45:40,020 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:40,038 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:40,038 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:44,121 - 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 1022ms')
2025-12-15 02:45:44,121 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:44,137 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:44,137 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:48,216 - 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-12-15 02:45:48,216 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:48,233 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:48,233 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:52,305 - 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 1013ms')
2025-12-15 02:45:52,305 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:52,320 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:52,320 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:45:56,407 - 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 1023ms')
2025-12-15 02:45:56,407 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:45:56,469 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:45:56,469 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:46:00,559 - 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-12-15 02:46:00,559 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:46:00,616 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:46:00,616 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:46:04,693 - 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-12-15 02:46:04,693 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:46:04,751 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:46:04,751 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:46:08,821 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1006ms')
2025-12-15 02:46:08,822 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:46:08,880 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:46:08,880 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:46:12,944 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1006ms')
2025-12-15 02:46:12,944 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 failed!
2025-12-15 02:46:12,961 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 85.104.11.1 and allocation pool is NOT set
2025-12-15 02:46:12,961 - DEBUG - Gateway for vn default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 is 332e:6146:1a2a:12f6:b0fb:a249:0:1 and allocation pool is NOT set
2025-12-15 02:46:15,032 - 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=8.55 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.40 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.401/4.975/8.549/3.574 ms')
2025-12-15 02:46:15,032 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 passed
2025-12-15 02:46:15,032 - INFO - VM ctest-VM11-89586208 verifications in Compute nodes passed
2025-12-15 02:46:15,316 - DEBUG - Validated VM route 85.104.11.3 in vrouter of 10.0.0.27
2025-12-15 02:46:15,322 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-15 02:46:15,322 - INFO - Validated routes of VM ctest-VM11-89586208 in all vrouters
2025-12-15 02:46:15,756 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node
2025-12-15 02:46:15,880 - DEBUG - Layer2 route found for VM MAC 02:3f:ba:d7:84:fb in Control-node 10.0.0.50
2025-12-15 02:46:15,880 - DEBUG - L2 Label for VM ctest-VM11-89586208 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:15,994 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.50, not supported
2025-12-15 02:46:15,994 - DEBUG - Starting all layer2 verification in 10.0.0.23 Control Node
2025-12-15 02:46:16,118 - DEBUG - Layer2 route found for VM MAC 02:3f:ba:d7:84:fb in Control-node 10.0.0.23
2025-12-15 02:46:16,118 - DEBUG - L2 Label for VM ctest-VM11-89586208 same between Control-node 10.0.0.23 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:16,231 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.23, not supported
2025-12-15 02:46:16,232 - DEBUG - Starting all layer2 verification in 10.0.0.65 Control Node
2025-12-15 02:46:16,357 - DEBUG - Layer2 route found for VM MAC 02:3f:ba:d7:84:fb in Control-node 10.0.0.65
2025-12-15 02:46:16,357 - DEBUG - L2 Label for VM ctest-VM11-89586208 same between Control-node 10.0.0.65 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:16,473 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.65, not supported
2025-12-15 02:46:16,473 - INFO - Verification in Control-nodes for VM ctest-VM11-89586208 passed
2025-12-15 02:46:16,473 - DEBUG - Verifying the vm in opserver
2025-12-15 02:46:16,473 - DEBUG - Verifying in collector 10.0.0.65 ...
2025-12-15 02:46:16,473 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat
2025-12-15 02:46:16,489 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e?flat
2025-12-15 02:46:16,507 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e?flat
2025-12-15 02:46:16,524 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e?flat
2025-12-15 02:46:16,541 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat
2025-12-15 02:46:16,556 - DEBUG - Verifying vm in vn uve
2025-12-15 02:46:16,556 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e?flat
2025-12-15 02:46:16,572 - DEBUG - VM uve shows interface as {'ip_address': '85.104.11.3', 'l2_active': True, 'vm_name': 'ctest-VM11-89586208', 'port_mirror_enabled': False, 'rx_vlan': 65535, 'mac_address': '02:3f:ba:d7:84:fb', 'uuid': '3fbad784-fbf3-4c04-b58d-22b602ad848e', 'vn_uuid': '669d6e32-9031-420b-a7d3-e54b1b53d88f', 'tx_vlan': 65535, 'ip4_active': True, 'fixed_ip6_list': ['332e:6146:1a2a:12f6:b0fb:a249:0:3'], 'vhostuser_mode': 0, 'active': True, 'vm_uuid': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'fixed_ip4_list': ['85.104.11.3'], 'ip6_active': True, 'virtual_network': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366', '__T': 1765766722217121, 'is_health_check_active': True, 'label': 25, 'gateway': '85.104.11.1', 'admin_state': True, 'ip6_address': '332e:6146:1a2a:12f6:b0fb:a249:0:3'}
2025-12-15 02:46:16,572 - DEBUG - VM uve shows ip address as ['85.104.11.3', '332e:6146:1a2a:12f6:b0fb:a249:0:3']
2025-12-15 02:46:16,572 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:46:16,572 - INFO - Verifying through opserver in 10.0.0.23
2025-12-15 02:46:16,572 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366?flat
2025-12-15 02:46:16,590 - DEBUG - expected vm list 41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:46:16,590 - DEBUG - Extracted vm list ['41d05718-096f-4b78-9c5b-e675d5ad37b5']
2025-12-15 02:46:16,590 - INFO - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is present in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:46:16,590 - DEBUG - Verifying vm in vrouter uve
2025-12-15 02:46:16,590 - DEBUG - Getting info from collector 10.0.0.65..
2025-12-15 02:46:16,590 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat
2025-12-15 02:46:16,609 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4894-2']
2025-12-15 02:46:16,609 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:16,642 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:46:16,671 - DEBUG - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:16,671 - DEBUG - Validated that VM ctest-VM11-89586208 is in Vrouter an-jenkins-deploy-platform-ansible-os-4894-2 UVE
2025-12-15 02:46:16,671 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-15 02:46:16,678 - DEBUG - Expected tap interface of VM uuid 41d05718-096f-4b78-9c5b-e675d5ad37b5 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e
2025-12-15 02:46:16,678 - DEBUG - Expected VN of VM uuid 41d05718-096f-4b78-9c5b-e675d5ad37b5 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:46:16,678 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:16,708 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:46:16,737 - DEBUG - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:16,737 - INFO - tap interface default-domain:ctest-TestPolicyAclIpv4v6-99364654:3fbad784-fbf3-4c04-b58d-22b602ad848e of vm 41d05718-096f-4b78-9c5b-e675d5ad37b5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:16,737 - DEBUG - Connected network default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 of vm 41d05718-096f-4b78-9c5b-e675d5ad37b5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:16,737 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.23
2025-12-15 02:46:16,737 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:46:16,749 - DEBUG - VM link and name as {'name': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat'}
2025-12-15 02:46:16,749 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.50
2025-12-15 02:46:16,749 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:46:16,760 - DEBUG - VM link and name as {'name': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat'}
2025-12-15 02:46:16,760 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.65
2025-12-15 02:46:16,760 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:46:16,772 - DEBUG - VM link and name as {'name': '41d05718-096f-4b78-9c5b-e675d5ad37b5', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5?flat'}
2025-12-15 02:46:16,772 - INFO - VM ctest-VM11-89586208 validations in Opserver passed
2025-12-15 02:46:16,845 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:46:16,845 - INFO - VM name : ctest-VM21-73227528
2025-12-15 02:46:16,922 - DEBUG - VM ctest-VM21-73227528 ID is d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:16,995 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:46:16,995 - DEBUG - VM ctest-VM21-73227528 launched on Node an-jenkins-deploy-platform-ansible-os-4894-1
2025-12-15 02:46:17,081 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:17,091 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:17,099 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2ff05e85-b796-49aa-88c0-883a9e468bdc
2025-12-15 02:46:17,109 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:17,116 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2ff05e85-b796-49aa-88c0-883a9e468bdc
2025-12-15 02:46:17,127 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/826fa3c4-9e1e-4a2d-8eeb-4ab530a05885
2025-12-15 02:46:17,138 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/d166da2d-3efd-424a-96cb-df100a2252c6
2025-12-15 02:46:17,148 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:46:17,148 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:17,156 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2ff05e85-b796-49aa-88c0-883a9e468bdc
2025-12-15 02:46:17,166 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/826fa3c4-9e1e-4a2d-8eeb-4ab530a05885
2025-12-15 02:46:17,174 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/d166da2d-3efd-424a-96cb-df100a2252c6
2025-12-15 02:46:17,182 - INFO - VM ctest-VM21-73227528 verfication in all API Servers passed
2025-12-15 02:46:17,201 - DEBUG - VM ctest-VM21-73227528 Tap interface: {'index': '3', 'name': 'tap2ff05e85-b7', 'uuid': '2ff05e85-b796-49aa-88c0-883a9e468bdc', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407:ctest-VN2-50643407', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'vm_uuid': 'd2450e88-639c-44e5-8f66-ed6d8a756a46', 'vm_name': 'ctest-VM21-73227528', 'ip_addr': '73.186.102.3', 'mac_addr': '02:2f:f0:5e:85:b7', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '44', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '30', 'allowed_address_pair_list': None, 'ip6_addr': '28a7:17e2:11e8:17b1:194a:43f4:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:46:17,201 - DEBUG - Agent 10.0.0.22 vrf name: default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407:ctest-VN2-50643407
2025-12-15 02:46:17,208 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407:ctest-VN2-50643407', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'table_label': '-1', 'vxlan_id': '12', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.252:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-15 02:46:17,339 - DEBUG - VM ctest-VM21-73227528 : Tap interface tap2ff05e85-b7 is set to Active
2025-12-15 02:46:17,339 - DEBUG - Tap interface tap2ff05e85-b7 detail : {'index': '3', 'name': 'tap2ff05e85-b7', 'uuid': '2ff05e85-b796-49aa-88c0-883a9e468bdc', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407:ctest-VN2-50643407', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'vm_uuid': 'd2450e88-639c-44e5-8f66-ed6d8a756a46', 'vm_name': 'ctest-VM21-73227528', 'ip_addr': '73.186.102.3', 'mac_addr': '02:2f:f0:5e:85:b7', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '44', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '30', 'allowed_address_pair_list': None, 'ip6_addr': '28a7:17e2:11e8:17b1:194a:43f4:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:46:17,448 - DEBUG - Starting Layer 2 verification in Agent
2025-12-15 02:46:17,460 - DEBUG - Layer 2 path is seen for VM MAC 02:2f:f0:5e:85:b7 in agent 10.0.0.22
2025-12-15 02:46:17,460 - DEBUG - Active layer 2 route in agent is present for VMI tap2ff05e85-b7
2025-12-15 02:46:17,460 - DEBUG - L2 label(29) matches bw route table and interface table
2025-12-15 02:46:17,468 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 is found in Agent of node 10.0.0.22
2025-12-15 02:46:17,611 - DEBUG - VRF IDs of VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 is consistent in agent 10.0.0.22
2025-12-15 02:46:17,611 - DEBUG - Route for VM IP ['73.186.102.3', '28a7:17e2:11e8:17b1:194a:43f4:0:3'] is consistent in agent 10.0.0.22
2025-12-15 02:46:17,611 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 verification for VM ctest-VM21-73227528 in Agent 10.0.0.22 passed
2025-12-15 02:46:17,729 - DEBUG - Starting all layer 2 verification in agent 10.0.0.22
2025-12-15 02:46:17,738 - DEBUG - Route for VM MAC 02:2f:f0:5e:85:b7 is consistent in agent 10.0.0.22
2025-12-15 02:46:18,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=4.76 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.341 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.341/2.549/4.757/2.208 ms')
2025-12-15 02:46:18,934 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM21-73227528 passed
2025-12-15 02:46:18,934 - INFO - VM ctest-VM21-73227528 verifications in Compute nodes passed
2025-12-15 02:46:19,210 - DEBUG - Validated VM route 73.186.102.3 in vrouter of 10.0.0.22
2025-12-15 02:46:19,216 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-15 02:46:19,216 - INFO - Validated routes of VM ctest-VM21-73227528 in all vrouters
2025-12-15 02:46:19,640 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node
2025-12-15 02:46:19,773 - DEBUG - Layer2 route found for VM MAC 02:2f:f0:5e:85:b7 in Control-node 10.0.0.50
2025-12-15 02:46:19,773 - DEBUG - L2 Label for VM ctest-VM21-73227528 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:19,889 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.50, not supported
2025-12-15 02:46:19,889 - DEBUG - Starting all layer2 verification in 10.0.0.23 Control Node
2025-12-15 02:46:20,015 - DEBUG - Layer2 route found for VM MAC 02:2f:f0:5e:85:b7 in Control-node 10.0.0.23
2025-12-15 02:46:20,016 - DEBUG - L2 Label for VM ctest-VM21-73227528 same between Control-node 10.0.0.23 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:20,127 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.23, not supported
2025-12-15 02:46:20,127 - DEBUG - Starting all layer2 verification in 10.0.0.65 Control Node
2025-12-15 02:46:20,251 - DEBUG - Layer2 route found for VM MAC 02:2f:f0:5e:85:b7 in Control-node 10.0.0.65
2025-12-15 02:46:20,251 - DEBUG - L2 Label for VM ctest-VM21-73227528 same between Control-node 10.0.0.65 and Agent, Expected: 29, Seen: 29
2025-12-15 02:46:20,365 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.65, not supported
2025-12-15 02:46:20,365 - INFO - Verification in Control-nodes for VM ctest-VM21-73227528 passed
2025-12-15 02:46:20,366 - DEBUG - Verifying the vm in opserver
2025-12-15 02:46:20,366 - DEBUG - Verifying in collector 10.0.0.65 ...
2025-12-15 02:46:20,366 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat
2025-12-15 02:46:20,382 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc?flat
2025-12-15 02:46:20,400 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc?flat
2025-12-15 02:46:20,420 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc?flat
2025-12-15 02:46:20,438 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat
2025-12-15 02:46:20,456 - DEBUG - Verifying vm in vn uve
2025-12-15 02:46:20,456 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc?flat
2025-12-15 02:46:20,474 - DEBUG - VM uve shows interface as {'ip4_active': True, 'uuid': '2ff05e85-b796-49aa-88c0-883a9e468bdc', '__T': 1765766743959572, 'fixed_ip6_list': ['28a7:17e2:11e8:17b1:194a:43f4:0:3'], 'vm_name': 'ctest-VM21-73227528', 'port_mirror_enabled': False, 'fixed_ip4_list': ['73.186.102.3'], 'l2_active': True, 'mac_address': '02:2f:f0:5e:85:b7', 'ip_address': '73.186.102.3', 'virtual_network': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407', 'rx_vlan': 65535, 'label': 25, 'ip6_active': True, 'ip6_address': '28a7:17e2:11e8:17b1:194a:43f4:0:3', 'vhostuser_mode': 0, 'gateway': '73.186.102.1', 'admin_state': True, 'active': True, 'tx_vlan': 65535, 'vn_uuid': '5bb54abe-d161-487d-be61-712c6781f1bc', 'is_health_check_active': True, 'vm_uuid': 'd2450e88-639c-44e5-8f66-ed6d8a756a46'}
2025-12-15 02:46:20,475 - DEBUG - VM uve shows ip address as ['73.186.102.3', '28a7:17e2:11e8:17b1:194a:43f4:0:3']
2025-12-15 02:46:20,475 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:46:20,475 - INFO - Verifying through opserver in 10.0.0.23
2025-12-15 02:46:20,475 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407?flat
2025-12-15 02:46:20,496 - DEBUG - expected vm list d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:20,496 - DEBUG - Extracted vm list ['d2450e88-639c-44e5-8f66-ed6d8a756a46']
2025-12-15 02:46:20,497 - INFO - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is present in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:46:20,497 - DEBUG - Verifying vm in vrouter uve
2025-12-15 02:46:20,497 - DEBUG - Getting info from collector 10.0.0.65..
2025-12-15 02:46:20,497 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat
2025-12-15 02:46:20,513 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4894-1']
2025-12-15 02:46:20,514 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:20,545 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:46:20,575 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:46:20,575 - DEBUG - Validated that VM ctest-VM21-73227528 is in Vrouter an-jenkins-deploy-platform-ansible-os-4894-1 UVE
2025-12-15 02:46:20,575 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-15 02:46:20,581 - DEBUG - Expected tap interface of VM uuid d2450e88-639c-44e5-8f66-ed6d8a756a46 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc
2025-12-15 02:46:20,582 - DEBUG - Expected VN of VM uuid d2450e88-639c-44e5-8f66-ed6d8a756a46 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:46:20,582 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:20,615 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:46:20,645 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:46:20,645 - INFO - tap interface default-domain:ctest-TestPolicyAclIpv4v6-99364654:2ff05e85-b796-49aa-88c0-883a9e468bdc of vm d2450e88-639c-44e5-8f66-ed6d8a756a46 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:46:20,645 - DEBUG - Connected network default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 of vm d2450e88-639c-44e5-8f66-ed6d8a756a46 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:46:20,645 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.23
2025-12-15 02:46:20,645 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:46:20,660 - DEBUG - VM link and name as {'name': 'd2450e88-639c-44e5-8f66-ed6d8a756a46', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat'}
2025-12-15 02:46:20,660 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.50
2025-12-15 02:46:20,661 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:46:20,675 - DEBUG - VM link and name as {'name': 'd2450e88-639c-44e5-8f66-ed6d8a756a46', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat'}
2025-12-15 02:46:20,675 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.65
2025-12-15 02:46:20,675 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:46:20,688 - DEBUG - VM link and name as {'name': 'd2450e88-639c-44e5-8f66-ed6d8a756a46', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46?flat'}
2025-12-15 02:46:20,688 - INFO - VM ctest-VM21-73227528 validations in Opserver passed
2025-12-15 02:46:20,798 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:46:20,798 - INFO - VM name : ctest-VM31-57128789
2025-12-15 02:46:20,880 - DEBUG - VM ctest-VM31-57128789 ID is 90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:20,963 - DEBUG - VM is in ACTIVE state now
2025-12-15 02:46:20,963 - DEBUG - VM ctest-VM31-57128789 launched on Node an-jenkins-deploy-platform-ansible-os-4894-2
2025-12-15 02:46:21,045 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:21,055 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:21,063 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2e7f0aab-41b7-41cc-ac92-2534da082c5d
2025-12-15 02:46:21,078 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:21,086 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2e7f0aab-41b7-41cc-ac92-2534da082c5d
2025-12-15 02:46:21,096 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/7dbaeea2-1f07-4fb1-aea1-43c5f44265da
2025-12-15 02:46:21,106 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/cdffaf1f-8dd4-4692-9f86-1f17089576cb
2025-12-15 02:46:21,116 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:46:21,116 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:21,124 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2e7f0aab-41b7-41cc-ac92-2534da082c5d
2025-12-15 02:46:21,135 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/7dbaeea2-1f07-4fb1-aea1-43c5f44265da
2025-12-15 02:46:21,143 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/cdffaf1f-8dd4-4692-9f86-1f17089576cb
2025-12-15 02:46:21,151 - INFO - VM ctest-VM31-57128789 verfication in all API Servers passed
2025-12-15 02:46:21,170 - DEBUG - VM ctest-VM31-57128789 Tap interface: {'index': '4', 'name': 'tap2e7f0aab-41', 'uuid': '2e7f0aab-41b7-41cc-ac92-2534da082c5d', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196:ctest-VN3-83860196', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '32', 'l2_label': '36', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'vm_uuid': '90923bb1-8430-4608-b408-0964070cea84', 'vm_name': 'ctest-VM31-57128789', 'ip_addr': '18.46.17.67', 'mac_addr': '02:2e:7f:0a:ab:41', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '51', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '41', 'allowed_address_pair_list': None, 'ip6_addr': '2ec7:92ea:56aa:3f67:4289:8f20:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:46:21,171 - DEBUG - Agent 10.0.0.27 vrf name: default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196:ctest-VN3-83860196
2025-12-15 02:46:21,176 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196:ctest-VN3-83860196', 'ucindex': '3', 'mcindex': '3', 'l2index': '3', 'source': 'Config; ', 'uc6index': '3', 'vn': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '3', 'brindex': '3', 'mplsindex': '0', 'RD': '10.20.0.19:3', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-15 02:46:21,272 - DEBUG - VM ctest-VM31-57128789 : Tap interface tap2e7f0aab-41 is set to Active
2025-12-15 02:46:21,272 - DEBUG - Tap interface tap2e7f0aab-41 detail : {'index': '4', 'name': 'tap2e7f0aab-41', 'uuid': '2e7f0aab-41b7-41cc-ac92-2534da082c5d', 'vrf_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196:ctest-VN3-83860196', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Active', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Enable', 'dns_service': 'Enable', 'type': 'vport', 'label': '32', 'l2_label': '36', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', 'vm_uuid': '90923bb1-8430-4608-b408-0964070cea84', 'vm_name': 'ctest-VM31-57128789', 'ip_addr': '18.46.17.67', 'mac_addr': '02:2e:7f:0a:ab:41', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '51', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d', 'sg_uuid_list': ['c97f4a8a-225a-4d18-bf10-871b5e7dfdc3'], 'static_route_list': None, 'vm_project_uuid': 'ff1377e7-bbdc-42ce-9ed9-998cc8e12a64', 'admin_state': 'Enabled', 'flow_key_idx': '41', 'allowed_address_pair_list': None, 'ip6_addr': '2ec7:92ea:56aa:3f67:4289:8f20:0:3', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-12-15 02:46:21,383 - DEBUG - Starting Layer 2 verification in Agent
2025-12-15 02:46:21,394 - DEBUG - Layer 2 path is seen for VM MAC 02:2e:7f:0a:ab:41 in agent 10.0.0.27
2025-12-15 02:46:21,394 - DEBUG - Active layer 2 route in agent is present for VMI tap2e7f0aab-41
2025-12-15 02:46:21,394 - DEBUG - L2 label(36) matches bw route table and interface table
2025-12-15 02:46:21,404 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 is found in Agent of node 10.0.0.27
2025-12-15 02:46:21,547 - DEBUG - VRF IDs of VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 is consistent in agent 10.0.0.27
2025-12-15 02:46:21,547 - DEBUG - Route for VM IP ['2ec7:92ea:56aa:3f67:4289:8f20:0:3', '18.46.17.67'] is consistent in agent 10.0.0.27
2025-12-15 02:46:21,547 - DEBUG - VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 verification for VM ctest-VM31-57128789 in Agent 10.0.0.27 passed
2025-12-15 02:46:21,667 - DEBUG - Starting all layer 2 verification in agent 10.0.0.27
2025-12-15 02:46:21,695 - DEBUG - Route for VM MAC 02:2e:7f:0a:ab:41 is consistent in agent 10.0.0.27
2025-12-15 02:46:22,873 - 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.41 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.36 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 = 1.356/2.884/4.413/1.528 ms')
2025-12-15 02:46:22,873 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-57128789 passed
2025-12-15 02:46:22,873 - INFO - VM ctest-VM31-57128789 verifications in Compute nodes passed
2025-12-15 02:46:23,065 - DEBUG - Validated VM route 18.46.17.67 in vrouter of 10.0.0.27
2025-12-15 02:46:23,070 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-15 02:46:23,070 - INFO - Validated routes of VM ctest-VM31-57128789 in all vrouters
2025-12-15 02:46:23,640 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node
2025-12-15 02:46:23,755 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.50, not supported
2025-12-15 02:46:23,888 - DEBUG - Layer2 route found for VM MAC 02:2e:7f:0a:ab:41 in Control-node 10.0.0.50
2025-12-15 02:46:23,888 - DEBUG - L2 Label for VM ctest-VM31-57128789 same between Control-node 10.0.0.50 and Agent, Expected: 36, Seen: 36
2025-12-15 02:46:23,888 - DEBUG - Starting all layer2 verification in 10.0.0.65 Control Node
2025-12-15 02:46:23,999 - DEBUG - Skipping L2 verification of v6 route on cn 10.0.0.65, not supported
2025-12-15 02:46:24,136 - DEBUG - Layer2 route found for VM MAC 02:2e:7f:0a:ab:41 in Control-node 10.0.0.65
2025-12-15 02:46:24,137 - DEBUG - L2 Label for VM ctest-VM31-57128789 same between Control-node 10.0.0.65 and Agent, Expected: 36, Seen: 36
2025-12-15 02:46:24,137 - INFO - Verification in Control-nodes for VM ctest-VM31-57128789 passed
2025-12-15 02:46:24,137 - DEBUG - Verifying the vm in opserver
2025-12-15 02:46:24,137 - DEBUG - Verifying in collector 10.0.0.65 ...
2025-12-15 02:46:24,137 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat
2025-12-15 02:46:24,155 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d?flat
2025-12-15 02:46:24,174 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d?flat
2025-12-15 02:46:24,197 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d?flat
2025-12-15 02:46:24,213 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat
2025-12-15 02:46:24,231 - DEBUG - Verifying vm in vn uve
2025-12-15 02:46:24,231 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d?flat
2025-12-15 02:46:24,247 - DEBUG - VM uve shows interface as {'ip_address': '18.46.17.67', 'l2_active': True, 'vm_name': 'ctest-VM31-57128789', 'port_mirror_enabled': False, 'rx_vlan': 65535, 'mac_address': '02:2e:7f:0a:ab:41', 'uuid': '2e7f0aab-41b7-41cc-ac92-2534da082c5d', 'vn_uuid': 'b941587d-57ed-4b2e-a5ac-e630c432018a', 'tx_vlan': 65535, 'ip4_active': True, 'fixed_ip6_list': ['2ec7:92ea:56aa:3f67:4289:8f20:0:3'], 'vhostuser_mode': 0, 'active': True, 'vm_uuid': '90923bb1-8430-4608-b408-0964070cea84', 'fixed_ip4_list': ['18.46.17.67'], 'ip6_active': True, 'virtual_network': 'default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196', '__T': 1765766722217070, 'is_health_check_active': True, 'label': 32, 'gateway': '18.46.17.65', 'admin_state': True, 'ip6_address': '2ec7:92ea:56aa:3f67:4289:8f20:0:3'}
2025-12-15 02:46:24,247 - DEBUG - VM uve shows ip address as ['18.46.17.67', '2ec7:92ea:56aa:3f67:4289:8f20:0:3']
2025-12-15 02:46:24,247 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:46:24,247 - INFO - Verifying through opserver in 10.0.0.23
2025-12-15 02:46:24,247 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196?flat
2025-12-15 02:46:24,276 - DEBUG - expected vm list 90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:24,276 - DEBUG - Extracted vm list ['90923bb1-8430-4608-b408-0964070cea84']
2025-12-15 02:46:24,276 - INFO - VM 90923bb1-8430-4608-b408-0964070cea84 is present in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:46:24,276 - DEBUG - Verifying vm in vrouter uve
2025-12-15 02:46:24,276 - DEBUG - Getting info from collector 10.0.0.65..
2025-12-15 02:46:24,276 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat
2025-12-15 02:46:24,294 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4894-2']
2025-12-15 02:46:24,294 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:24,326 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:46:24,358 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:24,358 - DEBUG - Validated that VM ctest-VM31-57128789 is in Vrouter an-jenkins-deploy-platform-ansible-os-4894-2 UVE
2025-12-15 02:46:24,358 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-15 02:46:24,366 - DEBUG - Expected tap interface of VM uuid 90923bb1-8430-4608-b408-0964070cea84 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d
2025-12-15 02:46:24,366 - DEBUG - Expected VN of VM uuid 90923bb1-8430-4608-b408-0964070cea84 is default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:46:24,366 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:46:24,399 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:46:24,425 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:24,425 - INFO - tap interface default-domain:ctest-TestPolicyAclIpv4v6-99364654:2e7f0aab-41b7-41cc-ac92-2534da082c5d of vm 90923bb1-8430-4608-b408-0964070cea84 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:24,425 - DEBUG - Connected network default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 of vm 90923bb1-8430-4608-b408-0964070cea84 is present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:46:24,425 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.23
2025-12-15 02:46:24,425 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:46:24,437 - DEBUG - VM link and name as {'name': '90923bb1-8430-4608-b408-0964070cea84', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat'}
2025-12-15 02:46:24,437 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.50
2025-12-15 02:46:24,437 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:46:24,450 - DEBUG - VM link and name as {'name': '90923bb1-8430-4608-b408-0964070cea84', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat'}
2025-12-15 02:46:24,450 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.65
2025-12-15 02:46:24,450 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:46:24,463 - DEBUG - VM link and name as {'name': '90923bb1-8430-4608-b408-0964070cea84', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-machine/90923bb1-8430-4608-b408-0964070cea84?flat'}
2025-12-15 02:46:24,463 - INFO - VM ctest-VM31-57128789 validations in Opserver passed
2025-12-15 02:46:24,463 - INFO - Waiting for VM ctest-VM11-89586208 to be up..
2025-12-15 02:46:24,463 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:24,464 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:46:24,471 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/3fbad784-fbf3-4c04-b58d-22b602ad848e
2025-12-15 02:46:25,639 - 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=1.27 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.17 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 = 1.265/2.218/3.171/0.953 ms')
2025-12-15 02:46:25,640 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-89586208 passed
2025-12-15 02:46:25,708 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:25,708 - DEBUG - Waiting to SSH to VM ctest-VM11-89586208, IP 85.104.11.3, Port 22
2025-12-15 02:46:25,777 - DEBUG - Error on ssh to ubuntu@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-12-15 02:46:25,873 - DEBUG - VM ctest-VM11-89586208 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-15 02:46:30,873 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:30,873 - DEBUG - Waiting to SSH to VM ctest-VM11-89586208, IP 85.104.11.3, Port 22
2025-12-15 02:46:30,940 - DEBUG - Error on ssh to ubuntu@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-12-15 02:46:31,018 - DEBUG - VM ctest-VM11-89586208 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-15 02:46:36,019 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:36,019 - DEBUG - Waiting to SSH to VM ctest-VM11-89586208, IP 85.104.11.3, Port 22
2025-12-15 02:46:36,084 - DEBUG - Error on ssh to ubuntu@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-12-15 02:46:36,155 - DEBUG - VM ctest-VM11-89586208 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-15 02:46:41,156 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:41,156 - DEBUG - Waiting to SSH to VM ctest-VM11-89586208, IP 85.104.11.3, Port 22
2025-12-15 02:46:41,328 - DEBUG - VM ctest-VM11-89586208 is ready for SSH connections
2025-12-15 02:46:41,329 - INFO - Waiting for VM ctest-VM21-73227528 to be up..
2025-12-15 02:46:41,329 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:41,329 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:46:41,338 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2ff05e85-b796-49aa-88c0-883a9e468bdc
2025-12-15 02:46:42,499 - 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=2.91 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.417 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 = 0.417/1.664/2.912/1.247 ms')
2025-12-15 02:46:42,499 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM21-73227528 passed
2025-12-15 02:46:42,573 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:42,573 - DEBUG - Waiting to SSH to VM ctest-VM21-73227528, IP 73.186.102.3, Port 22
2025-12-15 02:46:42,740 - DEBUG - VM ctest-VM21-73227528 is ready for SSH connections
2025-12-15 02:46:42,740 - INFO - Waiting for VM ctest-VM31-57128789 to be up..
2025-12-15 02:46:42,740 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:42,740 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:46:42,749 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/2e7f0aab-41b7-41cc-ac92-2534da082c5d
2025-12-15 02:46:43,913 - 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=2.31 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.30 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 = 1.299/1.802/2.306/0.503 ms')
2025-12-15 02:46:43,913 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-57128789 passed
2025-12-15 02:46:43,998 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-15 02:46:43,998 - DEBUG - Waiting to SSH to VM ctest-VM31-57128789, IP 18.46.17.67, Port 22
2025-12-15 02:46:44,168 - DEBUG - VM ctest-VM31-57128789 is ready for SSH connections
2025-12-15 02:46:44,168 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 73.186.102.3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2025-12-15 02:46:44,168 - DEBUG - ping -s 56 -c 3 -W 1 73.186.102.3
2025-12-15 02:47:05,654 - DEBUG - PING 73.186.102.3 (73.186.102.3) 56(84) bytes of data.
64 bytes from 73.186.102.3: icmp_req=1 ttl=63 time=8.06 ms
64 bytes from 73.186.102.3: icmp_req=2 ttl=63 time=1.43 ms
64 bytes from 73.186.102.3: icmp_req=3 ttl=63 time=1.25 ms
--- 73.186.102.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2005ms
rtt min/avg/max/mdev = 1.250/3.585/8.069/3.171 ms
2025-12-15 02:47:05,655 - INFO - Ping to IP 73.186.102.3 from VM ctest-VM11-89586208 passed
2025-12-15 02:47:05,655 - DEBUG - Running remote_cmd, Cmd : ping6 -s 56 -c 3 -W 1 28a7:17e2:11e8:17b1:194a:43f4:0:3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2025-12-15 02:47:05,655 - DEBUG - ping6 -s 56 -c 3 -W 1 28a7:17e2:11e8:17b1:194a:43f4:0:3
2025-12-15 02:47:08,141 - DEBUG - PING 28a7:17e2:11e8:17b1:194a:43f4:0:3(28a7:17e2:11e8:17b1:194a:43f4:0:3) 56 data bytes
64 bytes from 28a7:17e2:11e8:17b1:194a:43f4:0:3: icmp_seq=1 ttl=64 time=7.53 ms
64 bytes from 28a7:17e2:11e8:17b1:194a:43f4:0:3: icmp_seq=2 ttl=64 time=1.75 ms
64 bytes from 28a7:17e2:11e8:17b1:194a:43f4:0:3: icmp_seq=3 ttl=64 time=1.26 ms
--- 28a7:17e2:11e8:17b1:194a:43f4:0:3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.269/3.519/7.530/2.843 ms
2025-12-15 02:47:08,141 - INFO - Ping to IP 28a7:17e2:11e8:17b1:194a:43f4:0:3 from VM ctest-VM11-89586208 passed
2025-12-15 02:47:08,141 - INFO - Test with src as policy and dst as any PASSED
2025-12-15 02:47:08,141 - INFO - Deleting VM ctest-VM31-57128789
2025-12-15 02:47:08,207 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:08,207 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:47:08,216 - DEBUG - VM ID 90923bb1-8430-4608-b408-0964070cea84 of VM ctest-VM31-57128789 is still found in API Server
2025-12-15 02:47:10,217 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:10,217 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:47:10,225 - DEBUG - Response Code: 404
2025-12-15 02:47:10,225 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:47:10,231 - DEBUG - Response Code: 404
2025-12-15 02:47:10,231 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/90923bb1-8430-4608-b408-0964070cea84
2025-12-15 02:47:10,237 - DEBUG - Response Code: 404
2025-12-15 02:47:10,237 - INFO - VM ctest-VM31-57128789 is fully removed in API-Server
2025-12-15 02:47:10,394 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-15 02:47:10,439 - DEBUG - Validated that vrouter 10.0.0.22 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:47:10,449 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:47:10,449 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196
2025-12-15 02:47:10,449 - INFO - VM ctest-VM31-57128789 is removed in Compute, and routes are removed in all compute nodes
2025-12-15 02:47:10,684 - INFO - Routes for VM ctest-VM31-57128789 is removed in all control-nodes
2025-12-15 02:47:10,684 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:10,719 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:10,747 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:10,748 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:10,748 - DEBUG - interface for vm 90923bb1-8430-4608-b408-0964070cea84 deleted from vrouter uve ...
2025-12-15 02:47:10,748 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:13,748 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:13,781 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:13,813 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:13,813 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:13,813 - DEBUG - interface for vm 90923bb1-8430-4608-b408-0964070cea84 deleted from vrouter uve ...
2025-12-15 02:47:13,813 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:16,814 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:16,846 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:16,872 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:16,872 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:16,872 - DEBUG - interface for vm 90923bb1-8430-4608-b408-0964070cea84 deleted from vrouter uve ...
2025-12-15 02:47:16,872 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:19,873 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:19,906 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:19,933 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:19,933 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:19,933 - DEBUG - interface for vm 90923bb1-8430-4608-b408-0964070cea84 deleted from vrouter uve ...
2025-12-15 02:47:19,933 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:22,933 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:22,963 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:22,998 - DEBUG - VM 90923bb1-8430-4608-b408-0964070cea84 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:22,998 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:22,998 - DEBUG - interface for vm 90923bb1-8430-4608-b408-0964070cea84 deleted from vrouter uve ...
2025-12-15 02:47:22,998 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:22,998 - DEBUG - Validated that VM 90923bb1-8430-4608-b408-0964070cea84 is removed in Vrouter UVE
2025-12-15 02:47:22,998 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-15 02:47:22,998 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196?flat
2025-12-15 02:47:23,018 - DEBUG - 90923bb1-8430-4608-b408-0964070cea84 BM not in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN3-83860196 uve
2025-12-15 02:47:23,018 - DEBUG - Validated that VM 90923bb1-8430-4608-b408-0964070cea84 is not present in the VN UVE
2025-12-15 02:47:23,018 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.23
2025-12-15 02:47:23,018 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:47:23,031 - INFO - 90923bb1-8430-4608-b408-0964070cea84 vm uve deleted from opserver
2025-12-15 02:47:23,031 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.50
2025-12-15 02:47:23,031 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:47:23,044 - INFO - 90923bb1-8430-4608-b408-0964070cea84 vm uve deleted from opserver
2025-12-15 02:47:23,044 - DEBUG - Verifying the 90923bb1-8430-4608-b408-0964070cea84 virtual network link through opserver 10.0.0.65
2025-12-15 02:47:23,044 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:47:23,063 - INFO - 90923bb1-8430-4608-b408-0964070cea84 vm uve deleted from opserver
2025-12-15 02:47:23,063 - INFO - Validated that VM 90923bb1-8430-4608-b408-0964070cea84 is removed from Opserver
2025-12-15 02:47:23,063 - INFO - Deleting VM ctest-VM21-73227528
2025-12-15 02:47:23,155 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:23,156 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:47:23,168 - DEBUG - VM ID d2450e88-639c-44e5-8f66-ed6d8a756a46 of VM ctest-VM21-73227528 is still found in API Server
2025-12-15 02:47:25,168 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:25,168 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:47:25,175 - DEBUG - Response Code: 404
2025-12-15 02:47:25,176 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:47:25,181 - DEBUG - Response Code: 404
2025-12-15 02:47:25,181 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d2450e88-639c-44e5-8f66-ed6d8a756a46
2025-12-15 02:47:25,188 - DEBUG - Response Code: 404
2025-12-15 02:47:25,189 - INFO - VM ctest-VM21-73227528 is fully removed in API-Server
2025-12-15 02:47:25,346 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-15 02:47:25,390 - DEBUG - Validated that vrouter 10.0.0.22 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:47:25,400 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:47:25,400 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407
2025-12-15 02:47:25,400 - INFO - VM ctest-VM21-73227528 is removed in Compute, and routes are removed in all compute nodes
2025-12-15 02:47:25,625 - INFO - Routes for VM ctest-VM21-73227528 is removed in all control-nodes
2025-12-15 02:47:25,625 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:25,661 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:25,691 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:25,691 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:25,691 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:25,691 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:28,692 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:28,726 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:28,757 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:28,757 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:28,757 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:28,757 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:31,758 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:31,798 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:31,828 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:31,828 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:31,829 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:31,829 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:34,830 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:34,864 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:34,894 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:34,894 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:34,894 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:34,894 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:37,895 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:37,928 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:37,958 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:37,958 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:37,958 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:37,958 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:40,959 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:40,992 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:41,021 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:41,021 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:41,021 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:41,021 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:44,022 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-1:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:44,053 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-1?flat
2025-12-15 02:47:44,084 - DEBUG - VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4894-1 uve
2025-12-15 02:47:44,084 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:44,084 - DEBUG - interface for vm d2450e88-639c-44e5-8f66-ed6d8a756a46 deleted from vrouter uve ...
2025-12-15 02:47:44,084 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:44,084 - DEBUG - Validated that VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is removed in Vrouter UVE
2025-12-15 02:47:44,084 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-15 02:47:44,084 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407?flat
2025-12-15 02:47:44,100 - DEBUG - d2450e88-639c-44e5-8f66-ed6d8a756a46 BM not in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN2-50643407 uve
2025-12-15 02:47:44,100 - DEBUG - Validated that VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is not present in the VN UVE
2025-12-15 02:47:44,100 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.23
2025-12-15 02:47:44,100 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:47:44,111 - INFO - d2450e88-639c-44e5-8f66-ed6d8a756a46 vm uve deleted from opserver
2025-12-15 02:47:44,111 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.50
2025-12-15 02:47:44,111 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:47:44,127 - INFO - d2450e88-639c-44e5-8f66-ed6d8a756a46 vm uve deleted from opserver
2025-12-15 02:47:44,127 - DEBUG - Verifying the d2450e88-639c-44e5-8f66-ed6d8a756a46 virtual network link through opserver 10.0.0.65
2025-12-15 02:47:44,127 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:47:44,144 - INFO - d2450e88-639c-44e5-8f66-ed6d8a756a46 vm uve deleted from opserver
2025-12-15 02:47:44,144 - INFO - Validated that VM d2450e88-639c-44e5-8f66-ed6d8a756a46 is removed from Opserver
2025-12-15 02:47:44,144 - INFO - Deleting VM ctest-VM11-89586208
2025-12-15 02:47:44,219 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:44,219 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:44,228 - DEBUG - VM ID 41d05718-096f-4b78-9c5b-e675d5ad37b5 of VM ctest-VM11-89586208 is still found in API Server
2025-12-15 02:47:46,229 - DEBUG - Verifying in api server 10.0.0.65
2025-12-15 02:47:46,229 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:46,236 - DEBUG - Response Code: 404
2025-12-15 02:47:46,236 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:46,241 - DEBUG - Response Code: 404
2025-12-15 02:47:46,241 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:46,246 - DEBUG - Response Code: 404
2025-12-15 02:47:46,246 - INFO - VM ctest-VM11-89586208 is fully removed in API-Server
2025-12-15 02:47:46,398 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-15 02:47:46,437 - DEBUG - Validated that vrouter 10.0.0.22 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:47:46,446 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:47:46,446 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366
2025-12-15 02:47:46,446 - INFO - VM ctest-VM11-89586208 is removed in Compute, and routes are removed in all compute nodes
2025-12-15 02:47:46,635 - INFO - Routes for VM ctest-VM11-89586208 is removed in all control-nodes
2025-12-15 02:47:46,635 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:46,663 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:46,692 - DEBUG - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:46,692 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:46,692 - DEBUG - interface for vm 41d05718-096f-4b78-9c5b-e675d5ad37b5 deleted from vrouter uve ...
2025-12-15 02:47:46,692 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:49,693 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:49,725 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:49,753 - DEBUG - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:49,753 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:49,753 - DEBUG - interface for vm 41d05718-096f-4b78-9c5b-e675d5ad37b5 deleted from vrouter uve ...
2025-12-15 02:47:49,753 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:52,753 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4894-2:Compute:contrail-vrouter-agent:0?flat
2025-12-15 02:47:52,784 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4894-2?flat
2025-12-15 02:47:52,810 - DEBUG - VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4894-2 uve
2025-12-15 02:47:52,810 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-15 02:47:52,810 - DEBUG - interface for vm 41d05718-096f-4b78-9c5b-e675d5ad37b5 deleted from vrouter uve ...
2025-12-15 02:47:52,810 - DEBUG - Deleted interface not in error interface list ...
2025-12-15 02:47:52,810 - DEBUG - Validated that VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is removed in Vrouter UVE
2025-12-15 02:47:52,810 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-15 02:47:52,810 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366?flat
2025-12-15 02:47:52,826 - DEBUG - 41d05718-096f-4b78-9c5b-e675d5ad37b5 BM not in default-domain:ctest-TestPolicyAclIpv4v6-99364654:ctest-VN1-00107366 uve
2025-12-15 02:47:52,826 - DEBUG - Validated that VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is not present in the VN UVE
2025-12-15 02:47:52,826 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.23
2025-12-15 02:47:52,826 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-15 02:47:52,837 - DEBUG - No links retuned for 41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:52,837 - INFO - 41d05718-096f-4b78-9c5b-e675d5ad37b5 vm uve deleted from opserver
2025-12-15 02:47:52,837 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.50
2025-12-15 02:47:52,837 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-12-15 02:47:52,848 - DEBUG - No links retuned for 41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:52,848 - INFO - 41d05718-096f-4b78-9c5b-e675d5ad37b5 vm uve deleted from opserver
2025-12-15 02:47:52,848 - DEBUG - Verifying the 41d05718-096f-4b78-9c5b-e675d5ad37b5 virtual network link through opserver 10.0.0.65
2025-12-15 02:47:52,848 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-15 02:47:52,861 - DEBUG - No links retuned for 41d05718-096f-4b78-9c5b-e675d5ad37b5
2025-12-15 02:47:52,861 - INFO - 41d05718-096f-4b78-9c5b-e675d5ad37b5 vm uve deleted from opserver
2025-12-15 02:47:52,861 - INFO - Validated that VM 41d05718-096f-4b78-9c5b-e675d5ad37b5 is removed from Opserver
2025-12-15 02:47:52,861 - DEBUG - Detaching the Policy for VN :ctest-VN2-50643407
2025-12-15 02:47:52,861 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:47:52,867 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:47:52,878 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:47:52,970 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/5bb54abe-d161-487d-be61-712c6781f1bc
2025-12-15 02:47:52,984 - DEBUG - Requesting: http://10.0.0.23:8082/network-policy/7abbbba2-4d3c-4ea5-af33-c7a4cc511c43
2025-12-15 02:47:53,185 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy21-78881754']] from ctest-VN2-50643407
2025-12-15 02:47:53,186 - DEBUG - Detaching the Policy for VN :ctest-VN1-00107366
2025-12-15 02:47:53,186 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:47:53,195 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:47:53,210 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:47:53,297 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/669d6e32-9031-420b-a7d3-e54b1b53d88f
2025-12-15 02:47:53,313 - DEBUG - Requesting: http://10.0.0.23:8082/network-policy/52cd3a1b-74aa-40b9-95aa-a8f65f5aafdd
2025-12-15 02:47:53,323 - DEBUG - Requesting: http://10.0.0.23:8082/network-policy/1920ead9-991d-4817-898f-67d95e2bf3af
2025-12-15 02:47:53,513 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy12-03344844'], ['default-domain', 'ctest-TestPolicyAclIpv4v6-99364654', 'ctest-policy13-44122466']] from ctest-VN1-00107366
2025-12-15 02:47:53,564 - INFO - Deleted policy ctest-policy21-78881754
2025-12-15 02:47:53,606 - INFO - Deleted policy ctest-policy12-03344844
2025-12-15 02:47:53,649 - INFO - Deleted policy ctest-policy13-44122466
2025-12-15 02:47:53,649 - INFO - Deleting VN ctest-VN3-83860196
2025-12-15 02:47:53,839 - DEBUG - Response for deleting network ()
2025-12-15 02:47:53,839 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/08b42e08-0219-4808-b17e-75db48ba59f2
2025-12-15 02:47:53,845 - DEBUG - Response Code: 404
2025-12-15 02:47:53,845 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:47:53,851 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:47:53,861 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:47:53,954 - INFO - Validated that VN ctest-VN3-83860196 is not found in API Server
2025-12-15 02:47:53,967 - DEBUG - VN ctest-VN3-83860196 is not present in Agent 10.0.0.22
2025-12-15 02:47:53,978 - DEBUG - VN ctest-VN3-83860196 is not present in Agent 10.0.0.27
2025-12-15 02:47:53,978 - INFO - Validated that VN ctest-VN3-83860196 is not in any agent
2025-12-15 02:47:54,010 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN3-83860196 info
2025-12-15 02:47:54,010 - INFO - Deleting VN ctest-VN2-50643407
2025-12-15 02:47:54,182 - DEBUG - Response for deleting network ()
2025-12-15 02:47:54,182 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/8817b6d3-abff-4033-b934-1493f7c40b7c
2025-12-15 02:47:54,194 - DEBUG - Response Code: 404
2025-12-15 02:47:54,194 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:47:54,201 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:47:54,214 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:47:54,297 - INFO - Validated that VN ctest-VN2-50643407 is not found in API Server
2025-12-15 02:47:54,308 - DEBUG - VN ctest-VN2-50643407 is not present in Agent 10.0.0.22
2025-12-15 02:47:54,320 - DEBUG - VN ctest-VN2-50643407 is not present in Agent 10.0.0.27
2025-12-15 02:47:54,320 - INFO - Validated that VN ctest-VN2-50643407 is not in any agent
2025-12-15 02:47:54,348 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN2-50643407 info
2025-12-15 02:47:54,348 - INFO - Deleting VN ctest-VN1-00107366
2025-12-15 02:47:54,530 - DEBUG - Response for deleting network ()
2025-12-15 02:47:54,530 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/28efce87-f54a-44c7-ad38-0d7fe45f9ee1
2025-12-15 02:47:54,550 - DEBUG - Response Code: 404
2025-12-15 02:47:54,551 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-15 02:47:54,562 - DEBUG - Requesting: http://10.0.0.23:8082/domain/747a8d7b-37d3-4985-88af-26a6e8bf7d0e
2025-12-15 02:47:54,575 - DEBUG - Requesting: http://10.0.0.23:8082/project/ff1377e7-bbdc-42ce-9ed9-998cc8e12a64
2025-12-15 02:47:54,670 - INFO - Validated that VN ctest-VN1-00107366 is not found in API Server
2025-12-15 02:47:54,681 - DEBUG - VN ctest-VN1-00107366 is not present in Agent 10.0.0.22
2025-12-15 02:47:54,691 - DEBUG - VN ctest-VN1-00107366 is not present in Agent 10.0.0.27
2025-12-15 02:47:54,691 - INFO - Validated that VN ctest-VN1-00107366 is not in any agent
2025-12-15 02:47:54,719 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN1-00107366 info
2025-12-15 02:47:54,819 - INFO - IPAM: ipam3 is not found in API Server
2025-12-15 02:47:54,840 - INFO - IPAM:ipam3 is not found in control node
2025-12-15 02:47:54,975 - INFO - IPAM: ipam2 is not found in API Server
2025-12-15 02:47:54,999 - INFO - IPAM:ipam2 is not found in control node
2025-12-15 02:47:55,135 - INFO - IPAM: ipam1 is not found in API Server
2025-12-15 02:47:55,158 - INFO - IPAM:ipam1 is not found in control node
2025-12-15 02:47:56,435 - DEBUG - No XMPP flaps were noticed during the test
2025-12-15 02:47:56,436 - INFO - END TEST : test_policy_inheritance_src_pol_dst_any : PASSED[0:02:52]
2025-12-15 02:47:56,436 - INFO - --------------------------------------------------------------------------------
2025-12-15 02:47:57,697 - DEBUG - No XMPP flaps were noticed during the test
2025-12-15 02:47:57,697 - INFO - END TEST : test_policy_inheritance_src_pol_dst_any : PASSED[0:02:55]
2025-12-15 02:47:57,697 - INFO - --------------------------------------------------------------------------------
2025-12-15 02:47:58,486 - INFO - Deleted project: ctest-TestPolicyAclIpv4v6-99364654, ID : ff1377e7-bbdc-42ce-9ed9-998cc8e12a64