2025-12-29 04:16:19,813 - INFO - Domain Default found not creating
2025-12-29 04:16:19,977 - INFO - Project ctest-TestBasicVMVN0-02904210 not found, creating it
2025-12-29 04:16:20,490 - INFO - Created Project:ctest-TestBasicVMVN0-02904210, ID : 1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:16:22,068 - INFO - ================================================================================
2025-12-29 04:16:22,069 - INFO - STARTING TEST : test_control_node_switchover
2025-12-29 04:16:22,069 - INFO - TEST DESCRIPTION : Stop the control node and check peering with agent fallback to other control node.
1. Pick one VN from respource pool which has 2 VM's in it
2. Verify ping between VM's
3. Find active control node in cluster by agent inspect
4. Stop control service on active control node
5. Verify agents are connected to new active control-node using xmpp connections
6. Bring back control service on previous active node
7. Verify ping between VM's again after bringing up control serveice
Pass criteria: Step 2,5 and 7 should pass
2025-12-29 04:16:23,340 - DEBUG - Skipping xmpp flap check
2025-12-29 04:16:23,341 - INFO - Initial checks done. Running the testcase now
2025-12-29 04:16:23,341 - INFO -
2025-12-29 04:16:23,993 - DEBUG - Response for create_network : {'network': {'id': 'f496d846-bbe3-4246-84e2-e4c096269c2b', 'name': 'ctest-vn1-19133818', 'tenant_id': '1c4478b4d1bb4f3881a55554efeaadc3', 'project_id': '1c4478b4d1bb4f3881a55554efeaadc3', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-02904210', 'ctest-vn1-19133818'], 'port_security_enabled': True, 'description': ''}}
2025-12-29 04:16:24,249 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f81322c5-0761-4547-ae04-feab75ba888b', 'name': '', 'tenant_id': '1c4478b4d1bb4f3881a55554efeaadc3', 'network_id': 'f496d846-bbe3-4246-84e2-e4c096269c2b', 'ip_version': 4, 'cidr': '192.168.1.0/24', 'allocation_pools': [{'start': '192.168.1.2', 'end': '192.168.1.254'}], 'gateway_ip': '192.168.1.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '192.168.1.2', 'tags': [], 'project_id': '1c4478b4d1bb4f3881a55554efeaadc3'}}
2025-12-29 04:16:24,274 - INFO - Created VN ctest-vn1-19133818
2025-12-29 04:16:24,284 - DEBUG - VN ctest-vn1-19133818 UUID is f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,353 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:16:24,657 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:16:24,687 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:16:24,702 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:16:24,806 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,820 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,829 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:16:24,838 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:16:24,848 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/672f5412-e7d1-46de-bcce-056f9b733374
2025-12-29 04:16:24,855 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:16:24,855 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,863 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:16:24,877 - INFO - Verified VN network id 12 for VN f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,877 - INFO - Verifications in API Server for VN ctest-vn1-19133818 passed
2025-12-29 04:16:24,877 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:24,887 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:16:24,894 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:16:24,902 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/672f5412-e7d1-46de-bcce-056f9b733374
2025-12-29 04:16:24,915 - DEBUG - Control-node 10.0.0.61 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17624511990072558150', 'uuid-lslong': '9575467273547062315'}, 'enable': 'true', 'created': '2025-12-29T04:16:23', 'last-modified': '2025-12-29T04:16:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.713141'}
2025-12-29 04:16:24,921 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:16:24,925 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17624511990072558150', 'uuid-lslong': '9575467273547062315'}, 'enable': 'true', 'created': '2025-12-29T04:16:23', 'last-modified': '2025-12-29T04:16:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.725050'}
2025-12-29 04:16:24,931 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:16:24,936 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17624511990072558150', 'uuid-lslong': '9575467273547062315'}, 'enable': 'true', 'created': '2025-12-29T04:16:23', 'last-modified': '2025-12-29T04:16:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.737021'}
2025-12-29 04:16:24,943 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:16:24,943 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-19133818 passed
2025-12-29 04:16:24,943 - DEBUG - ====Verifying policy data for ctest-vn1-19133818 in API_Server ======
2025-12-29 04:16:24,943 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:16:24,948 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:16:24,959 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:16:25,051 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/f496d846-bbe3-4246-84e2-e4c096269c2b
2025-12-29 04:16:25,061 - DEBUG - =>VN ctest-vn1-19133818 has no policy to be verified
2025-12-29 04:16:25,061 - DEBUG - Verifying the vn in opserver
2025-12-29 04:16:25,061 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 virtual network link through opserver 10.0.0.61
2025-12-29 04:16:25,061 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-networks
2025-12-29 04:16:25,359 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-networks
2025-12-29 04:16:25,429 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat'}
2025-12-29 04:16:25,430 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 virtual network link through opserver 10.0.0.22
2025-12-29 04:16:25,430 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-12-29 04:16:25,730 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-12-29 04:16:25,798 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat'}
2025-12-29 04:16:25,798 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 virtual network link through opserver 10.0.0.27
2025-12-29 04:16:25,798 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks
2025-12-29 04:16:26,103 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks
2025-12-29 04:16:26,185 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat'}
2025-12-29 04:16:26,186 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is found in opserver
2025-12-29 04:16:26,209 - DEBUG - Do not have enough data to verify VN in agent
2025-12-29 04:16:26,219 - DEBUG - VRF ids for VN ctest-vn1-19133818: {}
2025-12-29 04:16:26,276 - DEBUG - Services list from nova: [, , , ]
2025-12-29 04:16:27,323 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-1)
2025-12-29 04:16:28,747 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-2)
2025-12-29 04:16:28,747 - INFO - Waiting for VM ctest-vn1_vm1-48754280 to be up..
2025-12-29 04:16:28,849 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-12-29 04:16:33,963 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:16:33,963 - INFO - VM name : ctest-vn1_vm1-48754280
2025-12-29 04:16:34,164 - DEBUG - VM ctest-vn1_vm1-48754280 ID is e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:16:34,187 - DEBUG - VM ctest-vn1_vm1-48754280 launched on Node an-jenkins-deploy-platform-ansible-os-4934-1
2025-12-29 04:16:34,271 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:16:34,590 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:16:34,632 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/9da15eb1-2e51-4c15-895a-b78e52ed3aa2
2025-12-29 04:16:37,810 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms')
2025-12-29 04:16:37,811 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:37,824 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:16:41,902 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2025-12-29 04:16:41,902 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:41,918 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:16:45,998 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:16:45,998 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:46,013 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:16:50,098 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms')
2025-12-29 04:16:50,098 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:50,112 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:16:54,188 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1011ms')
2025-12-29 04:16:54,188 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:54,205 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:16:58,282 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:16:58,282 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:16:58,296 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:17:02,390 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms')
2025-12-29 04:17:02,390 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:17:02,404 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:17:06,480 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-12-29 04:17:06,480 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:17:06,492 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:17:10,576 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2025-12-29 04:17:10,576 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 failed!
2025-12-29 04:17:10,591 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is 192.168.1.1 and allocation pool is NOT set
2025-12-29 04:17:12,659 - 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=10.9 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.871 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.871/5.891/10.912/5.020 ms')
2025-12-29 04:17:12,659 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-48754280 passed
2025-12-29 04:17:12,733 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:12,733 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:12,799 - 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-29 04:17:12,918 - DEBUG - VM ctest-vn1_vm1-48754280 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:17:17,919 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:17,919 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:17,987 - 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-29 04:17:18,071 - DEBUG - VM ctest-vn1_vm1-48754280 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:17:23,072 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:23,072 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:23,139 - 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-29 04:17:23,225 - DEBUG - VM ctest-vn1_vm1-48754280 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:17:28,225 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:28,225 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:28,291 - 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-29 04:17:28,365 - DEBUG - VM ctest-vn1_vm1-48754280 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:17:33,366 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:33,366 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:33,437 - 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-29 04:17:33,530 - DEBUG - VM ctest-vn1_vm1-48754280 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:17:38,531 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:38,531 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-48754280, IP 192.168.1.3, Port 22
2025-12-29 04:17:38,699 - DEBUG - VM ctest-vn1_vm1-48754280 is ready for SSH connections
2025-12-29 04:17:38,699 - INFO - Waiting for VM ctest-vn1_vm2-01876245 to be up..
2025-12-29 04:17:38,801 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:17:38,801 - INFO - VM name : ctest-vn1_vm2-01876245
2025-12-29 04:17:38,900 - DEBUG - VM ctest-vn1_vm2-01876245 ID is 1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:17:38,901 - DEBUG - VM ctest-vn1_vm2-01876245 launched on Node an-jenkins-deploy-platform-ansible-os-4934-2
2025-12-29 04:17:39,002 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:17:39,013 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/a638b5e3-5895-4774-acd6-02bbed4ccc59
2025-12-29 04:17:40,187 - 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.62 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.08 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.084/1.850/2.616/0.766 ms')
2025-12-29 04:17:40,187 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm2-01876245 passed
2025-12-29 04:17:40,263 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:40,263 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-01876245, IP 192.168.1.4, Port 22
2025-12-29 04:17:40,422 - DEBUG - VM ctest-vn1_vm2-01876245 is ready for SSH connections
2025-12-29 04:17:40,422 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:17:40,422 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.1.4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.56, gateway password: c0ntrail123
2025-12-29 04:17:40,422 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4
2025-12-29 04:18:04,910 - DEBUG - PING 192.168.1.4 (192.168.1.4) 56(84) bytes of data.
64 bytes from 192.168.1.4: icmp_req=1 ttl=64 time=10.3 ms
64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=1.46 ms
64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.24 ms
--- 192.168.1.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.240/4.353/10.356/4.245 ms
2025-12-29 04:18:04,910 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-48754280 passed
2025-12-29 04:18:04,910 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:18:04,910 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.1.3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2025-12-29 04:18:04,910 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3
2025-12-29 04:18:44,715 - DEBUG - PING 192.168.1.3 (192.168.1.3) 56(84) bytes of data.
64 bytes from 192.168.1.3: icmp_req=1 ttl=64 time=7.08 ms
64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.40 ms
64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=1.41 ms
--- 192.168.1.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.409/3.303/7.089/2.677 ms
2025-12-29 04:18:44,715 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-01876245 passed
2025-12-29 04:18:44,723 - INFO - Active control node from the Agent 10.0.0.56 is 10.0.0.61
2025-12-29 04:18:44,723 - INFO - Stoping the Control service in 10.0.0.61
2025-12-29 04:18:45,372 - INFO - 10.0.0.61
2025-12-29 04:18:45,372 - INFO - control:inactive
2025-12-29 04:18:45,373 - INFO - Contrail services control are down on nodes 10.0.0.61
2025-12-29 04:18:50,381 - INFO - Active control node from the Agent 10.0.0.56 is 10.0.0.27
2025-12-29 04:18:50,382 - INFO - Starting the Control service in 10.0.0.61
2025-12-29 04:18:50,806 - INFO - 10.0.0.61
2025-12-29 04:18:50,813 - INFO - control:initializing
2025-12-29 04:18:50,814 - DEBUG - defaultdict(, {'10.0.0.61': {'control': {'status': 'initializing', 'description': None}}})
2025-12-29 04:18:50,814 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:18:55,919 - INFO - 10.0.0.61
2025-12-29 04:18:55,925 - INFO - control:active
2025-12-29 04:18:55,925 - INFO - Contrail services ['control'] are up on nodes 10.0.0.61
2025-12-29 04:19:01,025 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:19:01,026 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:19:01,026 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:01,053 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/9da15eb1-2e51-4c15-895a-b78e52ed3aa2
2025-12-29 04:19:01,071 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:01,080 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/9da15eb1-2e51-4c15-895a-b78e52ed3aa2
2025-12-29 04:19:01,095 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/6d02f63d-a22b-4ed7-924c-9bea58f1bb1d
2025-12-29 04:19:01,108 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:01,108 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:01,115 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/9da15eb1-2e51-4c15-895a-b78e52ed3aa2
2025-12-29 04:19:01,126 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/6d02f63d-a22b-4ed7-924c-9bea58f1bb1d
2025-12-29 04:19:01,138 - INFO - VM ctest-vn1_vm1-48754280 verfication in all API Servers passed
2025-12-29 04:19:01,159 - DEBUG - VM ctest-vn1_vm1-48754280 Tap interface: {'index': '3', 'name': 'tap9da15eb1-2e', 'uuid': '9da15eb1-2e51-4c15-895a-b78e52ed3aa2', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', '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': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'vm_name': 'ctest-vn1_vm1-48754280', 'ip_addr': '192.168.1.3', 'mac_addr': '02:9d:a1:5e:b1:2e', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '159', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '30', '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-29 04:19:01,159 - DEBUG - Agent 10.0.0.56 vrf name: default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818
2025-12-29 04:19:01,165 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'table_label': '-1', 'vxlan_id': '12', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.241:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-29 04:19:01,255 - DEBUG - VM ctest-vn1_vm1-48754280 : Tap interface tap9da15eb1-2e is set to Active
2025-12-29 04:19:01,256 - DEBUG - Tap interface tap9da15eb1-2e detail : {'index': '3', 'name': 'tap9da15eb1-2e', 'uuid': '9da15eb1-2e51-4c15-895a-b78e52ed3aa2', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', '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': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'vm_name': 'ctest-vn1_vm1-48754280', 'ip_addr': '192.168.1.3', 'mac_addr': '02:9d:a1:5e:b1:2e', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '159', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '30', '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-29 04:19:01,378 - DEBUG - Starting Layer 2 verification in Agent
2025-12-29 04:19:01,392 - DEBUG - Layer 2 path is seen for VM MAC 02:9d:a1:5e:b1:2e in agent 10.0.0.56
2025-12-29 04:19:01,392 - DEBUG - Active layer 2 route in agent is present for VMI tap9da15eb1-2e
2025-12-29 04:19:01,392 - DEBUG - L2 label(29) matches bw route table and interface table
2025-12-29 04:19:01,398 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is found in Agent of node 10.0.0.56
2025-12-29 04:19:01,531 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is consistent in agent 10.0.0.56
2025-12-29 04:19:01,531 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.56
2025-12-29 04:19:01,531 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 verification for VM ctest-vn1_vm1-48754280 in Agent 10.0.0.56 passed
2025-12-29 04:19:01,644 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56
2025-12-29 04:19:01,659 - DEBUG - Route for VM MAC 02:9d:a1:5e:b1:2e is consistent in agent 10.0.0.56
2025-12-29 04:19:01,666 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is found in Agent of node 10.0.0.240
2025-12-29 04:19:01,795 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is consistent in agent 10.0.0.240
2025-12-29 04:19:01,796 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.240
2025-12-29 04:19:01,796 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 verification for VM ctest-vn1_vm1-48754280 in Agent 10.0.0.240 passed
2025-12-29 04:19:01,905 - DEBUG - Starting all layer 2 verification in agent 10.0.0.240
2025-12-29 04:19:01,918 - DEBUG - Route for VM MAC 02:9d:a1:5e:b1:2e is consistent in agent 10.0.0.240
2025-12-29 04:19:01,918 - INFO - VM ctest-vn1_vm1-48754280 verifications in Compute nodes passed
2025-12-29 04:19:02,156 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.56
2025-12-29 04:19:02,161 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-29 04:19:02,273 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.240
2025-12-29 04:19:02,277 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.241, 25; Got 10.20.0.241,25
2025-12-29 04:19:02,278 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.240
2025-12-29 04:19:02,278 - INFO - Validated routes of VM ctest-vn1_vm1-48754280 in all vrouters
2025-12-29 04:19:02,791 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node
2025-12-29 04:19:02,918 - DEBUG - Layer2 route found for VM MAC 02:9d:a1:5e:b1:2e in Control-node 10.0.0.22
2025-12-29 04:19:02,918 - DEBUG - L2 Label for VM ctest-vn1_vm1-48754280 same between Control-node 10.0.0.22 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:02,918 - DEBUG - Starting all layer2 verification in 10.0.0.61 Control Node
2025-12-29 04:19:03,044 - DEBUG - Layer2 route found for VM MAC 02:9d:a1:5e:b1:2e in Control-node 10.0.0.61
2025-12-29 04:19:03,044 - DEBUG - L2 Label for VM ctest-vn1_vm1-48754280 same between Control-node 10.0.0.61 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:03,044 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node
2025-12-29 04:19:03,189 - DEBUG - Layer2 route found for VM MAC 02:9d:a1:5e:b1:2e in Control-node 10.0.0.27
2025-12-29 04:19:03,189 - DEBUG - L2 Label for VM ctest-vn1_vm1-48754280 same between Control-node 10.0.0.27 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:03,189 - INFO - Verification in Control-nodes for VM ctest-vn1_vm1-48754280 passed
2025-12-29 04:19:03,189 - DEBUG - Verifying the vm in opserver
2025-12-29 04:19:03,189 - DEBUG - Verifying in collector 10.0.0.27 ...
2025-12-29 04:19:03,189 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat
2025-12-29 04:19:03,212 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2?flat
2025-12-29 04:19:03,235 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2?flat
2025-12-29 04:19:03,307 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat
2025-12-29 04:19:03,398 - DEBUG - Verifying vm in vn uve
2025-12-29 04:19:03,398 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2?flat
2025-12-29 04:19:03,501 - DEBUG - VM uve shows interface as {'tx_vlan': 65535, 'uuid': '9da15eb1-2e51-4c15-895a-b78e52ed3aa2', 'mac_address': '02:9d:a1:5e:b1:2e', 'port_mirror_enabled': False, 'ip4_active': True, 'vn_uuid': 'f496d846-bbe3-4246-84e2-e4c096269c2b', 'fixed_ip4_list': ['192.168.1.3'], 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'ip_address': '192.168.1.3', 'rx_vlan': 65535, 'ip6_address': '::', 'vhostuser_mode': 0, 'ip6_active': False, 'is_health_check_active': True, 'admin_state': True, 'active': True, 'l2_active': True, 'vm_name': 'ctest-vn1_vm1-48754280', '__T': 1766981942949057, 'gateway': '192.168.1.1', 'label': 25}
2025-12-29 04:19:03,502 - DEBUG - VM uve shows ip address as ['192.168.1.3', '::']
2025-12-29 04:19:03,502 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:03,502 - INFO - Verifying through opserver in 10.0.0.61
2025-12-29 04:19:03,502 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat
2025-12-29 04:19:03,524 - DEBUG - expected vm list e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:03,524 - DEBUG - Extracted vm list ['e4686217-6c2c-4d7d-8e6c-a1837f73cfc9']
2025-12-29 04:19:03,524 - INFO - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is present in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:03,524 - DEBUG - Verifying vm in vrouter uve
2025-12-29 04:19:03,524 - DEBUG - Getting info from collector 10.0.0.27..
2025-12-29 04:19:03,524 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat
2025-12-29 04:19:03,607 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4934-1']
2025-12-29 04:19:03,607 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:03,673 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:03,707 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:03,707 - DEBUG - Validated that VM ctest-vn1_vm1-48754280 is in Vrouter an-jenkins-deploy-platform-ansible-os-4934-1 UVE
2025-12-29 04:19:03,707 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-29 04:19:03,717 - DEBUG - Expected tap interface of VM uuid e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2
2025-12-29 04:19:03,718 - DEBUG - Expected VN of VM uuid e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:03,718 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:03,779 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:03,813 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:03,813 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-02904210:9da15eb1-2e51-4c15-895a-b78e52ed3aa2 of vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:03,813 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 of vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:03,814 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.61
2025-12-29 04:19:03,814 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:19:03,827 - DEBUG - VM link and name as {'name': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat'}
2025-12-29 04:19:03,827 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.22
2025-12-29 04:19:03,827 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:19:03,844 - DEBUG - VM link and name as {'name': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat'}
2025-12-29 04:19:03,844 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.27
2025-12-29 04:19:03,844 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:19:03,861 - DEBUG - VM link and name as {'name': 'e4686217-6c2c-4d7d-8e6c-a1837f73cfc9', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9?flat'}
2025-12-29 04:19:03,861 - INFO - VM ctest-vn1_vm1-48754280 validations in Opserver passed
2025-12-29 04:19:03,956 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:19:03,957 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:19:03,957 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:03,966 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/a638b5e3-5895-4774-acd6-02bbed4ccc59
2025-12-29 04:19:03,981 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:03,991 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/a638b5e3-5895-4774-acd6-02bbed4ccc59
2025-12-29 04:19:04,004 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/5ef7d2f6-a414-4376-84d2-ed3a6bb7333f
2025-12-29 04:19:04,021 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:04,021 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:04,033 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/a638b5e3-5895-4774-acd6-02bbed4ccc59
2025-12-29 04:19:04,044 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/5ef7d2f6-a414-4376-84d2-ed3a6bb7333f
2025-12-29 04:19:04,054 - INFO - VM ctest-vn1_vm2-01876245 verfication in all API Servers passed
2025-12-29 04:19:04,077 - DEBUG - VM ctest-vn1_vm2-01876245 Tap interface: {'index': '3', 'name': 'tapa638b5e3-58', 'uuid': 'a638b5e3-5895-4774-acd6-02bbed4ccc59', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', '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': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'vm_name': 'ctest-vn1_vm2-01876245', 'ip_addr': '192.168.1.4', 'mac_addr': '02:a6:38:b5:e3:58', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '129', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '26', '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-29 04:19:04,077 - DEBUG - Agent 10.0.0.240 vrf name: default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818
2025-12-29 04:19:04,083 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'table_label': '-1', 'vxlan_id': '12', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.19:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-29 04:19:04,172 - DEBUG - VM ctest-vn1_vm2-01876245 : Tap interface tapa638b5e3-58 is set to Active
2025-12-29 04:19:04,172 - DEBUG - Tap interface tapa638b5e3-58 detail : {'index': '3', 'name': 'tapa638b5e3-58', 'uuid': 'a638b5e3-5895-4774-acd6-02bbed4ccc59', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818:ctest-vn1-19133818', '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': '25', 'l2_label': '29', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'vm_name': 'ctest-vn1_vm2-01876245', 'ip_addr': '192.168.1.4', 'mac_addr': '02:a6:38:b5:e3:58', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '129', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '26', '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-29 04:19:04,281 - DEBUG - Starting Layer 2 verification in Agent
2025-12-29 04:19:04,292 - DEBUG - Layer 2 path is seen for VM MAC 02:a6:38:b5:e3:58 in agent 10.0.0.240
2025-12-29 04:19:04,293 - DEBUG - Active layer 2 route in agent is present for VMI tapa638b5e3-58
2025-12-29 04:19:04,293 - DEBUG - L2 label(29) matches bw route table and interface table
2025-12-29 04:19:04,300 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is found in Agent of node 10.0.0.56
2025-12-29 04:19:04,430 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is consistent in agent 10.0.0.56
2025-12-29 04:19:04,430 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.56
2025-12-29 04:19:04,430 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 verification for VM ctest-vn1_vm2-01876245 in Agent 10.0.0.56 passed
2025-12-29 04:19:04,537 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56
2025-12-29 04:19:04,548 - DEBUG - Route for VM MAC 02:a6:38:b5:e3:58 is consistent in agent 10.0.0.56
2025-12-29 04:19:04,554 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is found in Agent of node 10.0.0.240
2025-12-29 04:19:04,679 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 is consistent in agent 10.0.0.240
2025-12-29 04:19:04,679 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.240
2025-12-29 04:19:04,679 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 verification for VM ctest-vn1_vm2-01876245 in Agent 10.0.0.240 passed
2025-12-29 04:19:04,789 - DEBUG - Starting all layer 2 verification in agent 10.0.0.240
2025-12-29 04:19:04,803 - DEBUG - Route for VM MAC 02:a6:38:b5:e3:58 is consistent in agent 10.0.0.240
2025-12-29 04:19:04,804 - INFO - VM ctest-vn1_vm2-01876245 verifications in Compute nodes passed
2025-12-29 04:19:05,060 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.56
2025-12-29 04:19:05,065 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.19, 25; Got 10.20.0.19,25
2025-12-29 04:19:05,065 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.56
2025-12-29 04:19:05,212 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.240
2025-12-29 04:19:05,216 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-29 04:19:05,216 - INFO - Validated routes of VM ctest-vn1_vm2-01876245 in all vrouters
2025-12-29 04:19:05,725 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node
2025-12-29 04:19:05,863 - DEBUG - Layer2 route found for VM MAC 02:a6:38:b5:e3:58 in Control-node 10.0.0.22
2025-12-29 04:19:05,864 - DEBUG - L2 Label for VM ctest-vn1_vm2-01876245 same between Control-node 10.0.0.22 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:05,864 - DEBUG - Starting all layer2 verification in 10.0.0.61 Control Node
2025-12-29 04:19:06,003 - DEBUG - Layer2 route found for VM MAC 02:a6:38:b5:e3:58 in Control-node 10.0.0.61
2025-12-29 04:19:06,003 - DEBUG - L2 Label for VM ctest-vn1_vm2-01876245 same between Control-node 10.0.0.61 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:06,003 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node
2025-12-29 04:19:06,134 - DEBUG - Layer2 route found for VM MAC 02:a6:38:b5:e3:58 in Control-node 10.0.0.27
2025-12-29 04:19:06,134 - DEBUG - L2 Label for VM ctest-vn1_vm2-01876245 same between Control-node 10.0.0.27 and Agent, Expected: 29, Seen: 29
2025-12-29 04:19:06,134 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-01876245 passed
2025-12-29 04:19:06,134 - DEBUG - Verifying the vm in opserver
2025-12-29 04:19:06,135 - DEBUG - Verifying in collector 10.0.0.27 ...
2025-12-29 04:19:06,135 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat
2025-12-29 04:19:06,151 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59?flat
2025-12-29 04:19:06,172 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59?flat
2025-12-29 04:19:06,189 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat
2025-12-29 04:19:06,207 - DEBUG - Verifying vm in vn uve
2025-12-29 04:19:06,207 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59?flat
2025-12-29 04:19:06,226 - DEBUG - VM uve shows interface as {'tx_vlan': 65535, 'uuid': 'a638b5e3-5895-4774-acd6-02bbed4ccc59', 'mac_address': '02:a6:38:b5:e3:58', 'port_mirror_enabled': False, 'ip4_active': True, 'vn_uuid': 'f496d846-bbe3-4246-84e2-e4c096269c2b', 'fixed_ip4_list': ['192.168.1.4'], 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818', 'vm_uuid': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'ip_address': '192.168.1.4', 'rx_vlan': 65535, 'ip6_address': '::', 'vhostuser_mode': 0, 'ip6_active': False, 'is_health_check_active': True, 'admin_state': True, 'active': True, 'l2_active': True, 'vm_name': 'ctest-vn1_vm2-01876245', '__T': 1766981801730718, 'gateway': '192.168.1.1', 'label': 25}
2025-12-29 04:19:06,226 - DEBUG - VM uve shows ip address as ['192.168.1.4', '::']
2025-12-29 04:19:06,226 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:06,226 - INFO - Verifying through opserver in 10.0.0.61
2025-12-29 04:19:06,226 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat
2025-12-29 04:19:06,249 - DEBUG - expected vm list 1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:06,249 - DEBUG - Extracted vm list ['1e7b4e3b-5bfb-499a-bea1-dca0702a471f']
2025-12-29 04:19:06,249 - INFO - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is present in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:06,249 - DEBUG - Verifying vm in vrouter uve
2025-12-29 04:19:06,249 - DEBUG - Getting info from collector 10.0.0.27..
2025-12-29 04:19:06,249 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat
2025-12-29 04:19:06,266 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4934-2']
2025-12-29 04:19:06,266 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:06,298 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:06,329 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:06,329 - DEBUG - Validated that VM ctest-vn1_vm2-01876245 is in Vrouter an-jenkins-deploy-platform-ansible-os-4934-2 UVE
2025-12-29 04:19:06,329 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-29 04:19:06,335 - DEBUG - Expected tap interface of VM uuid 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59
2025-12-29 04:19:06,335 - DEBUG - Expected VN of VM uuid 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:06,336 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:06,373 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:06,409 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:06,409 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-02904210:a638b5e3-5895-4774-acd6-02bbed4ccc59 of vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:06,409 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 of vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:06,409 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.61
2025-12-29 04:19:06,409 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:19:06,422 - DEBUG - VM link and name as {'name': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat'}
2025-12-29 04:19:06,422 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.22
2025-12-29 04:19:06,422 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:19:06,493 - DEBUG - VM link and name as {'name': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat'}
2025-12-29 04:19:06,493 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.27
2025-12-29 04:19:06,493 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:19:06,505 - DEBUG - VM link and name as {'name': '1e7b4e3b-5bfb-499a-bea1-dca0702a471f', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f?flat'}
2025-12-29 04:19:06,505 - INFO - VM ctest-vn1_vm2-01876245 validations in Opserver passed
2025-12-29 04:19:06,505 - INFO - Checking the ping between the VM again
2025-12-29 04:19:06,505 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:19:06,506 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.1.4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.56, gateway password: c0ntrail123
2025-12-29 04:19:06,506 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4
2025-12-29 04:19:09,039 - DEBUG - PING 192.168.1.4 (192.168.1.4) 56(84) bytes of data.
64 bytes from 192.168.1.4: icmp_req=1 ttl=64 time=3.12 ms
64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=0.991 ms
64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.08 ms
--- 192.168.1.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 0.991/1.736/3.128/0.985 ms
2025-12-29 04:19:09,040 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-48754280 passed
2025-12-29 04:19:09,040 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:19:09,040 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.1.3, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.240, gateway password: c0ntrail123
2025-12-29 04:19:09,040 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3
2025-12-29 04:19:11,511 - DEBUG - PING 192.168.1.3 (192.168.1.3) 56(84) bytes of data.
64 bytes from 192.168.1.3: icmp_req=1 ttl=64 time=3.32 ms
64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.18 ms
64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=1.11 ms
--- 192.168.1.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.117/1.875/3.322/1.024 ms
2025-12-29 04:19:11,511 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-01876245 passed
2025-12-29 04:19:11,511 - INFO - Deleting VM ctest-vn1_vm2-01876245
2025-12-29 04:19:11,582 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:11,582 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:11,594 - DEBUG - VM ID 1e7b4e3b-5bfb-499a-bea1-dca0702a471f of VM ctest-vn1_vm2-01876245 is still found in API Server
2025-12-29 04:19:13,595 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:13,595 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:13,602 - DEBUG - Response Code: 404
2025-12-29 04:19:13,602 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:13,607 - DEBUG - Response Code: 404
2025-12-29 04:19:13,607 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/1e7b4e3b-5bfb-499a-bea1-dca0702a471f
2025-12-29 04:19:13,613 - DEBUG - Response Code: 404
2025-12-29 04:19:13,613 - INFO - VM ctest-vn1_vm2-01876245 is fully removed in API-Server
2025-12-29 04:19:13,773 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-29 04:19:13,956 - DEBUG - VM route 192.168.1.4 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 of compute 10.0.0.56
2025-12-29 04:19:13,962 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:13,962 - DEBUG - Validated that vrouter 10.0.0.240 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:13,962 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:13,962 - INFO - VM ctest-vn1_vm2-01876245 is removed in Compute, and routes are removed in all compute nodes
2025-12-29 04:19:14,207 - INFO - Routes for VM ctest-vn1_vm2-01876245 is removed in all control-nodes
2025-12-29 04:19:14,207 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:14,239 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:14,267 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:14,267 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:14,267 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:17,268 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:17,301 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:17,329 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:17,329 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:17,329 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:20,330 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:20,365 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:20,396 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:20,396 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:20,396 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:23,397 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:23,429 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:23,456 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:23,456 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:23,456 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:26,457 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:26,493 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:26,523 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:26,523 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:26,523 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:29,523 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:29,559 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:29,588 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:29,588 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:29,588 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:32,589 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:32,630 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:32,659 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:32,659 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:32,659 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:35,660 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:35,693 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:35,728 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:35,728 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:35,728 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:38,729 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:38,763 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:38,792 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:38,792 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:38,792 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:41,792 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:41,824 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:19:41,854 - DEBUG - VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is not present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:19:41,854 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:41,854 - DEBUG - interface for vm 1e7b4e3b-5bfb-499a-bea1-dca0702a471f deleted from vrouter uve ...
2025-12-29 04:19:41,854 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:41,854 - DEBUG - Validated that VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is removed in Vrouter UVE
2025-12-29 04:19:41,854 - DEBUG - Verifying through opserver in 10.0.0.61
2025-12-29 04:19:41,854 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat
2025-12-29 04:19:41,875 - DEBUG - 1e7b4e3b-5bfb-499a-bea1-dca0702a471f BM not in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 uve
2025-12-29 04:19:41,875 - DEBUG - Validated that VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is not present in the VN UVE
2025-12-29 04:19:41,875 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.61
2025-12-29 04:19:41,875 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:19:41,885 - INFO - 1e7b4e3b-5bfb-499a-bea1-dca0702a471f vm uve deleted from opserver
2025-12-29 04:19:41,885 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.22
2025-12-29 04:19:41,885 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:19:41,948 - INFO - 1e7b4e3b-5bfb-499a-bea1-dca0702a471f vm uve deleted from opserver
2025-12-29 04:19:41,948 - DEBUG - Verifying the 1e7b4e3b-5bfb-499a-bea1-dca0702a471f virtual network link through opserver 10.0.0.27
2025-12-29 04:19:41,948 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:19:41,960 - INFO - 1e7b4e3b-5bfb-499a-bea1-dca0702a471f vm uve deleted from opserver
2025-12-29 04:19:41,960 - INFO - Validated that VM 1e7b4e3b-5bfb-499a-bea1-dca0702a471f is removed from Opserver
2025-12-29 04:19:41,960 - INFO - Deleting VM ctest-vn1_vm1-48754280
2025-12-29 04:19:42,035 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:42,035 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:42,044 - DEBUG - VM ID e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 of VM ctest-vn1_vm1-48754280 is still found in API Server
2025-12-29 04:19:44,044 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:19:44,044 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:44,051 - DEBUG - Response Code: 404
2025-12-29 04:19:44,052 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:44,058 - DEBUG - Response Code: 404
2025-12-29 04:19:44,058 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e4686217-6c2c-4d7d-8e6c-a1837f73cfc9
2025-12-29 04:19:44,066 - DEBUG - Response Code: 404
2025-12-29 04:19:44,066 - INFO - VM ctest-vn1_vm1-48754280 is fully removed in API-Server
2025-12-29 04:19:44,234 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-29 04:19:44,284 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:44,296 - DEBUG - Validated that vrouter 10.0.0.240 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:44,296 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818
2025-12-29 04:19:44,296 - INFO - VM ctest-vn1_vm1-48754280 is removed in Compute, and routes are removed in all compute nodes
2025-12-29 04:19:44,535 - INFO - Routes for VM ctest-vn1_vm1-48754280 is removed in all control-nodes
2025-12-29 04:19:44,536 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:44,579 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:44,609 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:44,609 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:44,609 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:44,609 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:47,611 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:47,657 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:47,689 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:47,689 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:47,690 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:47,690 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:50,690 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:50,735 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:50,763 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:50,763 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:50,763 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:50,763 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:53,764 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:53,810 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:53,838 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:53,838 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:53,838 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:53,838 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:56,839 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:56,888 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:56,916 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:56,916 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:56,916 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:56,916 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:19:59,917 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:19:59,962 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:19:59,990 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:19:59,990 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:19:59,990 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:19:59,990 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:20:02,991 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:20:03,039 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:20:03,069 - DEBUG - VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:20:03,069 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:20:03,069 - DEBUG - interface for vm e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 deleted from vrouter uve ...
2025-12-29 04:20:03,069 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:20:03,069 - DEBUG - Validated that VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is removed in Vrouter UVE
2025-12-29 04:20:03,069 - DEBUG - Verifying through opserver in 10.0.0.61
2025-12-29 04:20:03,069 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818?flat
2025-12-29 04:20:03,087 - DEBUG - e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 BM not in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-19133818 uve
2025-12-29 04:20:03,087 - DEBUG - Validated that VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is not present in the VN UVE
2025-12-29 04:20:03,087 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.61
2025-12-29 04:20:03,087 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:20:03,098 - INFO - e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 vm uve deleted from opserver
2025-12-29 04:20:03,098 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.22
2025-12-29 04:20:03,099 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:20:03,111 - INFO - e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 vm uve deleted from opserver
2025-12-29 04:20:03,111 - DEBUG - Verifying the e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 virtual network link through opserver 10.0.0.27
2025-12-29 04:20:03,111 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:20:03,124 - INFO - e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 vm uve deleted from opserver
2025-12-29 04:20:03,124 - INFO - Validated that VM e4686217-6c2c-4d7d-8e6c-a1837f73cfc9 is removed from Opserver
2025-12-29 04:20:03,124 - INFO - Deleting VN ctest-vn1-19133818
2025-12-29 04:20:03,388 - DEBUG - Response for deleting network ()
2025-12-29 04:20:03,389 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6ec1067f-75b6-4959-a0bd-8d7f367379f8
2025-12-29 04:20:03,397 - DEBUG - Response Code: 404
2025-12-29 04:20:03,397 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:20:03,408 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:20:03,470 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:20:03,560 - INFO - Validated that VN ctest-vn1-19133818 is not found in API Server
2025-12-29 04:20:03,576 - DEBUG - VN ctest-vn1-19133818 is not present in Agent 10.0.0.56
2025-12-29 04:20:03,588 - DEBUG - VN ctest-vn1-19133818 is not present in Agent 10.0.0.240
2025-12-29 04:20:03,588 - INFO - Validated that VN ctest-vn1-19133818 is not in any agent
2025-12-29 04:20:03,623 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-19133818 info
2025-12-29 04:20:04,910 - DEBUG - Skipping xmpp flap check
2025-12-29 04:20:04,910 - INFO - END TEST : test_control_node_switchover : PASSED[0:03:42]
2025-12-29 04:20:04,910 - INFO - --------------------------------------------------------------------------------
2025-12-29 04:20:04,913 - INFO - ================================================================================
2025-12-29 04:20:04,913 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns
2025-12-29 04:20:04,913 - INFO - TEST DESCRIPTION : Test to validate that with policy having rule to check icmp fwding between VMs on different VNs , ping between VMs should pass
with process restarts
1. Pick 2 VN's from resource pool which has one VM each
2. Create policy with icmp allow rule between those VN's and bind it networks
3. Ping from one VM to another VM
4. Restart process 'vrouter' and 'control' on setup
5. Ping again between VM's after process restart
Pass criteria: Step 2,3,4 and 5 should pass
2025-12-29 04:20:06,193 - DEBUG - Skipping xmpp flap check
2025-12-29 04:20:06,193 - INFO - Initial checks done. Running the testcase now
2025-12-29 04:20:06,193 - INFO -
2025-12-29 04:20:06,200 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None]
2025-12-29 04:20:06,508 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None]
2025-12-29 04:20:07,040 - INFO - Created VN ctest-vn1-67602985, UUID :4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,356 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:20:07,362 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:20:07,459 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:20:07,557 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,574 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,584 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:20:07,594 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:20:07,604 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/ce54d531-b5b3-43b0-b02a-4a47f828c263
2025-12-29 04:20:07,612 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:20:07,612 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,623 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:20:07,641 - INFO - Verified VN network id 12 for VN 4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,641 - INFO - Verifications in API Server for VN ctest-vn1-67602985 passed
2025-12-29 04:20:07,642 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,653 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:20:07,661 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:20:07,669 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/ce54d531-b5b3-43b0-b02a-4a47f828c263
2025-12-29 04:20:07,681 - DEBUG - Control-node 10.0.0.61 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:07', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.491875'}
2025-12-29 04:20:07,686 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:20:07,693 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:07', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.502143'}
2025-12-29 04:20:07,699 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:20:07,708 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:07', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.521479'}
2025-12-29 04:20:07,719 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:20:07,719 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-67602985 passed
2025-12-29 04:20:07,719 - DEBUG - ====Verifying policy data for ctest-vn1-67602985 in API_Server ======
2025-12-29 04:20:07,719 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:20:07,729 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:20:07,745 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:20:07,854 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:20:07,864 - DEBUG - =>VN ctest-vn1-67602985 has no policy to be verified
2025-12-29 04:20:07,864 - DEBUG - Verifying the vn in opserver
2025-12-29 04:20:07,864 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.61
2025-12-29 04:20:07,864 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-networks
2025-12-29 04:20:07,875 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:20:07,875 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.22
2025-12-29 04:20:07,875 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-12-29 04:20:07,888 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:20:07,888 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.27
2025-12-29 04:20:07,888 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks
2025-12-29 04:20:07,901 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:20:07,901 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is found in opserver
2025-12-29 04:20:07,925 - DEBUG - Do not have enough data to verify VN in agent
2025-12-29 04:20:07,939 - DEBUG - VRF ids for VN ctest-vn1-67602985: {}
2025-12-29 04:20:08,596 - INFO - Created VN ctest-vn2-66052682, UUID :026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:08,915 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:20:08,924 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:20:08,935 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:20:09,031 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,045 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,058 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:20:09,067 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:20:09,074 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/8013cc12-b584-49b8-9851-97a7d263ccd7
2025-12-29 04:20:09,080 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-29 04:20:09,080 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,090 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:20:09,104 - INFO - Verified VN network id 13 for VN 026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,104 - INFO - Verifications in API Server for VN ctest-vn2-66052682 passed
2025-12-29 04:20:09,104 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,115 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:20:09,122 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:20:09,130 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/8013cc12-b584-49b8-9851-97a7d263ccd7
2025-12-29 04:20:09,141 - DEBUG - Control-node 10.0.0.61 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '175428415259364258', 'uuid-lslong': '10099827979635449632'}, 'enable': 'true', 'created': '2025-12-29T04:20:08', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.397281'}
2025-12-29 04:20:09,150 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-29 04:20:09,157 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '175428415259364258', 'uuid-lslong': '10099827979635449632'}, 'enable': 'true', 'created': '2025-12-29T04:20:08', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.417592'}
2025-12-29 04:20:09,162 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-29 04:20:09,168 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '175428415259364258', 'uuid-lslong': '10099827979635449632'}, 'enable': 'true', 'created': '2025-12-29T04:20:08', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.424394'}
2025-12-29 04:20:09,175 - DEBUG - Route Targets: ['target:64512:8000006']
2025-12-29 04:20:09,175 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-66052682 passed
2025-12-29 04:20:09,175 - DEBUG - ====Verifying policy data for ctest-vn2-66052682 in API_Server ======
2025-12-29 04:20:09,175 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:20:09,180 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:20:09,191 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:20:09,294 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/026f3f36-d70b-4ba2-8c29-cc094ab8df20
2025-12-29 04:20:09,307 - DEBUG - =>VN ctest-vn2-66052682 has no policy to be verified
2025-12-29 04:20:09,307 - DEBUG - Verifying the vn in opserver
2025-12-29 04:20:09,307 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 virtual network link through opserver 10.0.0.61
2025-12-29 04:20:09,307 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-networks
2025-12-29 04:20:09,318 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682?flat'}
2025-12-29 04:20:09,318 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 virtual network link through opserver 10.0.0.22
2025-12-29 04:20:09,319 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-12-29 04:20:09,330 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682?flat'}
2025-12-29 04:20:09,330 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 virtual network link through opserver 10.0.0.27
2025-12-29 04:20:09,330 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks
2025-12-29 04:20:09,342 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682?flat'}
2025-12-29 04:20:09,342 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is found in opserver
2025-12-29 04:20:09,366 - DEBUG - Do not have enough data to verify VN in agent
2025-12-29 04:20:09,376 - DEBUG - VRF ids for VN ctest-vn2-66052682: {}
2025-12-29 04:20:10,874 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-1)
2025-12-29 04:20:12,454 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-2)
2025-12-29 04:20:12,454 - INFO - Waiting for VM ctest-vn1_vm1-11722112 to be up..
2025-12-29 04:20:12,563 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-12-29 04:20:17,653 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:20:17,654 - INFO - VM name : ctest-vn1_vm1-11722112
2025-12-29 04:20:17,748 - DEBUG - VM ctest-vn1_vm1-11722112 ID is d3ae3527-7f3e-40fc-a9cc-ad813fd4cd07
2025-12-29 04:20:17,748 - DEBUG - VM ctest-vn1_vm1-11722112 launched on Node an-jenkins-deploy-platform-ansible-os-4934-1
2025-12-29 04:20:17,847 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/d3ae3527-7f3e-40fc-a9cc-ad813fd4cd07
2025-12-29 04:20:17,858 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/3f4f6080-1fb6-4860-845a-9964b463febf
2025-12-29 04:20:21,041 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms')
2025-12-29 04:20:21,041 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:21,055 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:25,133 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms')
2025-12-29 04:20:25,133 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:25,147 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:29,231 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2025-12-29 04:20:29,232 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:29,246 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:33,327 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:20:33,328 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:33,343 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:37,425 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:20:37,425 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:37,440 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:41,522 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms')
2025-12-29 04:20:41,522 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:41,536 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:45,617 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms')
2025-12-29 04:20:45,617 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:45,634 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:49,714 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms')
2025-12-29 04:20:49,714 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:49,727 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:53,807 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:20:53,807 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:53,821 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:20:57,905 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:20:57,905 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:20:57,918 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:21:02,003 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms')
2025-12-29 04:21:02,003 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:21:02,019 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:21:06,098 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms')
2025-12-29 04:21:06,098 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 failed!
2025-12-29 04:21:06,110 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:21:08,174 - 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=7.85 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.45 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.448/4.646/7.845/3.198 ms')
2025-12-29 04:21:08,175 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-11722112 passed
2025-12-29 04:21:08,240 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:08,240 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:08,311 - 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-29 04:21:08,395 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:13,395 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:13,396 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:13,462 - 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-29 04:21:13,542 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:18,543 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:18,543 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:18,642 - 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-29 04:21:18,742 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:23,743 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:23,744 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:23,811 - 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-29 04:21:23,968 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:28,969 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:28,969 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:29,035 - 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-29 04:21:29,145 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:34,146 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:34,146 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:34,215 - 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-29 04:21:34,297 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:39,297 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:39,298 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:39,367 - 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-29 04:21:39,448 - DEBUG - VM ctest-vn1_vm1-11722112 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:21:44,448 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:44,449 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-11722112, IP 192.168.1.252, Port 22
2025-12-29 04:21:44,616 - DEBUG - VM ctest-vn1_vm1-11722112 is ready for SSH connections
2025-12-29 04:21:44,616 - INFO - Waiting for VM ctest-vn2_vm1-66968380 to be up..
2025-12-29 04:21:44,700 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:21:44,700 - INFO - VM name : ctest-vn2_vm1-66968380
2025-12-29 04:21:44,789 - DEBUG - VM ctest-vn2_vm1-66968380 ID is e9bb913a-3015-4a55-bdfd-aae956152abe
2025-12-29 04:21:44,790 - DEBUG - VM ctest-vn2_vm1-66968380 launched on Node an-jenkins-deploy-platform-ansible-os-4934-2
2025-12-29 04:21:44,878 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/e9bb913a-3015-4a55-bdfd-aae956152abe
2025-12-29 04:21:44,980 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/e8e607fa-c057-4e0b-89f3-090e32966495
2025-12-29 04:21:46,181 - 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.50 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.422 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.422/2.458/4.495/2.036 ms')
2025-12-29 04:21:46,182 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2_vm1-66968380 passed
2025-12-29 04:21:46,249 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:46,249 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-66968380, IP 192.168.2.252, Port 22
2025-12-29 04:21:46,415 - DEBUG - VM ctest-vn2_vm1-66968380 is ready for SSH connections
2025-12-29 04:21:46,415 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:21:46,415 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.2.252, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.56, gateway password: c0ntrail123
2025-12-29 04:21:46,416 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.252
2025-12-29 04:22:12,911 - DEBUG - PING 192.168.2.252 (192.168.2.252) 56(84) bytes of data.
64 bytes from 192.168.2.252: icmp_req=1 ttl=63 time=6.41 ms
64 bytes from 192.168.2.252: icmp_req=2 ttl=63 time=1.25 ms
64 bytes from 192.168.2.252: icmp_req=3 ttl=63 time=1.22 ms
--- 192.168.2.252 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.221/2.962/6.415/2.442 ms
2025-12-29 04:22:12,911 - INFO - Ping to IP 192.168.2.252 from VM ctest-vn1_vm1-11722112 passed
2025-12-29 04:22:16,348 - INFO - 10.0.0.56
2025-12-29 04:22:16,352 - INFO - agent:initializing
2025-12-29 04:22:16,352 - DEBUG - defaultdict(, {'10.0.0.56': {'agent': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:16,352 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:21,438 - INFO - 10.0.0.56
2025-12-29 04:22:21,444 - INFO - agent:active
2025-12-29 04:22:21,445 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.56
2025-12-29 04:22:24,816 - INFO - 10.0.0.240
2025-12-29 04:22:24,820 - INFO - agent:initializing
2025-12-29 04:22:24,820 - DEBUG - defaultdict(, {'10.0.0.240': {'agent': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:24,820 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:29,908 - INFO - 10.0.0.240
2025-12-29 04:22:29,914 - INFO - agent:active
2025-12-29 04:22:29,914 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.240
2025-12-29 04:22:30,374 - INFO - 10.0.0.61
2025-12-29 04:22:30,377 - INFO - control:initializing
2025-12-29 04:22:30,377 - DEBUG - defaultdict(, {'10.0.0.61': {'control': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:30,377 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:35,492 - INFO - 10.0.0.61
2025-12-29 04:22:35,499 - INFO - control:active
2025-12-29 04:22:35,499 - INFO - Contrail services ['control'] are up on nodes 10.0.0.61
2025-12-29 04:22:35,875 - INFO - 10.0.0.22
2025-12-29 04:22:35,880 - INFO - control:initializing
2025-12-29 04:22:35,880 - DEBUG - defaultdict(, {'10.0.0.22': {'control': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:35,880 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:40,970 - INFO - 10.0.0.22
2025-12-29 04:22:40,977 - INFO - control:active
2025-12-29 04:22:40,977 - INFO - Contrail services ['control'] are up on nodes 10.0.0.22
2025-12-29 04:22:41,410 - INFO - 10.0.0.27
2025-12-29 04:22:41,414 - INFO - control:initializing
2025-12-29 04:22:41,414 - DEBUG - defaultdict(, {'10.0.0.27': {'control': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:41,415 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:46,502 - INFO - 10.0.0.27
2025-12-29 04:22:46,508 - INFO - control:active
2025-12-29 04:22:46,508 - INFO - Contrail services ['control'] are up on nodes 10.0.0.27
2025-12-29 04:22:47,214 - INFO - 10.0.0.61
2025-12-29 04:22:47,219 - INFO - api-server:initializing
2025-12-29 04:22:47,219 - DEBUG - defaultdict(, {'10.0.0.61': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:47,219 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:22:52,337 - INFO - 10.0.0.61
2025-12-29 04:22:52,342 - INFO - api-server:initializing
2025-12-29 04:22:52,342 - DEBUG - defaultdict(, {'10.0.0.61': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:22:52,342 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-12-29 04:22:57,459 - INFO - 10.0.0.61
2025-12-29 04:22:57,464 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-12-29 04:22:57,465 - DEBUG - defaultdict(, {'10.0.0.61': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-12-29 04:22:57,465 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-12-29 04:23:02,579 - INFO - 10.0.0.61
2025-12-29 04:23:02,583 - INFO - api-server:active
2025-12-29 04:23:02,583 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.61
2025-12-29 04:23:03,240 - INFO - 10.0.0.22
2025-12-29 04:23:03,244 - INFO - api-server:initializing
2025-12-29 04:23:03,244 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:23:03,244 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:23:08,344 - INFO - 10.0.0.22
2025-12-29 04:23:08,348 - INFO - api-server:initializing
2025-12-29 04:23:08,348 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:23:08,349 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-12-29 04:23:13,438 - INFO - 10.0.0.22
2025-12-29 04:23:13,444 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-12-29 04:23:13,444 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-12-29 04:23:13,444 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-12-29 04:23:18,545 - INFO - 10.0.0.22
2025-12-29 04:23:18,550 - INFO - api-server:active
2025-12-29 04:23:18,550 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.22
2025-12-29 04:23:19,217 - INFO - 10.0.0.27
2025-12-29 04:23:19,221 - INFO - api-server:initializing
2025-12-29 04:23:19,221 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:23:19,221 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-12-29 04:23:24,335 - INFO - 10.0.0.27
2025-12-29 04:23:24,340 - INFO - api-server:initializing
2025-12-29 04:23:24,340 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': None}}})
2025-12-29 04:23:24,340 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-12-29 04:23:29,430 - INFO - 10.0.0.27
2025-12-29 04:23:29,435 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-12-29 04:23:29,436 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-12-29 04:23:29,436 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-12-29 04:23:34,536 - INFO - 10.0.0.27
2025-12-29 04:23:34,540 - INFO - api-server:active
2025-12-29 04:23:34,541 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.27
2025-12-29 04:23:34,659 - INFO - 10.0.0.61
2025-12-29 04:23:34,659 - INFO - config
2025-12-29 04:23:34,664 - INFO - config-nodemgr:active
2025-12-29 04:23:34,667 - INFO - api-server:active
2025-12-29 04:23:34,671 - INFO - schema:active
2025-12-29 04:23:34,675 - INFO - svc-monitor:active
2025-12-29 04:23:34,678 - INFO - device-manager:active
2025-12-29 04:23:34,678 - INFO - config-database
2025-12-29 04:23:34,678 - INFO - config-cassandra:active
2025-12-29 04:23:34,678 - INFO - config-zookeeper:active
2025-12-29 04:23:34,678 - INFO - config-rabbitmq:active
2025-12-29 04:23:34,678 - INFO - control
2025-12-29 04:23:34,683 - INFO - control-nodemgr:active
2025-12-29 04:23:34,687 - INFO - control:active
2025-12-29 04:23:34,687 - INFO - named:active
2025-12-29 04:23:34,692 - INFO - dns:active
2025-12-29 04:23:34,693 - INFO - analytics
2025-12-29 04:23:34,698 - INFO - analytics-nodemgr:active
2025-12-29 04:23:34,701 - INFO - analytics-api:active
2025-12-29 04:23:34,705 - INFO - collector:active
2025-12-29 04:23:34,705 - INFO - analytics-database
2025-12-29 04:23:34,706 - INFO - analytics-cassandra:active
2025-12-29 04:23:34,710 - INFO - analyticsdb-nodemgr:active
2025-12-29 04:23:34,714 - INFO - query-engine:active
2025-12-29 04:23:34,715 - INFO - webui
2025-12-29 04:23:34,715 - INFO - webui:active
2025-12-29 04:23:34,715 - INFO - webui-middleware:active
2025-12-29 04:23:34,715 - INFO - redis:active
2025-12-29 04:23:34,715 - INFO - analytics_snmp
2025-12-29 04:23:34,719 - INFO - snmp-collector:active
2025-12-29 04:23:34,719 - INFO - snmp-topology:active
2025-12-29 04:23:34,719 - INFO - analytics_alarm
2025-12-29 04:23:34,719 - INFO - alarmgen:active
2025-12-29 04:23:34,806 - INFO - 10.0.0.22
2025-12-29 04:23:34,806 - INFO - config
2025-12-29 04:23:34,812 - INFO - config-nodemgr:active
2025-12-29 04:23:34,816 - INFO - api-server:active
2025-12-29 04:23:34,820 - INFO - schema:backup
2025-12-29 04:23:34,823 - INFO - svc-monitor:backup
2025-12-29 04:23:34,826 - INFO - device-manager:backup
2025-12-29 04:23:34,826 - INFO - config-database
2025-12-29 04:23:34,826 - INFO - config-cassandra:active
2025-12-29 04:23:34,826 - INFO - config-zookeeper:active
2025-12-29 04:23:34,826 - INFO - config-rabbitmq:active
2025-12-29 04:23:34,826 - INFO - control
2025-12-29 04:23:34,830 - INFO - control-nodemgr:active
2025-12-29 04:23:34,835 - INFO - control:active
2025-12-29 04:23:34,835 - INFO - named:active
2025-12-29 04:23:34,839 - INFO - dns:active
2025-12-29 04:23:34,839 - INFO - analytics
2025-12-29 04:23:34,844 - INFO - analytics-nodemgr:active
2025-12-29 04:23:34,847 - INFO - analytics-api:active
2025-12-29 04:23:34,852 - INFO - collector:active
2025-12-29 04:23:34,852 - INFO - analytics-database
2025-12-29 04:23:34,852 - INFO - analytics-cassandra:active
2025-12-29 04:23:34,857 - INFO - analyticsdb-nodemgr:active
2025-12-29 04:23:34,861 - INFO - query-engine:active
2025-12-29 04:23:34,861 - INFO - webui
2025-12-29 04:23:34,861 - INFO - webui:active
2025-12-29 04:23:34,861 - INFO - webui-middleware:active
2025-12-29 04:23:34,861 - INFO - redis:active
2025-12-29 04:23:34,861 - INFO - analytics_snmp
2025-12-29 04:23:34,865 - INFO - snmp-collector:active
2025-12-29 04:23:34,865 - INFO - snmp-topology:active
2025-12-29 04:23:34,865 - INFO - analytics_alarm
2025-12-29 04:23:34,865 - INFO - alarmgen:active
2025-12-29 04:23:34,964 - INFO - 10.0.0.27
2025-12-29 04:23:34,964 - INFO - config
2025-12-29 04:23:34,971 - INFO - config-nodemgr:active
2025-12-29 04:23:34,976 - INFO - api-server:active
2025-12-29 04:23:34,981 - INFO - schema:backup
2025-12-29 04:23:34,985 - INFO - svc-monitor:backup
2025-12-29 04:23:34,990 - INFO - device-manager:backup
2025-12-29 04:23:34,990 - INFO - config-database
2025-12-29 04:23:34,990 - INFO - config-cassandra:active
2025-12-29 04:23:34,990 - INFO - config-zookeeper:active
2025-12-29 04:23:34,990 - INFO - config-rabbitmq:active
2025-12-29 04:23:34,990 - INFO - control
2025-12-29 04:23:34,997 - INFO - control-nodemgr:active
2025-12-29 04:23:35,004 - INFO - control:active
2025-12-29 04:23:35,004 - INFO - named:active
2025-12-29 04:23:35,010 - INFO - dns:active
2025-12-29 04:23:35,010 - INFO - analytics
2025-12-29 04:23:35,016 - INFO - analytics-nodemgr:active
2025-12-29 04:23:35,021 - INFO - analytics-api:active
2025-12-29 04:23:35,027 - INFO - collector:active
2025-12-29 04:23:35,027 - INFO - analytics-database
2025-12-29 04:23:35,027 - INFO - analytics-cassandra:active
2025-12-29 04:23:35,032 - INFO - analyticsdb-nodemgr:active
2025-12-29 04:23:35,039 - INFO - query-engine:active
2025-12-29 04:23:35,039 - INFO - webui
2025-12-29 04:23:35,039 - INFO - webui:active
2025-12-29 04:23:35,039 - INFO - webui-middleware:active
2025-12-29 04:23:35,039 - INFO - redis:active
2025-12-29 04:23:35,039 - INFO - analytics_snmp
2025-12-29 04:23:35,044 - INFO - snmp-collector:active
2025-12-29 04:23:35,044 - INFO - snmp-topology:active
2025-12-29 04:23:35,044 - INFO - analytics_alarm
2025-12-29 04:23:35,044 - INFO - alarmgen:active
2025-12-29 04:23:35,143 - INFO - 10.0.0.56
2025-12-29 04:23:35,143 - INFO - vrouter
2025-12-29 04:23:35,149 - INFO - vrouter-nodemgr:active
2025-12-29 04:23:35,154 - INFO - agent:active
2025-12-29 04:23:35,241 - INFO - 10.0.0.240
2025-12-29 04:23:35,241 - INFO - vrouter
2025-12-29 04:23:35,248 - INFO - vrouter-nodemgr:active
2025-12-29 04:23:35,253 - INFO - agent:active
2025-12-29 04:23:35,253 - INFO - All the contrail services are up on all nodes
2025-12-29 04:23:35,253 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:23:35,661 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.18:5269'] servers UP
2025-12-29 04:23:35,661 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1 connected to xmpp 10.20.0.18
2025-12-29 04:23:35,661 - WARNING - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.145:5269'] servers NOT UP
2025-12-29 04:23:35,661 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.252:5269'] servers UP
2025-12-29 04:23:35,662 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1 connected to xmpp 10.20.0.252
2025-12-29 04:23:35,662 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.18:53'] servers UP
2025-12-29 04:23:35,662 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1 connected to dns 10.20.0.18
2025-12-29 04:23:35,662 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.145:53'] servers UP
2025-12-29 04:23:35,662 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1 connected to dns 10.20.0.145
2025-12-29 04:23:35,663 - WARNING - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.20.0.252:53'] servers NOT UP
2025-12-29 04:23:35,663 - WARNING - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.0.0.61:8086'] servers NOT UP
2025-12-29 04:23:35,663 - WARNING - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.0.0.22:8086'] servers NOT UP
2025-12-29 04:23:35,663 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1:contrail-vrouter-agent module connection to ['10.0.0.27:8086'] servers UP
2025-12-29 04:23:35,663 - INFO - an-jenkins-deploy-platform-ansible-os-4934-1 connected to collector 10.0.0.27
2025-12-29 04:23:35,664 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:23:36,041 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-1:contrail-control module connection to 10.0.0.61:9041 servers UP
2025-12-29 04:23:36,041 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-1:contrail-control module connection to 10.0.0.61:5673 servers UP
2025-12-29 04:23:36,041 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-1:contrail-control module connection to ['10.0.0.61:8086'] servers UP
2025-12-29 04:23:36,041 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:23:36,443 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-2:contrail-control module connection to 10.0.0.61:9041 servers UP
2025-12-29 04:23:36,444 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-2:contrail-control module connection to 10.0.0.61:5673 servers UP
2025-12-29 04:23:36,444 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-2:contrail-control module connection to ['10.0.0.61:8086'] servers UP
2025-12-29 04:23:36,444 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4934-3?flat
2025-12-29 04:23:36,464 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-3:contrail-control module connection to 10.0.0.61:9041 servers UP
2025-12-29 04:23:36,464 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-3:contrail-control module connection to 10.0.0.61:5673 servers UP
2025-12-29 04:23:36,464 - INFO - cn-jenkins-deploy-platform-ansible-os-4934-3:contrail-control module connection to ['10.0.0.61:8086'] servers UP
2025-12-29 04:23:36,464 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4934-1.?flat
2025-12-29 04:23:36,491 - DEBUG - contrail-api is running
2025-12-29 04:23:36,492 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4934-2.?flat
2025-12-29 04:23:36,513 - DEBUG - contrail-api is running
2025-12-29 04:23:36,513 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4934-3.?flat
2025-12-29 04:23:36,533 - DEBUG - contrail-api is running
2025-12-29 04:23:36,848 - INFO - Created VN ctest-vn3-92534882, UUID :0f021f99-07f7-41ae-99c2-556cb905932d
2025-12-29 04:23:37,235 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:23:37,265 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:23:37,280 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:23:37,385 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,397 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,406 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:23:37,429 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:23:37,438 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/ce54d531-b5b3-43b0-b02a-4a47f828c263
2025-12-29 04:23:37,446 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:23:37,446 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,456 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:23:37,475 - INFO - Verified VN network id 12 for VN 4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,475 - INFO - Verifications in API Server for VN ctest-vn1-67602985 passed
2025-12-29 04:23:37,475 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,485 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:23:37,493 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:23:37,500 - DEBUG - Requesting: http://10.0.0.61:8082/route-target/ce54d531-b5b3-43b0-b02a-4a47f828c263
2025-12-29 04:23:37,512 - DEBUG - Control-node 10.0.0.61 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '0', 'advertised': '0', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:06.757866'}
2025-12-29 04:23:37,521 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:23:37,526 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:01.356358'}
2025-12-29 04:23:37,532 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:23:37,538 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-02904210', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5690591049628536267', 'uuid-lslong': '10706578672830643256'}, 'enable': 'true', 'created': '2025-12-29T04:20:06', 'last-modified': '2025-12-29T04:20:08', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:55.690319'}
2025-12-29 04:23:37,545 - DEBUG - Route Targets: ['target:64512:8000004']
2025-12-29 04:23:37,545 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-67602985 passed
2025-12-29 04:23:37,545 - DEBUG - ====Verifying policy data for ctest-vn1-67602985 in API_Server ======
2025-12-29 04:23:37,545 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:23:37,551 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:23:37,562 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:23:37,653 - DEBUG - Requesting: http://10.0.0.61:8082/virtual-network/4ef90a68-db20-4dcb-9495-6893b9d7fc38
2025-12-29 04:23:37,667 - DEBUG - ==>Verifying data for policy with id: b12fe42f-4358-44a2-ae8e-a2f7490a3459, fqn: ['default-domain', 'ctest-TestBasicVMVN0-02904210', 'policy1']
2025-12-29 04:23:37,668 - INFO - VN ctest-vn1-67602985 Policy verification: verify_vn_policy_in_api_server, status: True
2025-12-29 04:23:37,668 - DEBUG - Verifying the vn in opserver
2025-12-29 04:23:37,668 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.61
2025-12-29 04:23:37,668 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-networks
2025-12-29 04:23:37,681 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:23:37,681 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.22
2025-12-29 04:23:37,681 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-12-29 04:23:37,743 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:23:37,743 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 virtual network link through opserver 10.0.0.27
2025-12-29 04:23:37,743 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks
2025-12-29 04:23:37,809 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat'}
2025-12-29 04:23:37,809 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is found in opserver
2025-12-29 04:23:37,821 - DEBUG - VRF ids for VN ctest-vn1-67602985: {'10.0.0.56': '2'}
2025-12-29 04:23:39,132 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-1)
2025-12-29 04:23:39,172 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-12-29 04:23:44,248 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:23:44,248 - INFO - VM name : ctest-vn1_vm2-64300054
2025-12-29 04:23:44,326 - DEBUG - VM ctest-vn1_vm2-64300054 ID is 7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:23:44,403 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:23:44,403 - DEBUG - VM ctest-vn1_vm2-64300054 launched on Node an-jenkins-deploy-platform-ansible-os-4934-1
2025-12-29 04:23:44,483 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:23:44,518 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:23:44,525 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/229fe53b-273a-46eb-aacb-3d3fc3533532
2025-12-29 04:23:44,535 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:23:44,544 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/229fe53b-273a-46eb-aacb-3d3fc3533532
2025-12-29 04:23:44,554 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/929e513f-9823-43cf-a2fa-509c07530d85
2025-12-29 04:23:44,566 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:23:44,566 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:23:44,574 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/229fe53b-273a-46eb-aacb-3d3fc3533532
2025-12-29 04:23:44,585 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/929e513f-9823-43cf-a2fa-509c07530d85
2025-12-29 04:23:44,593 - INFO - VM ctest-vn1_vm2-64300054 verfication in all API Servers passed
2025-12-29 04:23:44,617 - DEBUG - VM ctest-vn1_vm2-64300054 Tap interface: {'index': '4', 'name': 'tap229fe53b-27', 'uuid': '229fe53b-273a-46eb-aacb-3d3fc3533532', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985:ctest-vn1-67602985', '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': '30', 'l2_label': '34', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'vm_uuid': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'vm_name': 'ctest-vn1_vm2-64300054', 'ip_addr': '192.168.1.251', 'mac_addr': '02:22:9f:e5:3b:27', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '163', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '20', '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-29 04:23:44,618 - DEBUG - Agent 10.0.0.56 vrf name: default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985:ctest-vn1-67602985
2025-12-29 04:23:44,627 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985:ctest-vn1-67602985', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'table_label': '-1', 'vxlan_id': '12', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.241:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-29 04:23:44,711 - DEBUG - VM ctest-vn1_vm2-64300054 : Tap interface tap229fe53b-27 is set to Active
2025-12-29 04:23:44,711 - DEBUG - Tap interface tap229fe53b-27 detail : {'index': '4', 'name': 'tap229fe53b-27', 'uuid': '229fe53b-273a-46eb-aacb-3d3fc3533532', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985:ctest-vn1-67602985', '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': '30', 'l2_label': '34', 'vxlan_id': '12', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'vm_uuid': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'vm_name': 'ctest-vn1_vm2-64300054', 'ip_addr': '192.168.1.251', 'mac_addr': '02:22:9f:e5:3b:27', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '163', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '20', '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-29 04:23:44,822 - DEBUG - Starting Layer 2 verification in Agent
2025-12-29 04:23:44,836 - DEBUG - Layer 2 path is seen for VM MAC 02:22:9f:e5:3b:27 in agent 10.0.0.56
2025-12-29 04:23:44,836 - DEBUG - Active layer 2 route in agent is present for VMI tap229fe53b-27
2025-12-29 04:23:44,836 - DEBUG - L2 label(34) matches bw route table and interface table
2025-12-29 04:23:44,847 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is found in Agent of node 10.0.0.56
2025-12-29 04:23:44,991 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is consistent in agent 10.0.0.56
2025-12-29 04:23:44,991 - DEBUG - Route for VM IP ['192.168.1.251'] is consistent in agent 10.0.0.56
2025-12-29 04:23:44,991 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 verification for VM ctest-vn1_vm2-64300054 in Agent 10.0.0.56 passed
2025-12-29 04:23:45,105 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56
2025-12-29 04:23:45,129 - DEBUG - Route for VM MAC 02:22:9f:e5:3b:27 is consistent in agent 10.0.0.56
2025-12-29 04:23:48,335 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-12-29 04:23:48,335 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:23:48,348 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:23:52,432 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms')
2025-12-29 04:23:52,432 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:23:52,447 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:23:56,530 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms')
2025-12-29 04:23:56,530 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:23:56,546 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:00,627 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:24:00,628 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:00,643 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:04,719 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms')
2025-12-29 04:24:04,719 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:04,733 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:08,817 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms')
2025-12-29 04:24:08,817 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:08,830 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:12,910 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:24:12,911 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:12,925 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:17,010 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-12-29 04:24:17,011 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:17,026 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:21,104 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms')
2025-12-29 04:24:21,104 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:21,119 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:25,202 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-12-29 04:24:25,202 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:25,218 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:29,297 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms')
2025-12-29 04:24:29,297 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:29,310 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:33,388 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-12-29 04:24:33,388 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 failed!
2025-12-29 04:24:33,402 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 is 192.168.1.254 and allocation pool is NOT set
2025-12-29 04:24:35,471 - 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=9.42 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.822 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.822/5.122/9.423/4.300 ms')
2025-12-29 04:24:35,471 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 passed
2025-12-29 04:24:35,472 - INFO - VM ctest-vn1_vm2-64300054 verifications in Compute nodes passed
2025-12-29 04:24:35,686 - DEBUG - Validated VM route 192.168.1.251 in vrouter of 10.0.0.56
2025-12-29 04:24:35,692 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-29 04:24:35,692 - INFO - Validated routes of VM ctest-vn1_vm2-64300054 in all vrouters
2025-12-29 04:24:36,115 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node
2025-12-29 04:24:36,241 - DEBUG - Layer2 route found for VM MAC 02:22:9f:e5:3b:27 in Control-node 10.0.0.22
2025-12-29 04:24:36,241 - DEBUG - L2 Label for VM ctest-vn1_vm2-64300054 same between Control-node 10.0.0.22 and Agent, Expected: 34, Seen: 34
2025-12-29 04:24:36,241 - DEBUG - Starting all layer2 verification in 10.0.0.61 Control Node
2025-12-29 04:24:36,369 - DEBUG - Layer2 route found for VM MAC 02:22:9f:e5:3b:27 in Control-node 10.0.0.61
2025-12-29 04:24:36,369 - DEBUG - L2 Label for VM ctest-vn1_vm2-64300054 same between Control-node 10.0.0.61 and Agent, Expected: 34, Seen: 34
2025-12-29 04:24:36,369 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node
2025-12-29 04:24:36,494 - DEBUG - Layer2 route found for VM MAC 02:22:9f:e5:3b:27 in Control-node 10.0.0.27
2025-12-29 04:24:36,494 - DEBUG - L2 Label for VM ctest-vn1_vm2-64300054 same between Control-node 10.0.0.27 and Agent, Expected: 34, Seen: 34
2025-12-29 04:24:36,494 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-64300054 passed
2025-12-29 04:24:36,495 - DEBUG - Verifying the vm in opserver
2025-12-29 04:24:36,495 - DEBUG - Verifying in collector 10.0.0.27 ...
2025-12-29 04:24:36,495 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat
2025-12-29 04:24:36,576 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532?flat
2025-12-29 04:24:36,595 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532?flat
2025-12-29 04:24:36,614 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat
2025-12-29 04:24:36,630 - DEBUG - Verifying vm in vn uve
2025-12-29 04:24:36,630 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532?flat
2025-12-29 04:24:36,649 - DEBUG - VM uve shows interface as {'tx_vlan': 65535, 'uuid': '229fe53b-273a-46eb-aacb-3d3fc3533532', 'mac_address': '02:22:9f:e5:3b:27', 'port_mirror_enabled': False, 'ip4_active': True, 'vn_uuid': '4ef90a68-db20-4dcb-9495-6893b9d7fc38', 'fixed_ip4_list': ['192.168.1.251'], 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985', 'vm_uuid': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'ip_address': '192.168.1.251', 'rx_vlan': 65535, 'ip6_address': '::', 'vhostuser_mode': 0, 'ip6_active': False, 'is_health_check_active': True, 'admin_state': True, 'active': True, 'l2_active': True, 'vm_name': 'ctest-vn1_vm2-64300054', '__T': 1766982227083334, 'gateway': '192.168.1.254', 'label': 30}
2025-12-29 04:24:36,649 - DEBUG - VM uve shows ip address as ['192.168.1.251', '::']
2025-12-29 04:24:36,649 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:24:36,649 - INFO - Verifying through opserver in 10.0.0.61
2025-12-29 04:24:36,649 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat
2025-12-29 04:24:36,673 - DEBUG - expected vm list 7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:24:36,673 - DEBUG - Extracted vm list ['7cb51584-87fa-46b9-94b8-00d028ff2ff2']
2025-12-29 04:24:36,673 - INFO - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is present in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:24:36,673 - DEBUG - Verifying vm in vrouter uve
2025-12-29 04:24:36,673 - DEBUG - Getting info from collector 10.0.0.27..
2025-12-29 04:24:36,673 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat
2025-12-29 04:24:36,743 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4934-1']
2025-12-29 04:24:36,743 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:24:36,808 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:24:36,836 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:24:36,836 - DEBUG - Validated that VM ctest-vn1_vm2-64300054 is in Vrouter an-jenkins-deploy-platform-ansible-os-4934-1 UVE
2025-12-29 04:24:36,836 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-29 04:24:36,845 - DEBUG - Expected tap interface of VM uuid 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532
2025-12-29 04:24:36,845 - DEBUG - Expected VN of VM uuid 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:24:36,845 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:24:36,909 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:24:36,944 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:24:36,944 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-02904210:229fe53b-273a-46eb-aacb-3d3fc3533532 of vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:24:36,944 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 of vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:24:36,944 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.61
2025-12-29 04:24:36,944 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:24:36,957 - DEBUG - VM link and name as {'name': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat'}
2025-12-29 04:24:36,957 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.22
2025-12-29 04:24:36,957 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:24:37,016 - DEBUG - VM link and name as {'name': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat'}
2025-12-29 04:24:37,016 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.27
2025-12-29 04:24:37,016 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:24:37,030 - DEBUG - VM link and name as {'name': '7cb51584-87fa-46b9-94b8-00d028ff2ff2', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2?flat'}
2025-12-29 04:24:37,030 - INFO - VM ctest-vn1_vm2-64300054 validations in Opserver passed
2025-12-29 04:24:38,398 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4934-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4934-2)
2025-12-29 04:24:38,459 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-12-29 04:24:43,552 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:24:43,552 - INFO - VM name : ctest-vn2_vm2-44668324
2025-12-29 04:24:43,633 - DEBUG - VM ctest-vn2_vm2-44668324 ID is a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:24:43,714 - DEBUG - VM is in ACTIVE state now
2025-12-29 04:24:43,714 - DEBUG - VM ctest-vn2_vm2-44668324 launched on Node an-jenkins-deploy-platform-ansible-os-4934-2
2025-12-29 04:24:43,797 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:24:43,807 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:24:43,814 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/25ce6428-22c7-4305-9312-4cae3d596629
2025-12-29 04:24:43,823 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:24:43,831 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/25ce6428-22c7-4305-9312-4cae3d596629
2025-12-29 04:24:43,842 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/b011f63f-48eb-4fa6-a9a8-3fa25b8eed50
2025-12-29 04:24:43,851 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:24:43,851 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:24:43,859 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/25ce6428-22c7-4305-9312-4cae3d596629
2025-12-29 04:24:43,868 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/b011f63f-48eb-4fa6-a9a8-3fa25b8eed50
2025-12-29 04:24:43,877 - INFO - VM ctest-vn2_vm2-44668324 verfication in all API Servers passed
2025-12-29 04:24:43,899 - DEBUG - VM ctest-vn2_vm2-44668324 Tap interface: {'index': '4', 'name': 'tap25ce6428-22', 'uuid': '25ce6428-22c7-4305-9312-4cae3d596629', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682:ctest-vn2-66052682', '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': '30', 'l2_label': '34', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'vm_uuid': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'vm_name': 'ctest-vn2_vm2-44668324', 'ip_addr': '192.168.2.251', 'mac_addr': '02:25:ce:64:28:22', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '133', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '26', '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-29 04:24:43,899 - DEBUG - Agent 10.0.0.240 vrf name: default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682:ctest-vn2-66052682
2025-12-29 04:24:43,908 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682:ctest-vn2-66052682', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.19:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-12-29 04:24:43,990 - DEBUG - VM ctest-vn2_vm2-44668324 : Tap interface tap25ce6428-22 is set to Active
2025-12-29 04:24:43,991 - DEBUG - Tap interface tap25ce6428-22 detail : {'index': '4', 'name': 'tap25ce6428-22', 'uuid': '25ce6428-22c7-4305-9312-4cae3d596629', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682:ctest-vn2-66052682', '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': '30', 'l2_label': '34', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'vm_uuid': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'vm_name': 'ctest-vn2_vm2-44668324', 'ip_addr': '192.168.2.251', 'mac_addr': '02:25:ce:64:28:22', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '133', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629', 'sg_uuid_list': ['c77f0d78-83e2-426f-ab02-be191cc7874f'], 'static_route_list': None, 'vm_project_uuid': '1c4478b4-d1bb-4f38-81a5-5554efeaadc3', 'admin_state': 'Enabled', 'flow_key_idx': '26', '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-29 04:24:44,104 - DEBUG - Starting Layer 2 verification in Agent
2025-12-29 04:24:44,117 - DEBUG - Layer 2 path is seen for VM MAC 02:25:ce:64:28:22 in agent 10.0.0.240
2025-12-29 04:24:44,117 - DEBUG - Active layer 2 route in agent is present for VMI tap25ce6428-22
2025-12-29 04:24:44,117 - DEBUG - L2 label(34) matches bw route table and interface table
2025-12-29 04:24:44,131 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is found in Agent of node 10.0.0.240
2025-12-29 04:24:44,267 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is consistent in agent 10.0.0.240
2025-12-29 04:24:44,267 - DEBUG - Route for VM IP ['192.168.2.251'] is consistent in agent 10.0.0.240
2025-12-29 04:24:44,267 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 verification for VM ctest-vn2_vm2-44668324 in Agent 10.0.0.240 passed
2025-12-29 04:24:44,381 - DEBUG - Starting all layer 2 verification in agent 10.0.0.240
2025-12-29 04:24:44,396 - DEBUG - Route for VM MAC 02:25:ce:64:28:22 is consistent in agent 10.0.0.240
2025-12-29 04:24:47,581 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2025-12-29 04:24:47,581 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:24:47,596 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:24:51,676 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1017ms')
2025-12-29 04:24:51,676 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:24:51,689 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:24:55,777 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms')
2025-12-29 04:24:55,777 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:24:55,790 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:24:59,872 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1016ms')
2025-12-29 04:24:59,872 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:24:59,886 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:25:03,961 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms')
2025-12-29 04:25:03,961 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:25:03,974 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:25:08,064 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms')
2025-12-29 04:25:08,064 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:25:08,079 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:25:12,163 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-12-29 04:25:12,163 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:25:12,177 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:25:16,250 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-12-29 04:25:16,250 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 failed!
2025-12-29 04:25:16,264 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 is 192.168.2.254 and allocation pool is NOT set
2025-12-29 04:25:18,335 - 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=13.0 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.88 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 = 2.878/7.948/13.019/5.070 ms')
2025-12-29 04:25:18,335 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 passed
2025-12-29 04:25:18,335 - INFO - VM ctest-vn2_vm2-44668324 verifications in Compute nodes passed
2025-12-29 04:25:18,547 - DEBUG - Validated VM route 192.168.2.251 in vrouter of 10.0.0.240
2025-12-29 04:25:18,553 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-12-29 04:25:18,553 - INFO - Validated routes of VM ctest-vn2_vm2-44668324 in all vrouters
2025-12-29 04:25:18,993 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node
2025-12-29 04:25:19,117 - DEBUG - Layer2 route found for VM MAC 02:25:ce:64:28:22 in Control-node 10.0.0.22
2025-12-29 04:25:19,117 - DEBUG - L2 Label for VM ctest-vn2_vm2-44668324 same between Control-node 10.0.0.22 and Agent, Expected: 34, Seen: 34
2025-12-29 04:25:19,117 - DEBUG - Starting all layer2 verification in 10.0.0.61 Control Node
2025-12-29 04:25:19,243 - DEBUG - Layer2 route found for VM MAC 02:25:ce:64:28:22 in Control-node 10.0.0.61
2025-12-29 04:25:19,244 - DEBUG - L2 Label for VM ctest-vn2_vm2-44668324 same between Control-node 10.0.0.61 and Agent, Expected: 34, Seen: 34
2025-12-29 04:25:19,244 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node
2025-12-29 04:25:19,379 - DEBUG - Layer2 route found for VM MAC 02:25:ce:64:28:22 in Control-node 10.0.0.27
2025-12-29 04:25:19,380 - DEBUG - L2 Label for VM ctest-vn2_vm2-44668324 same between Control-node 10.0.0.27 and Agent, Expected: 34, Seen: 34
2025-12-29 04:25:19,380 - INFO - Verification in Control-nodes for VM ctest-vn2_vm2-44668324 passed
2025-12-29 04:25:19,380 - DEBUG - Verifying the vm in opserver
2025-12-29 04:25:19,380 - DEBUG - Verifying in collector 10.0.0.27 ...
2025-12-29 04:25:19,380 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat
2025-12-29 04:25:19,397 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629?flat
2025-12-29 04:25:19,417 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629?flat
2025-12-29 04:25:19,439 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat
2025-12-29 04:25:19,456 - DEBUG - Verifying vm in vn uve
2025-12-29 04:25:19,456 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629?flat
2025-12-29 04:25:19,477 - DEBUG - VM uve shows interface as {'label': 30, 'uuid': '25ce6428-22c7-4305-9312-4cae3d596629', 'vm_name': 'ctest-vn2_vm2-44668324', 'ip_address': '192.168.2.251', 'active': True, 'is_health_check_active': True, 'rx_vlan': 65535, 'admin_state': True, 'vn_uuid': '026f3f36-d70b-4ba2-8c29-cc094ab8df20', 'l2_active': True, 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682', 'port_mirror_enabled': False, 'ip6_active': False, 'vhostuser_mode': 0, 'ip6_address': '::', 'fixed_ip4_list': ['192.168.2.251'], 'ip4_active': True, 'mac_address': '02:25:ce:64:28:22', 'tx_vlan': 65535, 'vm_uuid': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'gateway': '192.168.2.254', '__T': 1766982295372464}
2025-12-29 04:25:19,477 - DEBUG - VM uve shows ip address as ['192.168.2.251', '::']
2025-12-29 04:25:19,477 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:25:19,477 - INFO - Verifying through opserver in 10.0.0.61
2025-12-29 04:25:19,477 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682?flat
2025-12-29 04:25:19,504 - DEBUG - expected vm list a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:25:19,504 - DEBUG - Extracted vm list ['a229b5d3-a8c4-4489-bd56-e5d971c6cc62']
2025-12-29 04:25:19,504 - INFO - VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is present in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:25:19,504 - DEBUG - Verifying vm in vrouter uve
2025-12-29 04:25:19,504 - DEBUG - Getting info from collector 10.0.0.27..
2025-12-29 04:25:19,504 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat
2025-12-29 04:25:19,521 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4934-2']
2025-12-29 04:25:19,521 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:25:19,570 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:25:19,605 - DEBUG - VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:25:19,605 - DEBUG - Validated that VM ctest-vn2_vm2-44668324 is in Vrouter an-jenkins-deploy-platform-ansible-os-4934-2 UVE
2025-12-29 04:25:19,605 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-12-29 04:25:19,613 - DEBUG - Expected tap interface of VM uuid a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629
2025-12-29 04:25:19,613 - DEBUG - Expected VN of VM uuid a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:25:19,613 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:25:19,664 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:25:19,694 - DEBUG - VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:25:19,694 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-02904210:25ce6428-22c7-4305-9312-4cae3d596629 of vm a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:25:19,694 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 of vm a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:25:19,695 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.61
2025-12-29 04:25:19,695 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:25:19,711 - DEBUG - VM link and name as {'name': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'href': 'http://10.0.0.61:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat'}
2025-12-29 04:25:19,711 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.22
2025-12-29 04:25:19,712 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:25:19,783 - DEBUG - VM link and name as {'name': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat'}
2025-12-29 04:25:19,783 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.27
2025-12-29 04:25:19,783 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:25:19,797 - DEBUG - VM link and name as {'name': 'a229b5d3-a8c4-4489-bd56-e5d971c6cc62', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62?flat'}
2025-12-29 04:25:19,797 - INFO - VM ctest-vn2_vm2-44668324 validations in Opserver passed
2025-12-29 04:25:19,797 - INFO - Waiting for VM ctest-vn1_vm2-64300054 to be up..
2025-12-29 04:25:19,797 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:19,797 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:25:19,808 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/229fe53b-273a-46eb-aacb-3d3fc3533532
2025-12-29 04:25:20,984 - 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.16 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.789 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.789/2.476/4.163/1.687 ms')
2025-12-29 04:25:20,984 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-64300054 passed
2025-12-29 04:25:21,053 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:21,053 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-64300054, IP 192.168.1.251, Port 22
2025-12-29 04:25:21,231 - DEBUG - VM ctest-vn1_vm2-64300054 is ready for SSH connections
2025-12-29 04:25:21,231 - INFO - Waiting for VM ctest-vn2_vm2-44668324 to be up..
2025-12-29 04:25:21,231 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:21,231 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:25:21,240 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/25ce6428-22c7-4305-9312-4cae3d596629
2025-12-29 04:25:22,405 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=2.20 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=5.37 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 = 2.204/3.785/5.366/1.581 ms')
2025-12-29 04:25:22,405 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-44668324 passed
2025-12-29 04:25:22,476 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:22,477 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-44668324, IP 192.168.2.251, Port 22
2025-12-29 04:25:22,533 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-29 04:25:22,617 - DEBUG - VM ctest-vn2_vm2-44668324 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:25:27,618 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:27,618 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-44668324, IP 192.168.2.251, Port 22
2025-12-29 04:25:27,673 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-29 04:25:27,755 - DEBUG - VM ctest-vn2_vm2-44668324 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:25:32,756 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:32,756 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-44668324, IP 192.168.2.251, Port 22
2025-12-29 04:25:32,824 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2025-12-29 04:25:32,922 - DEBUG - VM ctest-vn2_vm2-44668324 is NOT ready for SSH connections, VM status: ACTIVE
2025-12-29 04:25:37,923 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:37,923 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-44668324, IP 192.168.2.251, Port 22
2025-12-29 04:25:38,081 - DEBUG - VM ctest-vn2_vm2-44668324 is ready for SSH connections
2025-12-29 04:25:38,081 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-12-29 04:25:38,081 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.2.251, host_string: ubuntu@169.254.0.4, password: ubuntugateway: ubuntu@10.0.0.56, gateway password: c0ntrail123
2025-12-29 04:25:38,081 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.251
2025-12-29 04:26:24,063 - DEBUG - PING 192.168.2.251 (192.168.2.251) 56(84) bytes of data.
64 bytes from 192.168.2.251: icmp_req=1 ttl=63 time=8.00 ms
64 bytes from 192.168.2.251: icmp_req=2 ttl=63 time=1.10 ms
64 bytes from 192.168.2.251: icmp_req=3 ttl=63 time=1.27 ms
--- 192.168.2.251 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.102/3.461/8.005/3.214 ms
2025-12-29 04:26:24,063 - INFO - Ping to IP 192.168.2.251 from VM ctest-vn1_vm2-64300054 passed
2025-12-29 04:26:24,063 - INFO - Deleting VM ctest-vn2_vm2-44668324
2025-12-29 04:26:24,249 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:26:24,249 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:26:24,257 - DEBUG - VM ID a229b5d3-a8c4-4489-bd56-e5d971c6cc62 of VM ctest-vn2_vm2-44668324 is still found in API Server
2025-12-29 04:26:26,258 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:26:26,259 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:26:26,267 - DEBUG - Response Code: 404
2025-12-29 04:26:26,267 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:26:26,273 - DEBUG - Response Code: 404
2025-12-29 04:26:26,274 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/a229b5d3-a8c4-4489-bd56-e5d971c6cc62
2025-12-29 04:26:26,281 - DEBUG - Response Code: 404
2025-12-29 04:26:26,281 - INFO - VM ctest-vn2_vm2-44668324 is fully removed in API-Server
2025-12-29 04:26:26,451 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-29 04:26:26,484 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:26:26,605 - DEBUG - VM route 192.168.2.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 of compute 10.0.0.240
2025-12-29 04:26:26,610 - DEBUG - Validated that vrouter 10.0.0.240 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:26:26,610 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682
2025-12-29 04:26:26,611 - INFO - VM ctest-vn2_vm2-44668324 is removed in Compute, and routes are removed in all compute nodes
2025-12-29 04:26:26,823 - INFO - Routes for VM ctest-vn2_vm2-44668324 is removed in all control-nodes
2025-12-29 04:26:26,824 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-2:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:26,874 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-2?flat
2025-12-29 04:26:26,903 - DEBUG - VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4934-2 uve
2025-12-29 04:26:26,903 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:26,903 - DEBUG - interface for vm a229b5d3-a8c4-4489-bd56-e5d971c6cc62 deleted from vrouter uve ...
2025-12-29 04:26:26,904 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:26,904 - DEBUG - Validated that VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is removed in Vrouter UVE
2025-12-29 04:26:26,904 - DEBUG - Verifying through opserver in 10.0.0.61
2025-12-29 04:26:26,904 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682?flat
2025-12-29 04:26:26,926 - DEBUG - a229b5d3-a8c4-4489-bd56-e5d971c6cc62 BM not in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn2-66052682 uve
2025-12-29 04:26:26,926 - DEBUG - Validated that VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is not present in the VN UVE
2025-12-29 04:26:26,926 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.61
2025-12-29 04:26:26,926 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:26:26,937 - INFO - a229b5d3-a8c4-4489-bd56-e5d971c6cc62 vm uve deleted from opserver
2025-12-29 04:26:26,937 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.22
2025-12-29 04:26:26,937 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:26:26,948 - INFO - a229b5d3-a8c4-4489-bd56-e5d971c6cc62 vm uve deleted from opserver
2025-12-29 04:26:26,948 - DEBUG - Verifying the a229b5d3-a8c4-4489-bd56-e5d971c6cc62 virtual network link through opserver 10.0.0.27
2025-12-29 04:26:26,948 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:26:26,960 - INFO - a229b5d3-a8c4-4489-bd56-e5d971c6cc62 vm uve deleted from opserver
2025-12-29 04:26:26,960 - INFO - Validated that VM a229b5d3-a8c4-4489-bd56-e5d971c6cc62 is removed from Opserver
2025-12-29 04:26:26,960 - INFO - Deleting VM ctest-vn1_vm2-64300054
2025-12-29 04:26:27,023 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:26:27,023 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:26:27,031 - DEBUG - VM ID 7cb51584-87fa-46b9-94b8-00d028ff2ff2 of VM ctest-vn1_vm2-64300054 is still found in API Server
2025-12-29 04:26:29,032 - DEBUG - Verifying in api server 10.0.0.27
2025-12-29 04:26:29,032 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:26:29,039 - DEBUG - Response Code: 404
2025-12-29 04:26:29,039 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:26:29,046 - DEBUG - Response Code: 404
2025-12-29 04:26:29,046 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/7cb51584-87fa-46b9-94b8-00d028ff2ff2
2025-12-29 04:26:29,052 - DEBUG - Response Code: 404
2025-12-29 04:26:29,052 - INFO - VM ctest-vn1_vm2-64300054 is fully removed in API-Server
2025-12-29 04:26:29,207 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-12-29 04:26:29,376 - DEBUG - VM route 192.168.1.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 of compute 10.0.0.56
2025-12-29 04:26:29,382 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:26:29,382 - DEBUG - Validated that vrouter 10.0.0.240 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:26:29,382 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:26:29,382 - INFO - VM ctest-vn1_vm2-64300054 is removed in Compute, and routes are removed in all compute nodes
2025-12-29 04:26:29,616 - INFO - Routes for VM ctest-vn1_vm2-64300054 is removed in all control-nodes
2025-12-29 04:26:29,616 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:29,656 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:29,683 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:29,683 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:29,683 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:29,683 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:32,684 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:32,730 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:32,761 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:32,761 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:32,761 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:32,761 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:35,762 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:35,810 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:35,838 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:35,838 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:35,838 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:35,838 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:38,839 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:38,882 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:38,913 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:38,913 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:38,913 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:38,913 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:41,913 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:41,962 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:41,994 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:41,994 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:41,994 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:41,994 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:44,995 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:45,039 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:45,073 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:45,073 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:45,073 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:45,073 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:48,073 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4934-1:Compute:contrail-vrouter-agent:0?flat
2025-12-29 04:26:48,120 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4934-1?flat
2025-12-29 04:26:48,225 - DEBUG - VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4934-1 uve
2025-12-29 04:26:48,225 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-12-29 04:26:48,225 - DEBUG - interface for vm 7cb51584-87fa-46b9-94b8-00d028ff2ff2 deleted from vrouter uve ...
2025-12-29 04:26:48,225 - DEBUG - Deleted interface not in error interface list ...
2025-12-29 04:26:48,226 - DEBUG - Validated that VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is removed in Vrouter UVE
2025-12-29 04:26:48,226 - DEBUG - Verifying through opserver in 10.0.0.61
2025-12-29 04:26:48,226 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985?flat
2025-12-29 04:26:48,250 - DEBUG - 7cb51584-87fa-46b9-94b8-00d028ff2ff2 BM not in default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985 uve
2025-12-29 04:26:48,250 - DEBUG - Validated that VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is not present in the VN UVE
2025-12-29 04:26:48,250 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.61
2025-12-29 04:26:48,250 - DEBUG - Requesting: http://10.0.0.61:8081/analytics/uves/virtual-machines
2025-12-29 04:26:48,268 - INFO - 7cb51584-87fa-46b9-94b8-00d028ff2ff2 vm uve deleted from opserver
2025-12-29 04:26:48,269 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.22
2025-12-29 04:26:48,269 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines
2025-12-29 04:26:48,282 - INFO - 7cb51584-87fa-46b9-94b8-00d028ff2ff2 vm uve deleted from opserver
2025-12-29 04:26:48,282 - DEBUG - Verifying the 7cb51584-87fa-46b9-94b8-00d028ff2ff2 virtual network link through opserver 10.0.0.27
2025-12-29 04:26:48,282 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines
2025-12-29 04:26:48,297 - INFO - 7cb51584-87fa-46b9-94b8-00d028ff2ff2 vm uve deleted from opserver
2025-12-29 04:26:48,297 - INFO - Validated that VM 7cb51584-87fa-46b9-94b8-00d028ff2ff2 is removed from Opserver
2025-12-29 04:26:48,297 - INFO - Deleting VN ctest-vn3-92534882
2025-12-29 04:26:48,420 - INFO - Deleting VM ctest-vn2_vm1-66968380
2025-12-29 04:26:48,496 - INFO - Deleting VM ctest-vn1_vm1-11722112
2025-12-29 04:26:48,749 - INFO - Deleting VN ctest-vn2-66052682
2025-12-29 04:26:48,804 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.27:8082/virtual-machine-interface/e8e607fa-c057-4e0b-89f3-090e32966495'] while deleting VN ctest-vn2-66052682..Will retry
2025-12-29 04:26:50,909 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/42416979-2ee0-4d2a-a3f2-6192ed16c19b
2025-12-29 04:26:50,920 - DEBUG - Response Code: 404
2025-12-29 04:26:50,920 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:26:50,927 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:26:50,942 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:26:51,046 - INFO - Validated that VN ctest-vn2-66052682 is not found in API Server
2025-12-29 04:26:51,059 - DEBUG - VN ctest-vn2-66052682 is not present in Agent 10.0.0.56
2025-12-29 04:26:51,069 - DEBUG - VN ctest-vn2-66052682 is not present in Agent 10.0.0.240
2025-12-29 04:26:51,069 - INFO - Validated that VN ctest-vn2-66052682 is not in any agent
2025-12-29 04:26:51,096 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-66052682 info
2025-12-29 04:26:51,230 - INFO - Deleting VN ctest-vn1-67602985
2025-12-29 04:26:51,355 - DEBUG - Requesting: http://10.0.0.61:8082/routing-instance/6106fd04-1801-4089-88cd-e8a219c07e39
2025-12-29 04:26:51,363 - DEBUG - Response Code: 404
2025-12-29 04:26:51,363 - DEBUG - Requesting: http://10.0.0.61:8082/domains
2025-12-29 04:26:51,368 - DEBUG - Requesting: http://10.0.0.61:8082/domain/ea4b09a7-31d2-48cf-9e60-035b93d3d81c
2025-12-29 04:26:51,388 - DEBUG - Requesting: http://10.0.0.61:8082/project/1c4478b4-d1bb-4f38-81a5-5554efeaadc3
2025-12-29 04:26:51,477 - INFO - Validated that VN ctest-vn1-67602985 is not found in API Server
2025-12-29 04:26:51,488 - DEBUG - VN ctest-vn1-67602985 is not present in Agent 10.0.0.56
2025-12-29 04:26:51,501 - DEBUG - VN ctest-vn1-67602985 is not present in Agent 10.0.0.240
2025-12-29 04:26:51,501 - INFO - Validated that VN ctest-vn1-67602985 is not in any agent
2025-12-29 04:26:51,507 - DEBUG - VRF 2 is not seen in agent 10.0.0.56
2025-12-29 04:26:51,514 - DEBUG - Vrouter 10.0.0.56 does not have vrf 2 for VN ctest-vn1-67602985
2025-12-29 04:26:51,514 - INFO - Validated that all vrouters do not have the route table for VN default-domain:ctest-TestBasicVMVN0-02904210:ctest-vn1-67602985
2025-12-29 04:26:51,533 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-67602985 info
2025-12-29 04:26:51,569 - INFO - Deleted policy policy2
2025-12-29 04:26:51,626 - INFO - Deleted policy policy1
2025-12-29 04:26:52,885 - DEBUG - Skipping xmpp flap check
2025-12-29 04:26:52,885 - INFO - END TEST : test_process_restart_in_policy_between_vns : PASSED[0:06:48]
2025-12-29 04:26:52,885 - INFO - --------------------------------------------------------------------------------
2025-12-29 04:26:52,887 - INFO - ================================================================================
2025-12-29 04:26:52,888 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling
2025-12-29 04:26:52,888 - INFO - TEST DESCRIPTION : Test the underlay brocast traffic handling by vrouter. (Bug-1545229).
1. Send broadcast traffic from one compute node.
2. Other compute in same subnet should receive that traffic.
3. Receiving compute should treat this traffic as underlay.
4. Compute should not replicate the packet and send the copy back.
Pass criteria: Step 3-4 should pass
Maintainer : chhandak@juniper.net
2025-12-29 04:26:54,142 - DEBUG - Skipping xmpp flap check
2025-12-29 04:26:54,142 - INFO - Initial checks done. Running the testcase now
2025-12-29 04:26:54,142 - INFO -
2025-12-29 04:26:54,522 - INFO - Agent interface name: ens6
2025-12-29 04:26:54,603 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U host 10.20.0.255 -w /tmp/ens6_ctest-random-66937338.pcap
2025-12-29 04:26:59,962 - INFO - Pinging broacast address 10.20.0.255 from compute 10.20.0.241
2025-12-29 04:27:14,231 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2025-12-29 04:27:16,372 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-66937338.pcap | grep -c length
2025-12-29 04:27:16,387 - DEBUG - STDOUT: 10
2025-12-29 04:27:16,387 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-66937338.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-12-29 04:27:16,387 - INFO - 10 packets are found in tcpdump output as expected
2025-12-29 04:27:16,387 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2025-12-29 04:27:18,431 - INFO - Packet count matched: Compute 10.0.0.240 has receive only 10 packet from source IP 10.20.0.255. No duplicate packet seen
2025-12-29 04:27:19,686 - DEBUG - Skipping xmpp flap check
2025-12-29 04:27:19,686 - INFO - END TEST : test_underlay_broadcast_traffic_handling : PASSED[0:00:27]
2025-12-29 04:27:19,686 - INFO - --------------------------------------------------------------------------------
2025-12-29 04:27:20,421 - INFO - Deleted project: ctest-TestBasicVMVN0-02904210, ID : 1c4478b4-d1bb-4f38-81a5-5554efeaadc3