is in ACTIVE state now
2025-08-08 07:27:46,232 - DEBUG - VM ctest-VM31-22846230 launched on Node an-jenkins-deploy-platform-ansible-os-3781-2
2025-08-08 07:27:46,346 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:27:46,358 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:27:46,369 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/8780e110-1468-40a9-94e9-8be45322b22e
2025-08-08 07:27:46,386 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:27:46,401 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/8780e110-1468-40a9-94e9-8be45322b22e
2025-08-08 07:27:46,416 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/7b43e9ae-b175-4011-a044-a52f74af47a3
2025-08-08 07:27:46,430 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:27:46,431 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:27:46,442 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/8780e110-1468-40a9-94e9-8be45322b22e
2025-08-08 07:27:46,457 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/7b43e9ae-b175-4011-a044-a52f74af47a3
2025-08-08 07:27:46,468 - INFO - VM ctest-VM31-22846230 verfication in all API Servers passed
2025-08-08 07:27:46,542 - DEBUG - VM ctest-VM31-22846230 Tap interface: {'index': '4', 'name': 'tap8780e110-14', 'uuid': '8780e110-1468-40a9-94e9-8be45322b22e', 'vrf_name': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128:ctest-VN3-55302128', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '32', 'l2_label': '36', 'vxlan_id': '17', 'vn_name': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128', 'vm_uuid': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'vm_name': 'ctest-VM31-22846230', 'ip_addr': '149.12.5.195', 'mac_addr': '02:87:80:e1:10:14', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '47', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e', 'sg_uuid_list': ['92791198-0a3f-4746-b884-f0a7b8616c11'], 'static_route_list': None, 'vm_project_uuid': 'f72ee4f0-595b-4924-8ae6-bf97868eb003', 'admin_state': 'Enabled', 'flow_key_idx': '41', 'allowed_address_pair_list': None, 'ip6_addr': '::', '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-08-08 07:27:46,542 - DEBUG - Agent 10.0.0.27 vrf name: default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128:ctest-VN3-55302128
2025-08-08 07:27:46,561 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128:ctest-VN3-55302128', 'ucindex': '3', 'mcindex': '3', 'l2index': '3', 'source': 'Config; ', 'uc6index': '3', 'vn': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128', 'table_label': '-1', 'vxlan_id': '17', 'evpnindex': '3', 'brindex': '3', 'mplsindex': '0', 'RD': '10.20.0.18:3', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-08-08 07:27:46,701 - DEBUG - VM ctest-VM31-22846230 : Tap interface tap8780e110-14 is set to Active
2025-08-08 07:27:46,701 - DEBUG - Tap interface tap8780e110-14 detail : {'index': '4', 'name': 'tap8780e110-14', 'uuid': '8780e110-1468-40a9-94e9-8be45322b22e', 'vrf_name': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128:ctest-VN3-55302128', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '32', 'l2_label': '36', 'vxlan_id': '17', 'vn_name': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128', 'vm_uuid': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'vm_name': 'ctest-VM31-22846230', 'ip_addr': '149.12.5.195', 'mac_addr': '02:87:80:e1:10:14', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '47', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e', 'sg_uuid_list': ['92791198-0a3f-4746-b884-f0a7b8616c11'], 'static_route_list': None, 'vm_project_uuid': 'f72ee4f0-595b-4924-8ae6-bf97868eb003', 'admin_state': 'Enabled', 'flow_key_idx': '41', 'allowed_address_pair_list': None, 'ip6_addr': '::', '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-08-08 07:27:46,864 - DEBUG - Starting Layer 2 verification in Agent
2025-08-08 07:27:46,885 - DEBUG - Layer 2 path is seen for VM MAC 02:87:80:e1:10:14 in agent 10.0.0.27
2025-08-08 07:27:46,885 - DEBUG - Active layer 2 route in agent is present for VMI tap8780e110-14
2025-08-08 07:27:46,885 - DEBUG - L2 label(36) matches bw route table and interface table
2025-08-08 07:27:46,905 - DEBUG - VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128 is found in Agent of node 10.0.0.27
2025-08-08 07:27:47,044 - DEBUG - VRF IDs of VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128 is consistent in agent 10.0.0.27
2025-08-08 07:27:47,045 - DEBUG - Route for VM IP ['149.12.5.195'] is consistent in agent 10.0.0.27
2025-08-08 07:27:47,045 - DEBUG - VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128 verification for VM ctest-VM31-22846230 in Agent 10.0.0.27 passed
2025-08-08 07:27:47,197 - DEBUG - Starting all layer 2 verification in agent 10.0.0.27
2025-08-08 07:27:47,213 - DEBUG - Route for VM MAC 02:87:80:e1:10:14 is consistent in agent 10.0.0.27
2025-08-08 07:27:48,445 - 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=12.4 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=3.99 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 = 3.994/8.221/12.448/4.227 ms')
2025-08-08 07:27:48,446 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-22846230 passed
2025-08-08 07:27:48,446 - INFO - VM ctest-VM31-22846230 verifications in Compute nodes passed
2025-08-08 07:27:48,768 - DEBUG - Validated VM route 149.12.5.195 in vrouter of 10.0.0.27
2025-08-08 07:27:48,775 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-08-08 07:27:48,775 - INFO - Validated routes of VM ctest-VM31-22846230 in all vrouters
2025-08-08 07:27:49,412 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node
2025-08-08 07:27:49,582 - DEBUG - Layer2 route found for VM MAC 02:87:80:e1:10:14 in Control-node 10.0.0.50
2025-08-08 07:27:49,582 - DEBUG - L2 Label for VM ctest-VM31-22846230 same between Control-node 10.0.0.50 and Agent, Expected: 36, Seen: 36
2025-08-08 07:27:49,582 - DEBUG - Starting all layer2 verification in 10.0.0.65 Control Node
2025-08-08 07:27:49,758 - DEBUG - Layer2 route found for VM MAC 02:87:80:e1:10:14 in Control-node 10.0.0.65
2025-08-08 07:27:49,758 - DEBUG - L2 Label for VM ctest-VM31-22846230 same between Control-node 10.0.0.65 and Agent, Expected: 36, Seen: 36
2025-08-08 07:27:49,758 - INFO - Verification in Control-nodes for VM ctest-VM31-22846230 passed
2025-08-08 07:27:49,758 - DEBUG - Verifying the vm in opserver
2025-08-08 07:27:49,758 - DEBUG - Verifying in collector 10.0.0.65 ...
2025-08-08 07:27:49,758 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat
2025-08-08 07:27:49,776 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e?flat
2025-08-08 07:27:49,799 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e?flat
2025-08-08 07:27:49,825 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat
2025-08-08 07:27:49,843 - DEBUG - Verifying vm in vn uve
2025-08-08 07:27:49,843 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e?flat
2025-08-08 07:27:49,869 - DEBUG - VM uve shows interface as {'fixed_ip4_list': ['149.12.5.195'], 'ip6_address': '::', 'vhostuser_mode': 0, 'vn_uuid': '69589707-7177-4a81-8fc0-864846f8e5f4', 'ip4_active': True, 'is_health_check_active': True, 'vm_uuid': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'gateway': '149.12.5.193', 'uuid': '8780e110-1468-40a9-94e9-8be45322b22e', 'active': True, 'label': 32, 'vm_name': 'ctest-VM31-22846230', 'admin_state': True, 'port_mirror_enabled': False, 'l2_active': True, '__T': 1754638028716994, 'tx_vlan': 65535, 'ip_address': '149.12.5.195', 'ip6_active': False, 'mac_address': '02:87:80:e1:10:14', 'rx_vlan': 65535, 'virtual_network': 'default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128'}
2025-08-08 07:27:49,869 - DEBUG - VM uve shows ip address as ['149.12.5.195', '::']
2025-08-08 07:27:49,869 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:27:49,869 - INFO - Verifying through opserver in 10.0.0.50
2025-08-08 07:27:49,869 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128?flat
2025-08-08 07:27:49,904 - DEBUG - expected vm list 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:27:49,904 - DEBUG - Extracted vm list ['765e0453-64b5-4dbb-91ab-2ab0f99aa1ea']
2025-08-08 07:27:49,904 - INFO - VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is present in default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:27:49,904 - DEBUG - Verifying vm in vrouter uve
2025-08-08 07:27:49,904 - DEBUG - Getting info from collector 10.0.0.65..
2025-08-08 07:27:49,904 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat
2025-08-08 07:27:49,923 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-3781-2']
2025-08-08 07:27:49,923 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:27:49,975 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:27:50,023 - DEBUG - VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:27:50,023 - DEBUG - Validated that VM ctest-VM31-22846230 is in Vrouter an-jenkins-deploy-platform-ansible-os-3781-2 UVE
2025-08-08 07:27:50,023 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-08-08 07:27:50,038 - DEBUG - Expected tap interface of VM uuid 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e
2025-08-08 07:27:50,038 - DEBUG - Expected VN of VM uuid 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:27:50,038 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:27:50,086 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:27:50,131 - DEBUG - VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:27:50,131 - INFO - tap interface default-domain:ctest-TestPolicyAcl-86736195:8780e110-1468-40a9-94e9-8be45322b22e of vm 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:27:50,132 - DEBUG - Connected network default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128 of vm 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:27:50,132 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.50
2025-08-08 07:27:50,132 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-08-08 07:27:50,149 - DEBUG - VM link and name as {'name': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat'}
2025-08-08 07:27:50,149 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.254
2025-08-08 07:27:50,149 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-machines
2025-08-08 07:27:50,163 - DEBUG - VM link and name as {'name': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat'}
2025-08-08 07:27:50,163 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.65
2025-08-08 07:27:50,163 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-08-08 07:27:50,176 - DEBUG - VM link and name as {'name': '765e0453-64b5-4dbb-91ab-2ab0f99aa1ea', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea?flat'}
2025-08-08 07:27:50,176 - INFO - VM ctest-VM31-22846230 validations in Opserver passed
2025-08-08 07:27:50,176 - INFO - Waiting for VM ctest-VM11-32510659 to be up..
2025-08-08 07:27:50,176 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:27:50,176 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:27:50,185 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/259cff2c-888c-4d6e-885d-74aee1debc1d
2025-08-08 07:27:51,443 - 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.02 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.07 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 3.072/3.544/4.016/0.472 ms')
2025-08-08 07:27:51,443 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-32510659 passed
2025-08-08 07:27:51,557 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:27:51,557 - DEBUG - Waiting to SSH to VM ctest-VM11-32510659, IP 220.209.196.195, Port 22
2025-08-08 07:27:51,626 - 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-08-08 07:27:51,707 - DEBUG - VM ctest-VM11-32510659 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-08 07:27:56,708 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:27:56,708 - DEBUG - Waiting to SSH to VM ctest-VM11-32510659, IP 220.209.196.195, Port 22
2025-08-08 07:27:56,778 - 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-08-08 07:27:56,879 - DEBUG - VM ctest-VM11-32510659 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-08 07:28:01,880 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:01,880 - DEBUG - Waiting to SSH to VM ctest-VM11-32510659, IP 220.209.196.195, Port 22
2025-08-08 07:28:01,950 - 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-08-08 07:28:02,079 - DEBUG - VM ctest-VM11-32510659 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-08 07:28:07,079 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:07,080 - DEBUG - Waiting to SSH to VM ctest-VM11-32510659, IP 220.209.196.195, Port 22
2025-08-08 07:28:07,254 - DEBUG - VM ctest-VM11-32510659 is ready for SSH connections
2025-08-08 07:28:07,254 - INFO - Waiting for VM ctest-VM21-81706848 to be up..
2025-08-08 07:28:07,255 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:07,255 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0c6d4a2b-7bdf-4689-9e00-df3664d26cf0
2025-08-08 07:28:07,266 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/fc1c3e8e-e37e-486d-9e80-12eafe160f77
2025-08-08 07:28:08,479 - 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=3.17 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.439 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 0.439/1.806/3.173/1.367 ms')
2025-08-08 07:28:08,479 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM21-81706848 passed
2025-08-08 07:28:08,589 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:08,589 - DEBUG - Waiting to SSH to VM ctest-VM21-81706848, IP 107.2.216.131, Port 22
2025-08-08 07:28:08,759 - DEBUG - VM ctest-VM21-81706848 is ready for SSH connections
2025-08-08 07:28:08,759 - INFO - Waiting for VM ctest-VM31-22846230 to be up..
2025-08-08 07:28:08,759 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:08,759 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:28:08,770 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/8780e110-1468-40a9-94e9-8be45322b22e
2025-08-08 07:28:09,999 - 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.34 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.432 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.432/2.384/4.337/1.952 ms')
2025-08-08 07:28:09,999 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-22846230 passed
2025-08-08 07:28:10,124 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-08 07:28:10,124 - DEBUG - Waiting to SSH to VM ctest-VM31-22846230, IP 149.12.5.195, Port 22
2025-08-08 07:28:10,299 - DEBUG - VM ctest-VM31-22846230 is ready for SSH connections
2025-08-08 07:28:10,299 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 107.2.216.131, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2025-08-08 07:28:10,299 - DEBUG - ping -s 56 -c 3 -W 1 107.2.216.131
2025-08-08 07:28:36,999 - DEBUG - PING 107.2.216.131 (107.2.216.131) 56(84) bytes of data.
64 bytes from 107.2.216.131: icmp_req=1 ttl=63 time=7.49 ms
64 bytes from 107.2.216.131: icmp_req=2 ttl=63 time=1.70 ms
64 bytes from 107.2.216.131: icmp_req=3 ttl=63 time=1.20 ms
--- 107.2.216.131 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.202/3.469/7.499/2.857 ms
2025-08-08 07:28:37,000 - INFO - Ping to IP 107.2.216.131 from VM ctest-VM11-32510659 passed
2025-08-08 07:28:37,000 - INFO - Test with src as VN and dst as policy PASSED
2025-08-08 07:28:37,000 - INFO - Deleting VM ctest-VM31-22846230
2025-08-08 07:28:37,089 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:37,090 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:28:37,099 - DEBUG - VM ID 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea of VM ctest-VM31-22846230 is still found in API Server
2025-08-08 07:28:39,100 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:39,100 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:28:39,108 - DEBUG - Response Code: 404
2025-08-08 07:28:39,108 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:28:39,115 - DEBUG - Response Code: 404
2025-08-08 07:28:39,116 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/765e0453-64b5-4dbb-91ab-2ab0f99aa1ea
2025-08-08 07:28:39,122 - DEBUG - Response Code: 404
2025-08-08 07:28:39,123 - INFO - VM ctest-VM31-22846230 is fully removed in API-Server
2025-08-08 07:28:39,275 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-08-08 07:28:39,326 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:28:39,340 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:28:39,340 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128
2025-08-08 07:28:39,341 - INFO - VM ctest-VM31-22846230 is removed in Compute, and routes are removed in all compute nodes
2025-08-08 07:28:39,646 - INFO - Routes for VM ctest-VM31-22846230 is removed in all control-nodes
2025-08-08 07:28:39,647 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:39,729 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:28:39,778 - DEBUG - VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is not present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:28:39,778 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:39,778 - DEBUG - interface for vm 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea deleted from vrouter uve ...
2025-08-08 07:28:39,778 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:39,778 - DEBUG - Validated that VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is removed in Vrouter UVE
2025-08-08 07:28:39,779 - DEBUG - Verifying through opserver in 10.0.0.50
2025-08-08 07:28:39,779 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128?flat
2025-08-08 07:28:39,803 - DEBUG - 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea BM not in default-domain:ctest-TestPolicyAcl-86736195:ctest-VN3-55302128 uve
2025-08-08 07:28:39,803 - DEBUG - Validated that VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is not present in the VN UVE
2025-08-08 07:28:39,803 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.50
2025-08-08 07:28:39,803 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-08-08 07:28:39,819 - INFO - 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea vm uve deleted from opserver
2025-08-08 07:28:39,819 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.254
2025-08-08 07:28:39,819 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-machines
2025-08-08 07:28:39,837 - INFO - 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea vm uve deleted from opserver
2025-08-08 07:28:39,838 - DEBUG - Verifying the 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea virtual network link through opserver 10.0.0.65
2025-08-08 07:28:39,838 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-08-08 07:28:39,855 - INFO - 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea vm uve deleted from opserver
2025-08-08 07:28:39,855 - INFO - Validated that VM 765e0453-64b5-4dbb-91ab-2ab0f99aa1ea is removed from Opserver
2025-08-08 07:28:39,855 - INFO - Deleting VM ctest-VM21-81706848
2025-08-08 07:28:39,932 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:39,932 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0c6d4a2b-7bdf-4689-9e00-df3664d26cf0
2025-08-08 07:28:39,946 - DEBUG - VM ID 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 of VM ctest-VM21-81706848 is still found in API Server
2025-08-08 07:28:41,947 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:41,947 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0c6d4a2b-7bdf-4689-9e00-df3664d26cf0
2025-08-08 07:28:41,958 - DEBUG - Response Code: 404
2025-08-08 07:28:41,958 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0c6d4a2b-7bdf-4689-9e00-df3664d26cf0
2025-08-08 07:28:41,965 - DEBUG - Response Code: 404
2025-08-08 07:28:41,965 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/0c6d4a2b-7bdf-4689-9e00-df3664d26cf0
2025-08-08 07:28:41,972 - DEBUG - Response Code: 404
2025-08-08 07:28:41,972 - INFO - VM ctest-VM21-81706848 is fully removed in API-Server
2025-08-08 07:28:42,128 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-08-08 07:28:42,180 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN2-89949437
2025-08-08 07:28:42,193 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN2-89949437
2025-08-08 07:28:42,193 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN2-89949437
2025-08-08 07:28:42,194 - INFO - VM ctest-VM21-81706848 is removed in Compute, and routes are removed in all compute nodes
2025-08-08 07:28:42,472 - INFO - Routes for VM ctest-VM21-81706848 is removed in all control-nodes
2025-08-08 07:28:42,473 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-1:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:42,529 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-1?flat
2025-08-08 07:28:42,579 - DEBUG - VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-1 uve
2025-08-08 07:28:42,579 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:42,579 - DEBUG - interface for vm 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 deleted from vrouter uve ...
2025-08-08 07:28:42,579 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:45,580 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-1:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:45,636 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-1?flat
2025-08-08 07:28:45,692 - DEBUG - VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-1 uve
2025-08-08 07:28:45,692 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:45,692 - DEBUG - interface for vm 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 deleted from vrouter uve ...
2025-08-08 07:28:45,692 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:48,693 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-1:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:48,742 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-1?flat
2025-08-08 07:28:48,786 - DEBUG - VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is not present in vrouter an-jenkins-deploy-platform-ansible-os-3781-1 uve
2025-08-08 07:28:48,786 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:48,787 - DEBUG - interface for vm 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 deleted from vrouter uve ...
2025-08-08 07:28:48,787 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:48,788 - DEBUG - Validated that VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is removed in Vrouter UVE
2025-08-08 07:28:48,788 - DEBUG - Verifying through opserver in 10.0.0.50
2025-08-08 07:28:48,788 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-86736195:ctest-VN2-89949437?flat
2025-08-08 07:28:48,814 - DEBUG - 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 BM not in default-domain:ctest-TestPolicyAcl-86736195:ctest-VN2-89949437 uve
2025-08-08 07:28:48,814 - DEBUG - Validated that VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is not present in the VN UVE
2025-08-08 07:28:48,814 - DEBUG - Verifying the 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 virtual network link through opserver 10.0.0.50
2025-08-08 07:28:48,814 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-08-08 07:28:48,830 - INFO - 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 vm uve deleted from opserver
2025-08-08 07:28:48,830 - DEBUG - Verifying the 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 virtual network link through opserver 10.0.0.254
2025-08-08 07:28:48,830 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-machines
2025-08-08 07:28:48,846 - INFO - 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 vm uve deleted from opserver
2025-08-08 07:28:48,846 - DEBUG - Verifying the 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 virtual network link through opserver 10.0.0.65
2025-08-08 07:28:48,846 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-08-08 07:28:48,859 - INFO - 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 vm uve deleted from opserver
2025-08-08 07:28:48,859 - INFO - Validated that VM 0c6d4a2b-7bdf-4689-9e00-df3664d26cf0 is removed from Opserver
2025-08-08 07:28:48,859 - INFO - Deleting VM ctest-VM11-32510659
2025-08-08 07:28:48,963 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:48,963 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:28:48,974 - DEBUG - VM ID 180b18b2-547b-4a87-88c7-94cddcd63a8a of VM ctest-VM11-32510659 is still found in API Server
2025-08-08 07:28:50,975 - DEBUG - Verifying in api server 10.0.0.65
2025-08-08 07:28:50,975 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:28:50,985 - DEBUG - Response Code: 404
2025-08-08 07:28:50,985 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:28:50,993 - DEBUG - Response Code: 404
2025-08-08 07:28:50,993 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:28:51,001 - DEBUG - Response Code: 404
2025-08-08 07:28:51,001 - INFO - VM ctest-VM11-32510659 is fully removed in API-Server
2025-08-08 07:28:51,159 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-08-08 07:28:51,207 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN1-36123631
2025-08-08 07:28:51,219 - DEBUG - Validated that vrouter 10.0.0.27 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN1-36123631
2025-08-08 07:28:51,219 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-86736195:ctest-VN1-36123631
2025-08-08 07:28:51,219 - INFO - VM ctest-VM11-32510659 is removed in Compute, and routes are removed in all compute nodes
2025-08-08 07:28:51,467 - INFO - Routes for VM ctest-VM11-32510659 is removed in all control-nodes
2025-08-08 07:28:51,468 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:51,520 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:28:51,572 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:28:51,572 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:51,572 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:28:51,572 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:54,573 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:54,630 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:28:54,667 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:28:54,667 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:54,667 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:28:54,667 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:28:57,668 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:28:57,714 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:28:57,764 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:28:57,764 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:28:57,764 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:28:57,764 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:29:00,765 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:29:00,814 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:29:00,865 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:29:00,865 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:29:00,865 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:29:00,865 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:29:03,865 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:29:03,916 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:29:03,957 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:29:03,957 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:29:03,957 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:29:03,957 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:29:06,958 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:29:07,006 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:29:07,052 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:29:07,052 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:29:07,052 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:29:07,052 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:29:10,053 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3781-2:Compute:contrail-vrouter-agent:0?flat
2025-08-08 07:29:10,105 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3781-2?flat
2025-08-08 07:29:10,149 - DEBUG - VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is not present in vrouter an-jenkins-deploy-platform-ansible-os-3781-2 uve
2025-08-08 07:29:10,149 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-08-08 07:29:10,149 - DEBUG - interface for vm 180b18b2-547b-4a87-88c7-94cddcd63a8a deleted from vrouter uve ...
2025-08-08 07:29:10,149 - DEBUG - Deleted interface not in error interface list ...
2025-08-08 07:29:10,149 - DEBUG - Validated that VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is removed in Vrouter UVE
2025-08-08 07:29:10,149 - DEBUG - Verifying through opserver in 10.0.0.50
2025-08-08 07:29:10,149 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-86736195:ctest-VN1-36123631?flat
2025-08-08 07:29:10,173 - DEBUG - 180b18b2-547b-4a87-88c7-94cddcd63a8a BM not in default-domain:ctest-TestPolicyAcl-86736195:ctest-VN1-36123631 uve
2025-08-08 07:29:10,173 - DEBUG - Validated that VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is not present in the VN UVE
2025-08-08 07:29:10,173 - DEBUG - Verifying the 180b18b2-547b-4a87-88c7-94cddcd63a8a virtual network link through opserver 10.0.0.50
2025-08-08 07:29:10,173 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines
2025-08-08 07:29:10,192 - DEBUG - No links retuned for 180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:29:10,192 - INFO - 180b18b2-547b-4a87-88c7-94cddcd63a8a vm uve deleted from opserver
2025-08-08 07:29:10,192 - DEBUG - Verifying the 180b18b2-547b-4a87-88c7-94cddcd63a8a virtual network link through opserver 10.0.0.254
2025-08-08 07:29:10,192 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-machines
2025-08-08 07:29:10,208 - DEBUG - No links retuned for 180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:29:10,208 - INFO - 180b18b2-547b-4a87-88c7-94cddcd63a8a vm uve deleted from opserver
2025-08-08 07:29:10,208 - DEBUG - Verifying the 180b18b2-547b-4a87-88c7-94cddcd63a8a virtual network link through opserver 10.0.0.65
2025-08-08 07:29:10,208 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-08-08 07:29:10,223 - DEBUG - No links retuned for 180b18b2-547b-4a87-88c7-94cddcd63a8a
2025-08-08 07:29:10,223 - INFO - 180b18b2-547b-4a87-88c7-94cddcd63a8a vm uve deleted from opserver
2025-08-08 07:29:10,223 - INFO - Validated that VM 180b18b2-547b-4a87-88c7-94cddcd63a8a is removed from Opserver
2025-08-08 07:29:10,224 - DEBUG - Detaching the Policy for VN :ctest-VN2-89949437
2025-08-08 07:29:10,224 - DEBUG - Requesting: http://10.0.0.50:8082/domains
2025-08-08 07:29:10,234 - DEBUG - Requesting: http://10.0.0.50:8082/domain/0a1f62a0-4b7c-4f3b-81ab-d2813942820b
2025-08-08 07:29:10,252 - DEBUG - Requesting: http://10.0.0.50:8082/project/f72ee4f0-595b-4924-8ae6-bf97868eb003
2025-08-08 07:29:10,350 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/e9b48e9c-114f-4644-8d92-5bd1a97e9d86
2025-08-08 07:29:10,373 - DEBUG - Requesting: http://10.0.0.50:8082/network-policy/e21bbfac-c615-47f6-affc-4a76159e6183
2025-08-08 07:29:10,587 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestPolicyAcl-86736195', 'ctest-policy21-82652498']] from ctest-VN2-89949437
2025-08-08 07:29:10,588 - DEBUG - Detaching the Policy for VN :ctest-VN1-36123631
2025-08-08 07:29:10,588 - DEBUG - Requesting: http://10.0.0.50:8082/domains
2025-08-08 07:29:10,596 - DEBUG - Requesting: http://10.0.0.50:8082/domain/0a1f62a0-4b7c-4f3b-81ab-d2813942820b
2025-08-08 07:29:10,612 - DEBUG - Requesting: http://10.0.0.50:8082/project/f72ee4f0-595b-4924-8ae6-bf97868eb003
2025-08-08 07:29:10,720 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/d844eb4b-cf85-46be-8022-fa48dc6fb036
2025-08-08 07:29:10,932 - INFO - Detached Policy from ctest-VN1-36123631
2025-08-08 07:29:10,998 - INFO - Deleted policy ctest-policy13-65060189
2025-08-08 07:29:11,053 - INFO - Deleted policy ctest-policy21-82652498
2025-08-08 07:29:11,113 - INFO - Deleted policy ctest-policy12-82485629
2025-08-08 07:29:11,113 - INFO - Deleting VN ctest-VN3-55302128
2025-08-08 07:29:11,339 - DEBUG - Response for deleting network ()
2025-08-08 07:29:11,339 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/112deefa-ca40-4b65-a02b-572afcb288d6
2025-08-08 07:29:11,345 - DEBUG - Response Code: 404
2025-08-08 07:29:11,346 - DEBUG - Requesting: http://10.0.0.50:8082/domains
2025-08-08 07:29:11,353 - DEBUG - Requesting: http://10.0.0.50:8082/domain/0a1f62a0-4b7c-4f3b-81ab-d2813942820b
2025-08-08 07:29:11,366 - DEBUG - Requesting: http://10.0.0.50:8082/project/f72ee4f0-595b-4924-8ae6-bf97868eb003
2025-08-08 07:29:11,466 - INFO - Validated that VN ctest-VN3-55302128 is not found in API Server
2025-08-08 07:29:11,480 - DEBUG - VN ctest-VN3-55302128 is not present in Agent 10.0.0.41
2025-08-08 07:29:11,494 - DEBUG - VN ctest-VN3-55302128 is not present in Agent 10.0.0.27
2025-08-08 07:29:11,494 - INFO - Validated that VN ctest-VN3-55302128 is not in any agent
2025-08-08 07:29:11,534 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN3-55302128 info
2025-08-08 07:29:11,534 - INFO - Deleting VN ctest-VN2-89949437
2025-08-08 07:29:11,764 - DEBUG - Response for deleting network ()
2025-08-08 07:29:11,764 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/890b41a6-c22e-46e0-ab76-ce29278694cc
2025-08-08 07:29:11,772 - DEBUG - Response Code: 404
2025-08-08 07:29:11,773 - DEBUG - Requesting: http://10.0.0.50:8082/domains
2025-08-08 07:29:11,782 - DEBUG - Requesting: http://10.0.0.50:8082/domain/0a1f62a0-4b7c-4f3b-81ab-d2813942820b
2025-08-08 07:29:11,796 - DEBUG - Requesting: http://10.0.0.50:8082/project/f72ee4f0-595b-4924-8ae6-bf97868eb003
2025-08-08 07:29:11,889 - INFO - Validated that VN ctest-VN2-89949437 is not found in API Server
2025-08-08 07:29:11,906 - DEBUG - VN ctest-VN2-89949437 is not present in Agent 10.0.0.41
2025-08-08 07:29:11,921 - DEBUG - VN ctest-VN2-89949437 is not present in Agent 10.0.0.27
2025-08-08 07:29:11,921 - INFO - Validated that VN ctest-VN2-89949437 is not in any agent
2025-08-08 07:29:11,962 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN2-89949437 info
2025-08-08 07:29:11,962 - INFO - Deleting VN ctest-VN1-36123631
2025-08-08 07:29:12,124 - DEBUG - Response for deleting network ()
2025-08-08 07:29:12,124 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/5f843d5f-39b8-4977-be51-f9153648f048
2025-08-08 07:29:12,130 - DEBUG - Response Code: 404
2025-08-08 07:29:12,130 - DEBUG - Requesting: http://10.0.0.50:8082/domains
2025-08-08 07:29:12,137 - DEBUG - Requesting: http://10.0.0.50:8082/domain/0a1f62a0-4b7c-4f3b-81ab-d2813942820b
2025-08-08 07:29:12,198 - DEBUG - Requesting: http://10.0.0.50:8082/project/f72ee4f0-595b-4924-8ae6-bf97868eb003
2025-08-08 07:29:12,304 - INFO - Validated that VN ctest-VN1-36123631 is not found in API Server
2025-08-08 07:29:12,321 - DEBUG - VN ctest-VN1-36123631 is not present in Agent 10.0.0.41
2025-08-08 07:29:12,339 - DEBUG - VN ctest-VN1-36123631 is not present in Agent 10.0.0.27
2025-08-08 07:29:12,340 - INFO - Validated that VN ctest-VN1-36123631 is not in any agent
2025-08-08 07:29:12,386 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN1-36123631 info
2025-08-08 07:29:12,484 - INFO - IPAM: ipam3 is not found in API Server
2025-08-08 07:29:12,513 - INFO - IPAM:ipam3 is not found in control node
2025-08-08 07:29:12,664 - INFO - IPAM: ipam2 is not found in API Server
2025-08-08 07:29:12,693 - INFO - IPAM:ipam2 is not found in control node
2025-08-08 07:29:12,840 - INFO - IPAM: ipam1 is not found in API Server
2025-08-08 07:29:12,868 - INFO - IPAM:ipam1 is not found in control node
2025-08-08 07:29:14,184 - DEBUG - No XMPP flaps were noticed during the test
2025-08-08 07:29:14,184 - INFO - END TEST : test_policy_inheritance_src_vn_dst_pol : PASSED[0:02:43]
2025-08-08 07:29:14,185 - INFO - --------------------------------------------------------------------------------
2025-08-08 07:29:14,945 - INFO - Deleted project: ctest-TestPolicyAcl-86736195, ID : f72ee4f0-595b-4924-8ae6-bf97868eb003