is in ACTIVE state now
2025-12-08 02:37:25,735 - DEBUG - VM ctest-VM31-75147678 launched on Node an-jenkins-deploy-platform-ansible-os-4854-2
2025-12-08 02:37:25,811 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:25,821 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:25,827 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/ba5cfca4-0783-441a-b391-3c147c7c1fc7
2025-12-08 02:37:25,836 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:25,843 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/ba5cfca4-0783-441a-b391-3c147c7c1fc7
2025-12-08 02:37:25,851 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/c574ffb1-fb31-485d-9612-9ab2ce482d27
2025-12-08 02:37:25,860 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:37:25,860 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:25,867 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/ba5cfca4-0783-441a-b391-3c147c7c1fc7
2025-12-08 02:37:25,875 - DEBUG - Requesting: http://10.0.0.65:8082/instance-ip/c574ffb1-fb31-485d-9612-9ab2ce482d27
2025-12-08 02:37:25,883 - INFO - VM ctest-VM31-75147678 verfication in all API Servers passed
2025-12-08 02:37:25,900 - DEBUG - VM ctest-VM31-75147678 Tap interface: {'index': '4', 'name': 'tapba5cfca4-07', 'uuid': 'ba5cfca4-0783-441a-b391-3c147c7c1fc7', 'vrf_name': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570:ctest-VN3-51176570', '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': '16', 'vn_name': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570', 'vm_uuid': 'd4085425-2335-4d1e-bf05-03a65246ea6a', 'vm_name': 'ctest-VM31-75147678', 'ip_addr': '130.90.86.3', 'mac_addr': '02:ba:5c:fc:a4:07', '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-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7', 'sg_uuid_list': ['994e0c84-5dc6-48df-99fc-4ebcf7fc87d0'], 'static_route_list': None, 'vm_project_uuid': 'e5663c78-a584-42ea-aaab-d23b9ff29fa1', '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-12-08 02:37:25,900 - DEBUG - Agent 10.0.0.129 vrf name: default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570:ctest-VN3-51176570
2025-12-08 02:37:25,905 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570:ctest-VN3-51176570', 'ucindex': '3', 'mcindex': '3', 'l2index': '3', 'source': 'Config; ', 'uc6index': '3', 'vn': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570', 'table_label': '-1', 'vxlan_id': '16', '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-08 02:37:25,977 - DEBUG - VM ctest-VM31-75147678 : Tap interface tapba5cfca4-07 is set to Active
2025-12-08 02:37:25,977 - DEBUG - Tap interface tapba5cfca4-07 detail : {'index': '4', 'name': 'tapba5cfca4-07', 'uuid': 'ba5cfca4-0783-441a-b391-3c147c7c1fc7', 'vrf_name': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570:ctest-VN3-51176570', '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': '16', 'vn_name': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570', 'vm_uuid': 'd4085425-2335-4d1e-bf05-03a65246ea6a', 'vm_name': 'ctest-VM31-75147678', 'ip_addr': '130.90.86.3', 'mac_addr': '02:ba:5c:fc:a4:07', '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-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7', 'sg_uuid_list': ['994e0c84-5dc6-48df-99fc-4ebcf7fc87d0'], 'static_route_list': None, 'vm_project_uuid': 'e5663c78-a584-42ea-aaab-d23b9ff29fa1', '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-12-08 02:37:26,089 - DEBUG - Starting Layer 2 verification in Agent
2025-12-08 02:37:26,099 - DEBUG - Layer 2 path is seen for VM MAC 02:ba:5c:fc:a4:07 in agent 10.0.0.129
2025-12-08 02:37:26,099 - DEBUG - Active layer 2 route in agent is present for VMI tapba5cfca4-07
2025-12-08 02:37:26,099 - DEBUG - L2 label(36) matches bw route table and interface table
2025-12-08 02:37:26,111 - DEBUG - VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570 is found in Agent of node 10.0.0.129
2025-12-08 02:37:26,242 - DEBUG - VRF IDs of VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570 is consistent in agent 10.0.0.129
2025-12-08 02:37:26,242 - DEBUG - Route for VM IP ['130.90.86.3'] is consistent in agent 10.0.0.129
2025-12-08 02:37:26,242 - DEBUG - VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570 verification for VM ctest-VM31-75147678 in Agent 10.0.0.129 passed
2025-12-08 02:37:26,359 - DEBUG - Starting all layer 2 verification in agent 10.0.0.129
2025-12-08 02:37:26,370 - DEBUG - Route for VM MAC 02:ba:5c:fc:a4:07 is consistent in agent 10.0.0.129
2025-12-08 02:37:27,553 - 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=5.40 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.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 = 1.988/3.694/5.400/1.706 ms')
2025-12-08 02:37:27,554 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-75147678 passed
2025-12-08 02:37:27,554 - INFO - VM ctest-VM31-75147678 verifications in Compute nodes passed
2025-12-08 02:37:27,765 - DEBUG - Validated VM route 130.90.86.3 in vrouter of 10.0.0.129
2025-12-08 02:37:27,770 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-08 02:37:27,771 - INFO - Validated routes of VM ctest-VM31-75147678 in all vrouters
2025-12-08 02:37:28,299 - DEBUG - Starting all layer2 verification in 10.0.0.65 Control Node
2025-12-08 02:37:28,422 - DEBUG - Layer2 route found for VM MAC 02:ba:5c:fc:a4:07 in Control-node 10.0.0.65
2025-12-08 02:37:28,422 - DEBUG - L2 Label for VM ctest-VM31-75147678 same between Control-node 10.0.0.65 and Agent, Expected: 36, Seen: 36
2025-12-08 02:37:28,422 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node
2025-12-08 02:37:28,543 - DEBUG - Layer2 route found for VM MAC 02:ba:5c:fc:a4:07 in Control-node 10.0.0.22
2025-12-08 02:37:28,543 - DEBUG - L2 Label for VM ctest-VM31-75147678 same between Control-node 10.0.0.22 and Agent, Expected: 36, Seen: 36
2025-12-08 02:37:28,543 - INFO - Verification in Control-nodes for VM ctest-VM31-75147678 passed
2025-12-08 02:37:28,544 - DEBUG - Verifying the vm in opserver
2025-12-08 02:37:28,544 - DEBUG - Verifying in collector 10.0.0.65 ...
2025-12-08 02:37:28,544 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat
2025-12-08 02:37:28,560 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7?flat
2025-12-08 02:37:28,577 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7?flat
2025-12-08 02:37:28,596 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat
2025-12-08 02:37:28,610 - DEBUG - Verifying vm in vn uve
2025-12-08 02:37:28,610 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestPolicyAcl-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7?flat
2025-12-08 02:37:28,628 - DEBUG - VM uve shows interface as {'admin_state': True, 'uuid': 'ba5cfca4-0783-441a-b391-3c147c7c1fc7', 'vhostuser_mode': 0, 'ip_address': '130.90.86.3', 'mac_address': '02:ba:5c:fc:a4:07', 'vn_uuid': 'ef9931ff-926e-483d-a6fd-cd2541b40281', 'vm_name': 'ctest-VM31-75147678', 'label': 32, 'active': True, 'ip4_active': True, 'fixed_ip4_list': ['130.90.86.3'], 'gateway': '130.90.86.1', 'is_health_check_active': True, 'l2_active': True, 'rx_vlan': 65535, 'tx_vlan': 65535, 'ip6_address': '::', 'port_mirror_enabled': False, 'virtual_network': 'default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570', 'ip6_active': False, 'vm_uuid': 'd4085425-2335-4d1e-bf05-03a65246ea6a', '__T': 1765161414152048}
2025-12-08 02:37:28,628 - DEBUG - VM uve shows ip address as ['130.90.86.3', '::']
2025-12-08 02:37:28,628 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:37:28,628 - INFO - Verifying through opserver in 10.0.0.23
2025-12-08 02:37:28,628 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570?flat
2025-12-08 02:37:28,648 - DEBUG - expected vm list d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:28,648 - DEBUG - Extracted vm list ['d4085425-2335-4d1e-bf05-03a65246ea6a']
2025-12-08 02:37:28,648 - INFO - VM d4085425-2335-4d1e-bf05-03a65246ea6a is present in default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:37:28,648 - DEBUG - Verifying vm in vrouter uve
2025-12-08 02:37:28,648 - DEBUG - Getting info from collector 10.0.0.65..
2025-12-08 02:37:28,648 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat
2025-12-08 02:37:28,664 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4854-2']
2025-12-08 02:37:28,664 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:37:28,704 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:37:28,740 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:37:28,740 - DEBUG - Validated that VM ctest-VM31-75147678 is in Vrouter an-jenkins-deploy-platform-ansible-os-4854-2 UVE
2025-12-08 02:37:28,740 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-08 02:37:28,747 - DEBUG - Expected tap interface of VM uuid d4085425-2335-4d1e-bf05-03a65246ea6a is default-domain:ctest-TestPolicyAcl-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7
2025-12-08 02:37:28,747 - DEBUG - Expected VN of VM uuid d4085425-2335-4d1e-bf05-03a65246ea6a is default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:37:28,747 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:37:28,782 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:37:28,812 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:37:28,812 - INFO - tap interface default-domain:ctest-TestPolicyAcl-89640753:ba5cfca4-0783-441a-b391-3c147c7c1fc7 of vm d4085425-2335-4d1e-bf05-03a65246ea6a is present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:37:28,812 - DEBUG - Connected network default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570 of vm d4085425-2335-4d1e-bf05-03a65246ea6a is present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:37:28,812 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.23
2025-12-08 02:37:28,813 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-08 02:37:28,823 - DEBUG - VM link and name as {'name': 'd4085425-2335-4d1e-bf05-03a65246ea6a', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat'}
2025-12-08 02:37:28,823 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.22
2025-12-08 02:37:28,823 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-08 02:37:28,835 - DEBUG - VM link and name as {'name': 'd4085425-2335-4d1e-bf05-03a65246ea6a', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat'}
2025-12-08 02:37:28,836 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.65
2025-12-08 02:37:28,836 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-08 02:37:28,848 - DEBUG - VM link and name as {'name': 'd4085425-2335-4d1e-bf05-03a65246ea6a', 'href': 'http://10.0.0.65:8081/analytics/uves/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a?flat'}
2025-12-08 02:37:28,848 - INFO - VM ctest-VM31-75147678 validations in Opserver passed
2025-12-08 02:37:28,848 - INFO - Waiting for VM ctest-VM11-34676251 to be up..
2025-12-08 02:37:28,848 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:28,848 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:37:28,855 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/88f3a9c3-cdb2-47a8-bc9c-138d979ea885
2025-12-08 02:37:30,015 - 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.17 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.30 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.296/1.734/2.172/0.438 ms')
2025-12-08 02:37:30,016 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM11-34676251 passed
2025-12-08 02:37:30,085 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:30,085 - DEBUG - Waiting to SSH to VM ctest-VM11-34676251, IP 197.59.139.3, Port 22
2025-12-08 02:37:30,154 - 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-08 02:37:30,232 - DEBUG - VM ctest-VM11-34676251 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-08 02:37:35,233 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:35,233 - DEBUG - Waiting to SSH to VM ctest-VM11-34676251, IP 197.59.139.3, Port 22
2025-12-08 02:37:35,307 - 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-08 02:37:35,421 - DEBUG - VM ctest-VM11-34676251 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-08 02:37:40,422 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:40,422 - DEBUG - Waiting to SSH to VM ctest-VM11-34676251, IP 197.59.139.3, Port 22
2025-12-08 02:37:40,489 - 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-08 02:37:40,580 - DEBUG - VM ctest-VM11-34676251 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-08 02:37:45,580 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:45,581 - DEBUG - Waiting to SSH to VM ctest-VM11-34676251, IP 197.59.139.3, Port 22
2025-12-08 02:37:45,753 - DEBUG - VM ctest-VM11-34676251 is ready for SSH connections
2025-12-08 02:37:45,753 - INFO - Waiting for VM ctest-VM21-69796466 to be up..
2025-12-08 02:37:45,754 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:45,754 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/7c69cd00-8407-4c42-8be9-6316afa58d93
2025-12-08 02:37:45,765 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/da0662ea-77e3-4ab8-bec3-6c3896b6ffa3
2025-12-08 02:37:46,920 - 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.95 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.559 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.559/1.255/1.952/0.696 ms')
2025-12-08 02:37:46,920 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-VM21-69796466 passed
2025-12-08 02:37:46,989 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:46,989 - DEBUG - Waiting to SSH to VM ctest-VM21-69796466, IP 88.61.190.131, Port 22
2025-12-08 02:37:47,158 - DEBUG - VM ctest-VM21-69796466 is ready for SSH connections
2025-12-08 02:37:47,158 - INFO - Waiting for VM ctest-VM31-75147678 to be up..
2025-12-08 02:37:47,158 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:47,158 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:37:47,166 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine-interface/ba5cfca4-0783-441a-b391-3c147c7c1fc7
2025-12-08 02:37:48,323 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=3.41 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.802 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.802/2.107/3.412/1.305 ms')
2025-12-08 02:37:48,323 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-VM31-75147678 passed
2025-12-08 02:37:48,398 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-08 02:37:48,398 - DEBUG - Waiting to SSH to VM ctest-VM31-75147678, IP 130.90.86.3, Port 22
2025-12-08 02:37:48,570 - DEBUG - VM ctest-VM31-75147678 is ready for SSH connections
2025-12-08 02:37:48,570 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 88.61.190.131, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.129, gateway password: c0ntrail123
2025-12-08 02:37:48,570 - DEBUG - ping -s 56 -c 3 -W 1 88.61.190.131
2025-12-08 02:38:10,809 - DEBUG - PING 88.61.190.131 (88.61.190.131) 56(84) bytes of data.
64 bytes from 88.61.190.131: icmp_req=1 ttl=63 time=5.34 ms
64 bytes from 88.61.190.131: icmp_req=2 ttl=63 time=1.23 ms
64 bytes from 88.61.190.131: icmp_req=3 ttl=63 time=1.51 ms
--- 88.61.190.131 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.232/2.698/5.348/1.877 ms
2025-12-08 02:38:10,809 - INFO - Ping to IP 88.61.190.131 from VM ctest-VM11-34676251 passed
2025-12-08 02:38:10,810 - INFO - Test with src as VN and dst as policy PASSED
2025-12-08 02:38:10,810 - INFO - Deleting VM ctest-VM31-75147678
2025-12-08 02:38:10,879 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:10,879 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:38:10,888 - DEBUG - VM ID d4085425-2335-4d1e-bf05-03a65246ea6a of VM ctest-VM31-75147678 is still found in API Server
2025-12-08 02:38:12,889 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:12,889 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:38:12,896 - DEBUG - Response Code: 404
2025-12-08 02:38:12,896 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:38:12,901 - DEBUG - Response Code: 404
2025-12-08 02:38:12,902 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/d4085425-2335-4d1e-bf05-03a65246ea6a
2025-12-08 02:38:12,907 - DEBUG - Response Code: 404
2025-12-08 02:38:12,908 - INFO - VM ctest-VM31-75147678 is fully removed in API-Server
2025-12-08 02:38:13,075 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-08 02:38:13,114 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:38:13,124 - DEBUG - Validated that vrouter 10.0.0.129 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:38:13,124 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570
2025-12-08 02:38:13,124 - INFO - VM ctest-VM31-75147678 is removed in Compute, and routes are removed in all compute nodes
2025-12-08 02:38:13,365 - INFO - Routes for VM ctest-VM31-75147678 is removed in all control-nodes
2025-12-08 02:38:13,365 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:13,402 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:13,436 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:13,437 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:13,437 - DEBUG - interface for vm d4085425-2335-4d1e-bf05-03a65246ea6a deleted from vrouter uve ...
2025-12-08 02:38:13,437 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:16,437 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:16,474 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:16,506 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:16,506 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:16,506 - DEBUG - interface for vm d4085425-2335-4d1e-bf05-03a65246ea6a deleted from vrouter uve ...
2025-12-08 02:38:16,506 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:19,507 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:19,544 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:19,584 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:19,584 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:19,584 - DEBUG - interface for vm d4085425-2335-4d1e-bf05-03a65246ea6a deleted from vrouter uve ...
2025-12-08 02:38:19,584 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:22,584 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:22,629 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:22,662 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:22,662 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:22,662 - DEBUG - interface for vm d4085425-2335-4d1e-bf05-03a65246ea6a deleted from vrouter uve ...
2025-12-08 02:38:22,662 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:25,663 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:25,701 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:25,730 - DEBUG - VM d4085425-2335-4d1e-bf05-03a65246ea6a is not present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:25,730 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:25,730 - DEBUG - interface for vm d4085425-2335-4d1e-bf05-03a65246ea6a deleted from vrouter uve ...
2025-12-08 02:38:25,730 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:25,730 - DEBUG - Validated that VM d4085425-2335-4d1e-bf05-03a65246ea6a is removed in Vrouter UVE
2025-12-08 02:38:25,731 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-08 02:38:25,731 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570?flat
2025-12-08 02:38:25,749 - DEBUG - d4085425-2335-4d1e-bf05-03a65246ea6a BM not in default-domain:ctest-TestPolicyAcl-89640753:ctest-VN3-51176570 uve
2025-12-08 02:38:25,749 - DEBUG - Validated that VM d4085425-2335-4d1e-bf05-03a65246ea6a is not present in the VN UVE
2025-12-08 02:38:25,749 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.23
2025-12-08 02:38:25,749 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-08 02:38:25,760 - INFO - d4085425-2335-4d1e-bf05-03a65246ea6a vm uve deleted from opserver
2025-12-08 02:38:25,760 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.22
2025-12-08 02:38:25,760 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-08 02:38:25,772 - INFO - d4085425-2335-4d1e-bf05-03a65246ea6a vm uve deleted from opserver
2025-12-08 02:38:25,772 - DEBUG - Verifying the d4085425-2335-4d1e-bf05-03a65246ea6a virtual network link through opserver 10.0.0.65
2025-12-08 02:38:25,772 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-08 02:38:25,785 - INFO - d4085425-2335-4d1e-bf05-03a65246ea6a vm uve deleted from opserver
2025-12-08 02:38:25,786 - INFO - Validated that VM d4085425-2335-4d1e-bf05-03a65246ea6a is removed from Opserver
2025-12-08 02:38:25,786 - INFO - Deleting VM ctest-VM21-69796466
2025-12-08 02:38:25,857 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:25,857 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/7c69cd00-8407-4c42-8be9-6316afa58d93
2025-12-08 02:38:25,866 - DEBUG - VM ID 7c69cd00-8407-4c42-8be9-6316afa58d93 of VM ctest-VM21-69796466 is still found in API Server
2025-12-08 02:38:27,867 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:27,867 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/7c69cd00-8407-4c42-8be9-6316afa58d93
2025-12-08 02:38:27,874 - DEBUG - Response Code: 404
2025-12-08 02:38:27,875 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/7c69cd00-8407-4c42-8be9-6316afa58d93
2025-12-08 02:38:27,882 - DEBUG - Response Code: 404
2025-12-08 02:38:27,882 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/7c69cd00-8407-4c42-8be9-6316afa58d93
2025-12-08 02:38:27,892 - DEBUG - Response Code: 404
2025-12-08 02:38:27,892 - INFO - VM ctest-VM21-69796466 is fully removed in API-Server
2025-12-08 02:38:28,045 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-08 02:38:28,079 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN2-28871580
2025-12-08 02:38:28,089 - DEBUG - Validated that vrouter 10.0.0.129 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN2-28871580
2025-12-08 02:38:28,089 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN2-28871580
2025-12-08 02:38:28,089 - INFO - VM ctest-VM21-69796466 is removed in Compute, and routes are removed in all compute nodes
2025-12-08 02:38:28,293 - INFO - Routes for VM ctest-VM21-69796466 is removed in all control-nodes
2025-12-08 02:38:28,293 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-1:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:28,329 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-1?flat
2025-12-08 02:38:28,358 - DEBUG - VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-1 uve
2025-12-08 02:38:28,358 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:28,358 - DEBUG - interface for vm 7c69cd00-8407-4c42-8be9-6316afa58d93 deleted from vrouter uve ...
2025-12-08 02:38:28,358 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:31,359 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-1:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:31,396 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-1?flat
2025-12-08 02:38:31,428 - DEBUG - VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-1 uve
2025-12-08 02:38:31,428 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:31,428 - DEBUG - interface for vm 7c69cd00-8407-4c42-8be9-6316afa58d93 deleted from vrouter uve ...
2025-12-08 02:38:31,428 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:34,429 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-1:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:34,462 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-1?flat
2025-12-08 02:38:34,492 - DEBUG - VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4854-1 uve
2025-12-08 02:38:34,492 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:34,492 - DEBUG - interface for vm 7c69cd00-8407-4c42-8be9-6316afa58d93 deleted from vrouter uve ...
2025-12-08 02:38:34,492 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:34,492 - DEBUG - Validated that VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is removed in Vrouter UVE
2025-12-08 02:38:34,492 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-08 02:38:34,492 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-89640753:ctest-VN2-28871580?flat
2025-12-08 02:38:34,510 - DEBUG - 7c69cd00-8407-4c42-8be9-6316afa58d93 BM not in default-domain:ctest-TestPolicyAcl-89640753:ctest-VN2-28871580 uve
2025-12-08 02:38:34,511 - DEBUG - Validated that VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is not present in the VN UVE
2025-12-08 02:38:34,511 - DEBUG - Verifying the 7c69cd00-8407-4c42-8be9-6316afa58d93 virtual network link through opserver 10.0.0.23
2025-12-08 02:38:34,511 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-08 02:38:34,524 - INFO - 7c69cd00-8407-4c42-8be9-6316afa58d93 vm uve deleted from opserver
2025-12-08 02:38:34,524 - DEBUG - Verifying the 7c69cd00-8407-4c42-8be9-6316afa58d93 virtual network link through opserver 10.0.0.22
2025-12-08 02:38:34,524 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-08 02:38:34,536 - INFO - 7c69cd00-8407-4c42-8be9-6316afa58d93 vm uve deleted from opserver
2025-12-08 02:38:34,536 - DEBUG - Verifying the 7c69cd00-8407-4c42-8be9-6316afa58d93 virtual network link through opserver 10.0.0.65
2025-12-08 02:38:34,536 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-08 02:38:34,549 - INFO - 7c69cd00-8407-4c42-8be9-6316afa58d93 vm uve deleted from opserver
2025-12-08 02:38:34,549 - INFO - Validated that VM 7c69cd00-8407-4c42-8be9-6316afa58d93 is removed from Opserver
2025-12-08 02:38:34,549 - INFO - Deleting VM ctest-VM11-34676251
2025-12-08 02:38:34,620 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:34,620 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:34,630 - DEBUG - VM ID 29834a7f-4e0a-47f1-89f1-df38c5e74add of VM ctest-VM11-34676251 is still found in API Server
2025-12-08 02:38:36,630 - DEBUG - Verifying in api server 10.0.0.65
2025-12-08 02:38:36,630 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:36,637 - DEBUG - Response Code: 404
2025-12-08 02:38:36,637 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:36,642 - DEBUG - Response Code: 404
2025-12-08 02:38:36,643 - DEBUG - Requesting: http://10.0.0.65:8082/virtual-machine/29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:36,647 - DEBUG - Response Code: 404
2025-12-08 02:38:36,647 - INFO - VM ctest-VM11-34676251 is fully removed in API-Server
2025-12-08 02:38:36,804 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-08 02:38:36,839 - DEBUG - Validated that vrouter 10.0.0.41 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN1-30769467
2025-12-08 02:38:36,850 - DEBUG - Validated that vrouter 10.0.0.129 does not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN1-30769467
2025-12-08 02:38:36,851 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestPolicyAcl-89640753:ctest-VN1-30769467
2025-12-08 02:38:36,851 - INFO - VM ctest-VM11-34676251 is removed in Compute, and routes are removed in all compute nodes
2025-12-08 02:38:37,034 - INFO - Routes for VM ctest-VM11-34676251 is removed in all control-nodes
2025-12-08 02:38:37,034 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:37,071 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:37,102 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:37,102 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:37,102 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:37,102 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:40,102 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:40,143 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:40,175 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:40,175 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:40,175 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:40,175 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:43,176 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:43,213 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:43,243 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:43,243 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:43,243 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:43,243 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:46,244 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:46,285 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:46,315 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:46,315 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:46,315 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:46,315 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:49,317 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:49,353 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:49,388 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:49,388 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:49,388 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:49,388 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:52,389 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:52,425 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:52,455 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is still present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:52,455 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:52,455 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:52,455 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:55,456 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4854-2:Compute:contrail-vrouter-agent:0?flat
2025-12-08 02:38:55,498 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4854-2?flat
2025-12-08 02:38:55,528 - DEBUG - VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is not present in vrouter an-jenkins-deploy-platform-ansible-os-4854-2 uve
2025-12-08 02:38:55,528 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-08 02:38:55,528 - DEBUG - interface for vm 29834a7f-4e0a-47f1-89f1-df38c5e74add deleted from vrouter uve ...
2025-12-08 02:38:55,528 - DEBUG - Deleted interface not in error interface list ...
2025-12-08 02:38:55,528 - DEBUG - Validated that VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is removed in Vrouter UVE
2025-12-08 02:38:55,528 - DEBUG - Verifying through opserver in 10.0.0.23
2025-12-08 02:38:55,528 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestPolicyAcl-89640753:ctest-VN1-30769467?flat
2025-12-08 02:38:55,546 - DEBUG - 29834a7f-4e0a-47f1-89f1-df38c5e74add BM not in default-domain:ctest-TestPolicyAcl-89640753:ctest-VN1-30769467 uve
2025-12-08 02:38:55,546 - DEBUG - Validated that VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is not present in the VN UVE
2025-12-08 02:38:55,546 - DEBUG - Verifying the 29834a7f-4e0a-47f1-89f1-df38c5e74add virtual network link through opserver 10.0.0.23
2025-12-08 02:38:55,546 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-machines
2025-12-08 02:38:55,558 - DEBUG - No links retuned for 29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:55,558 - INFO - 29834a7f-4e0a-47f1-89f1-df38c5e74add vm uve deleted from opserver
2025-12-08 02:38:55,558 - DEBUG - Verifying the 29834a7f-4e0a-47f1-89f1-df38c5e74add virtual network link through opserver 10.0.0.22
2025-12-08 02:38:55,558 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-08 02:38:55,569 - DEBUG - No links retuned for 29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:55,569 - INFO - 29834a7f-4e0a-47f1-89f1-df38c5e74add vm uve deleted from opserver
2025-12-08 02:38:55,569 - DEBUG - Verifying the 29834a7f-4e0a-47f1-89f1-df38c5e74add virtual network link through opserver 10.0.0.65
2025-12-08 02:38:55,569 - DEBUG - Requesting: http://10.0.0.65:8081/analytics/uves/virtual-machines
2025-12-08 02:38:55,583 - DEBUG - No links retuned for 29834a7f-4e0a-47f1-89f1-df38c5e74add
2025-12-08 02:38:55,583 - INFO - 29834a7f-4e0a-47f1-89f1-df38c5e74add vm uve deleted from opserver
2025-12-08 02:38:55,583 - INFO - Validated that VM 29834a7f-4e0a-47f1-89f1-df38c5e74add is removed from Opserver
2025-12-08 02:38:55,583 - DEBUG - Detaching the Policy for VN :ctest-VN2-28871580
2025-12-08 02:38:55,583 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-08 02:38:55,589 - DEBUG - Requesting: http://10.0.0.23:8082/domain/c5befdc1-279e-4ac1-9620-9608231491f8
2025-12-08 02:38:55,605 - DEBUG - Requesting: http://10.0.0.23:8082/project/e5663c78-a584-42ea-aaab-d23b9ff29fa1
2025-12-08 02:38:55,697 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/aaf9bffe-894a-4bf9-9388-e887bc6890b7
2025-12-08 02:38:55,708 - DEBUG - Requesting: http://10.0.0.23:8082/network-policy/4c0df844-5010-4081-bb20-268b6d8bd79c
2025-12-08 02:38:55,944 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestPolicyAcl-89640753', 'ctest-policy21-51056033']] from ctest-VN2-28871580
2025-12-08 02:38:55,944 - DEBUG - Detaching the Policy for VN :ctest-VN1-30769467
2025-12-08 02:38:55,944 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-08 02:38:55,953 - DEBUG - Requesting: http://10.0.0.23:8082/domain/c5befdc1-279e-4ac1-9620-9608231491f8
2025-12-08 02:38:55,965 - DEBUG - Requesting: http://10.0.0.23:8082/project/e5663c78-a584-42ea-aaab-d23b9ff29fa1
2025-12-08 02:38:56,052 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-network/3ccc3bba-65a6-43d7-8167-6e935de2711a
2025-12-08 02:38:56,246 - INFO - Detached Policy from ctest-VN1-30769467
2025-12-08 02:38:56,308 - INFO - Deleted policy ctest-policy13-05730760
2025-12-08 02:38:56,341 - INFO - Deleted policy ctest-policy21-51056033
2025-12-08 02:38:56,394 - INFO - Deleted policy ctest-policy12-26613443
2025-12-08 02:38:56,394 - INFO - Deleting VN ctest-VN3-51176570
2025-12-08 02:38:56,576 - DEBUG - Response for deleting network ()
2025-12-08 02:38:56,576 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/3fb2837c-39bd-4e3c-b9f0-b3eb89de8ac7
2025-12-08 02:38:56,583 - DEBUG - Response Code: 404
2025-12-08 02:38:56,584 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-08 02:38:56,590 - DEBUG - Requesting: http://10.0.0.23:8082/domain/c5befdc1-279e-4ac1-9620-9608231491f8
2025-12-08 02:38:56,602 - DEBUG - Requesting: http://10.0.0.23:8082/project/e5663c78-a584-42ea-aaab-d23b9ff29fa1
2025-12-08 02:38:56,685 - INFO - Validated that VN ctest-VN3-51176570 is not found in API Server
2025-12-08 02:38:56,696 - DEBUG - VN ctest-VN3-51176570 is not present in Agent 10.0.0.41
2025-12-08 02:38:56,706 - DEBUG - VN ctest-VN3-51176570 is not present in Agent 10.0.0.129
2025-12-08 02:38:56,706 - INFO - Validated that VN ctest-VN3-51176570 is not in any agent
2025-12-08 02:38:56,734 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN3-51176570 info
2025-12-08 02:38:56,735 - INFO - Deleting VN ctest-VN2-28871580
2025-12-08 02:38:56,890 - DEBUG - Response for deleting network ()
2025-12-08 02:38:56,890 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/b48985fd-e368-44c6-96dc-c9afd28ba5cd
2025-12-08 02:38:56,895 - DEBUG - Response Code: 404
2025-12-08 02:38:56,895 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-08 02:38:56,908 - DEBUG - Requesting: http://10.0.0.23:8082/domain/c5befdc1-279e-4ac1-9620-9608231491f8
2025-12-08 02:38:56,967 - DEBUG - Requesting: http://10.0.0.23:8082/project/e5663c78-a584-42ea-aaab-d23b9ff29fa1
2025-12-08 02:38:57,057 - INFO - Validated that VN ctest-VN2-28871580 is not found in API Server
2025-12-08 02:38:57,067 - DEBUG - VN ctest-VN2-28871580 is not present in Agent 10.0.0.41
2025-12-08 02:38:57,079 - DEBUG - VN ctest-VN2-28871580 is not present in Agent 10.0.0.129
2025-12-08 02:38:57,079 - INFO - Validated that VN ctest-VN2-28871580 is not in any agent
2025-12-08 02:38:57,113 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN2-28871580 info
2025-12-08 02:38:57,113 - INFO - Deleting VN ctest-VN1-30769467
2025-12-08 02:38:57,298 - DEBUG - Response for deleting network ()
2025-12-08 02:38:57,298 - DEBUG - Requesting: http://10.0.0.23:8082/routing-instance/e432b20b-4ddf-49cc-9a21-00beb603b114
2025-12-08 02:38:57,306 - DEBUG - Response Code: 404
2025-12-08 02:38:57,306 - DEBUG - Requesting: http://10.0.0.23:8082/domains
2025-12-08 02:38:57,313 - DEBUG - Requesting: http://10.0.0.23:8082/domain/c5befdc1-279e-4ac1-9620-9608231491f8
2025-12-08 02:38:57,326 - DEBUG - Requesting: http://10.0.0.23:8082/project/e5663c78-a584-42ea-aaab-d23b9ff29fa1
2025-12-08 02:38:57,414 - INFO - Validated that VN ctest-VN1-30769467 is not found in API Server
2025-12-08 02:38:57,426 - DEBUG - VN ctest-VN1-30769467 is not present in Agent 10.0.0.41
2025-12-08 02:38:57,437 - DEBUG - VN ctest-VN1-30769467 is not present in Agent 10.0.0.129
2025-12-08 02:38:57,437 - INFO - Validated that VN ctest-VN1-30769467 is not in any agent
2025-12-08 02:38:57,465 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-VN1-30769467 info
2025-12-08 02:38:57,553 - INFO - IPAM: ipam3 is not found in API Server
2025-12-08 02:38:57,575 - INFO - IPAM:ipam3 is not found in control node
2025-12-08 02:38:57,713 - INFO - IPAM: ipam2 is not found in API Server
2025-12-08 02:38:57,743 - INFO - IPAM:ipam2 is not found in control node
2025-12-08 02:38:57,889 - INFO - IPAM: ipam1 is not found in API Server
2025-12-08 02:38:57,910 - INFO - IPAM:ipam1 is not found in control node
2025-12-08 02:38:59,199 - DEBUG - No XMPP flaps were noticed during the test
2025-12-08 02:38:59,199 - INFO - END TEST : test_policy_inheritance_src_vn_dst_pol : PASSED[0:02:41]
2025-12-08 02:38:59,199 - INFO - --------------------------------------------------------------------------------
2025-12-08 02:38:59,996 - INFO - Deleted project: ctest-TestPolicyAcl-89640753, ID : e5663c78-a584-42ea-aaab-d23b9ff29fa1