2026-01-08 04:08:35,907 - INFO - Domain Default found not creating 2026-01-08 04:08:36,120 - INFO - Project ctest-TestBasicVMVN0-28338633 not found, creating it 2026-01-08 04:08:36,626 - INFO - Created Project:ctest-TestBasicVMVN0-28338633, ID : 37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:08:38,181 - INFO - ================================================================================ 2026-01-08 04:08:38,181 - INFO - STARTING TEST : test_control_node_switchover 2026-01-08 04:08:38,182 - 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 2026-01-08 04:08:39,442 - DEBUG - Skipping xmpp flap check 2026-01-08 04:08:39,442 - INFO - Initial checks done. Running the testcase now 2026-01-08 04:08:39,442 - INFO - 2026-01-08 04:08:40,163 - DEBUG - Response for create_network : {'network': {'id': '18f94d0b-be10-40a9-b6d8-7627d7319de6', 'name': 'ctest-vn1-74620012', 'tenant_id': '37b535a1897e41debc03b246e39c9243', 'project_id': '37b535a1897e41debc03b246e39c9243', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-28338633', 'ctest-vn1-74620012'], 'port_security_enabled': True, 'description': ''}} 2026-01-08 04:08:40,495 - DEBUG - Response for create_subnet : {'subnet': {'id': '3854f85f-7c3a-4f6f-99f8-2a448c5972c1', 'name': '', 'tenant_id': '37b535a1897e41debc03b246e39c9243', 'network_id': '18f94d0b-be10-40a9-b6d8-7627d7319de6', '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': '37b535a1897e41debc03b246e39c9243'}} 2026-01-08 04:08:40,517 - INFO - Created VN ctest-vn1-74620012 2026-01-08 04:08:40,534 - DEBUG - VN ctest-vn1-74620012 UUID is 18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:40,615 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:08:40,908 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:08:40,939 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:08:40,954 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:08:41,046 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,057 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,067 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:08:41,074 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:08:41,081 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/0ca958ef-09cd-4dee-b6c9-99a35c7070bc 2026-01-08 04:08:41,088 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:08:41,088 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,096 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:08:41,109 - INFO - Verified VN network id 13 for VN 18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,110 - INFO - Verifications in API Server for VN ctest-vn1-74620012 passed 2026-01-08 04:08:41,110 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,121 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:08:41,128 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:08:41,134 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/0ca958ef-09cd-4dee-b6c9-99a35c7070bc 2026-01-08 04:08:41,151 - DEBUG - Control-node 10.0.0.242 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1799554238939938985', 'uuid-lslong': '13175410623358541286'}, 'enable': 'true', 'created': '2026-01-08T04:08:40', 'last-modified': '2026-01-08T04:08:40', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.709009'} 2026-01-08 04:08:41,157 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:08:41,163 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1799554238939938985', 'uuid-lslong': '13175410623358541286'}, 'enable': 'true', 'created': '2026-01-08T04:08:40', 'last-modified': '2026-01-08T04:08:40', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.712262'} 2026-01-08 04:08:41,169 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:08:41,175 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1799554238939938985', 'uuid-lslong': '13175410623358541286'}, 'enable': 'true', 'created': '2026-01-08T04:08:40', 'last-modified': '2026-01-08T04:08:40', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.733810'} 2026-01-08 04:08:41,181 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:08:41,181 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-74620012 passed 2026-01-08 04:08:41,181 - DEBUG - ====Verifying policy data for ctest-vn1-74620012 in API_Server ====== 2026-01-08 04:08:41,181 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:08:41,187 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:08:41,200 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:08:41,299 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/18f94d0b-be10-40a9-b6d8-7627d7319de6 2026-01-08 04:08:41,315 - DEBUG - =>VN ctest-vn1-74620012 has no policy to be verified 2026-01-08 04:08:41,315 - DEBUG - Verifying the vn in opserver 2026-01-08 04:08:41,315 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 virtual network link through opserver 10.0.0.242 2026-01-08 04:08:41,315 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-networks 2026-01-08 04:08:41,639 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-networks 2026-01-08 04:08:41,717 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat'} 2026-01-08 04:08:41,717 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 virtual network link through opserver 10.0.0.50 2026-01-08 04:08:41,717 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2026-01-08 04:08:42,036 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2026-01-08 04:08:42,109 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat'} 2026-01-08 04:08:42,109 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 virtual network link through opserver 10.0.0.27 2026-01-08 04:08:42,110 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks 2026-01-08 04:08:42,416 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks 2026-01-08 04:08:42,508 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat'} 2026-01-08 04:08:42,508 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is found in opserver 2026-01-08 04:08:42,535 - DEBUG - Do not have enough data to verify VN in agent 2026-01-08 04:08:42,547 - DEBUG - VRF ids for VN ctest-vn1-74620012: {} 2026-01-08 04:08:42,620 - DEBUG - Services list from nova: [, , , ] 2026-01-08 04:08:43,722 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-2) 2026-01-08 04:08:45,071 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-1) 2026-01-08 04:08:45,072 - INFO - Waiting for VM ctest-vn1_vm1-92923363 to be up.. 2026-01-08 04:08:45,154 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-08 04:08:50,244 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:08:50,244 - INFO - VM name : ctest-vn1_vm1-92923363 2026-01-08 04:08:50,324 - DEBUG - VM ctest-vn1_vm1-92923363 ID is 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:08:50,350 - DEBUG - VM ctest-vn1_vm1-92923363 launched on Node an-jenkins-deploy-platform-ansible-os-4976-2 2026-01-08 04:08:50,433 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:08:50,737 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:08:50,778 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/21b1b327-c496-4908-a012-1d8e171a764d 2026-01-08 04:08:53,961 - 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') 2026-01-08 04:08:53,961 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:08:53,977 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:08:58,052 - 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') 2026-01-08 04:08:58,052 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:08:58,066 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:02,157 - 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 1021ms') 2026-01-08 04:09:02,157 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:02,172 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:06,252 - 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') 2026-01-08 04:09:06,252 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:06,276 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:10,375 - 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 1033ms') 2026-01-08 04:09:10,376 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:10,389 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:14,469 - 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') 2026-01-08 04:09:14,469 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:14,484 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:18,570 - 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') 2026-01-08 04:09:18,570 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:18,589 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:22,664 - 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') 2026-01-08 04:09:22,664 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 failed! 2026-01-08 04:09:22,680 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is 192.168.1.1 and allocation pool is NOT set 2026-01-08 04:09:24,747 - 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=13.3 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.13 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 3.131/8.213/13.296/5.082 ms') 2026-01-08 04:09:24,747 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-92923363 passed 2026-01-08 04:09:24,821 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:24,822 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-92923363, IP 192.168.1.3, Port 22 2026-01-08 04:09:24,888 - 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': ''} 2026-01-08 04:09:25,011 - DEBUG - VM ctest-vn1_vm1-92923363 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:09:30,012 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:30,012 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-92923363, IP 192.168.1.3, Port 22 2026-01-08 04:09:30,070 - 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': ''} 2026-01-08 04:09:30,180 - DEBUG - VM ctest-vn1_vm1-92923363 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:09:35,181 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:35,181 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-92923363, IP 192.168.1.3, Port 22 2026-01-08 04:09:35,237 - 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': ''} 2026-01-08 04:09:35,325 - DEBUG - VM ctest-vn1_vm1-92923363 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:09:40,325 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:40,325 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-92923363, IP 192.168.1.3, Port 22 2026-01-08 04:09:40,381 - 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': ''} 2026-01-08 04:09:40,473 - DEBUG - VM ctest-vn1_vm1-92923363 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:09:45,474 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:45,474 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-92923363, IP 192.168.1.3, Port 22 2026-01-08 04:09:45,650 - DEBUG - VM ctest-vn1_vm1-92923363 is ready for SSH connections 2026-01-08 04:09:45,650 - INFO - Waiting for VM ctest-vn1_vm2-09771033 to be up.. 2026-01-08 04:09:45,751 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:09:45,751 - INFO - VM name : ctest-vn1_vm2-09771033 2026-01-08 04:09:45,839 - DEBUG - VM ctest-vn1_vm2-09771033 ID is 91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:09:45,839 - DEBUG - VM ctest-vn1_vm2-09771033 launched on Node an-jenkins-deploy-platform-ansible-os-4976-1 2026-01-08 04:09:45,923 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:09:45,935 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/bc68d0dd-4197-464d-83e0-ed8f02ca49ea 2026-01-08 04:09:47,111 - 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.49 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=3.58 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 = 3.584/5.538/7.492/1.954 ms') 2026-01-08 04:09:47,111 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm2-09771033 passed 2026-01-08 04:09:47,183 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:47,184 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-09771033, IP 192.168.1.4, Port 22 2026-01-08 04:09:47,252 - 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': ''} 2026-01-08 04:09:47,334 - DEBUG - VM ctest-vn1_vm2-09771033 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:09:52,334 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:52,334 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-09771033, IP 192.168.1.4, Port 22 2026-01-08 04:09:52,498 - DEBUG - VM ctest-vn1_vm2-09771033 is ready for SSH connections 2026-01-08 04:09:52,498 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:09:52,498 - 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 2026-01-08 04:09:52,499 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4 2026-01-08 04:10:09,615 - 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=11.2 ms 64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=4.04 ms 64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.16 ms --- 192.168.1.4 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.161/5.489/11.266/4.250 ms 2026-01-08 04:10:09,615 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-92923363 passed 2026-01-08 04:10:09,615 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:10:09,615 - 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.57, gateway password: c0ntrail123 2026-01-08 04:10:09,615 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3 2026-01-08 04:10:58,684 - 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.80 ms 64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.17 ms 64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=1.16 ms --- 192.168.1.3 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.168/3.381/7.804/3.127 ms 2026-01-08 04:10:58,685 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-09771033 passed 2026-01-08 04:10:58,691 - INFO - Active control node from the Agent 10.0.0.56 is 10.0.0.50 2026-01-08 04:10:58,691 - INFO - Stoping the Control service in 10.0.0.50 2026-01-08 04:10:59,101 - INFO - 10.0.0.50 2026-01-08 04:10:59,101 - INFO - control:inactive 2026-01-08 04:10:59,101 - INFO - Contrail services control are down on nodes 10.0.0.50 2026-01-08 04:11:04,109 - INFO - Active control node from the Agent 10.0.0.56 is 10.0.0.242 2026-01-08 04:11:04,109 - INFO - Starting the Control service in 10.0.0.50 2026-01-08 04:11:04,435 - INFO - 10.0.0.50 2026-01-08 04:11:04,439 - INFO - control:initializing 2026-01-08 04:11:04,439 - DEBUG - defaultdict(, {'10.0.0.50': {'control': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:11:04,439 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:11:09,542 - INFO - 10.0.0.50 2026-01-08 04:11:09,548 - INFO - control:active 2026-01-08 04:11:09,549 - INFO - Contrail services ['control'] are up on nodes 10.0.0.50 2026-01-08 04:11:14,645 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:11:14,645 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:11:14,645 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:14,654 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/21b1b327-c496-4908-a012-1d8e171a764d 2026-01-08 04:11:14,663 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:14,670 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/21b1b327-c496-4908-a012-1d8e171a764d 2026-01-08 04:11:14,679 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/76edd342-b361-4c6e-9f74-fbeb6c0c2ae2 2026-01-08 04:11:14,689 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:14,689 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:14,696 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/21b1b327-c496-4908-a012-1d8e171a764d 2026-01-08 04:11:14,705 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/76edd342-b361-4c6e-9f74-fbeb6c0c2ae2 2026-01-08 04:11:14,712 - INFO - VM ctest-vn1_vm1-92923363 verfication in all API Servers passed 2026-01-08 04:11:14,729 - DEBUG - VM ctest-vn1_vm1-92923363 Tap interface: {'index': '3', 'name': 'tap21b1b327-c4', 'uuid': '21b1b327-c496-4908-a012-1d8e171a764d', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'vm_uuid': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'vm_name': 'ctest-vn1_vm1-92923363', 'ip_addr': '192.168.1.3', 'mac_addr': '02:21:b1:b3:27:c4', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '165', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '27', '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': []} 2026-01-08 04:11:14,729 - DEBUG - Agent 10.0.0.56 vrf name: default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012 2026-01-08 04:11:14,734 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.192:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2026-01-08 04:11:14,809 - DEBUG - VM ctest-vn1_vm1-92923363 : Tap interface tap21b1b327-c4 is set to Active 2026-01-08 04:11:14,809 - DEBUG - Tap interface tap21b1b327-c4 detail : {'index': '3', 'name': 'tap21b1b327-c4', 'uuid': '21b1b327-c496-4908-a012-1d8e171a764d', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'vm_uuid': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'vm_name': 'ctest-vn1_vm1-92923363', 'ip_addr': '192.168.1.3', 'mac_addr': '02:21:b1:b3:27:c4', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '165', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '27', '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': []} 2026-01-08 04:11:14,923 - DEBUG - Starting Layer 2 verification in Agent 2026-01-08 04:11:14,934 - DEBUG - Layer 2 path is seen for VM MAC 02:21:b1:b3:27:c4 in agent 10.0.0.56 2026-01-08 04:11:14,935 - DEBUG - Active layer 2 route in agent is present for VMI tap21b1b327-c4 2026-01-08 04:11:14,935 - DEBUG - L2 label(29) matches bw route table and interface table 2026-01-08 04:11:14,940 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is found in Agent of node 10.0.0.57 2026-01-08 04:11:15,061 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is consistent in agent 10.0.0.57 2026-01-08 04:11:15,061 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.57 2026-01-08 04:11:15,061 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 verification for VM ctest-vn1_vm1-92923363 in Agent 10.0.0.57 passed 2026-01-08 04:11:15,177 - DEBUG - Starting all layer 2 verification in agent 10.0.0.57 2026-01-08 04:11:15,189 - DEBUG - Route for VM MAC 02:21:b1:b3:27:c4 is consistent in agent 10.0.0.57 2026-01-08 04:11:15,195 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is found in Agent of node 10.0.0.56 2026-01-08 04:11:15,330 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is consistent in agent 10.0.0.56 2026-01-08 04:11:15,330 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.56 2026-01-08 04:11:15,330 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 verification for VM ctest-vn1_vm1-92923363 in Agent 10.0.0.56 passed 2026-01-08 04:11:15,444 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56 2026-01-08 04:11:15,455 - DEBUG - Route for VM MAC 02:21:b1:b3:27:c4 is consistent in agent 10.0.0.56 2026-01-08 04:11:15,455 - INFO - VM ctest-vn1_vm1-92923363 verifications in Compute nodes passed 2026-01-08 04:11:15,692 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.57 2026-01-08 04:11:15,697 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.192, 25; Got 10.20.0.192,25 2026-01-08 04:11:15,697 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.57 2026-01-08 04:11:15,800 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.56 2026-01-08 04:11:15,803 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2026-01-08 04:11:15,804 - INFO - Validated routes of VM ctest-vn1_vm1-92923363 in all vrouters 2026-01-08 04:11:16,307 - DEBUG - Starting all layer2 verification in 10.0.0.242 Control Node 2026-01-08 04:11:16,439 - DEBUG - Layer2 route found for VM MAC 02:21:b1:b3:27:c4 in Control-node 10.0.0.242 2026-01-08 04:11:16,439 - DEBUG - L2 Label for VM ctest-vn1_vm1-92923363 same between Control-node 10.0.0.242 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:16,440 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2026-01-08 04:11:16,569 - DEBUG - Layer2 route found for VM MAC 02:21:b1:b3:27:c4 in Control-node 10.0.0.50 2026-01-08 04:11:16,569 - DEBUG - L2 Label for VM ctest-vn1_vm1-92923363 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:16,569 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node 2026-01-08 04:11:16,705 - DEBUG - Layer2 route found for VM MAC 02:21:b1:b3:27:c4 in Control-node 10.0.0.27 2026-01-08 04:11:16,705 - DEBUG - L2 Label for VM ctest-vn1_vm1-92923363 same between Control-node 10.0.0.27 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:16,705 - INFO - Verification in Control-nodes for VM ctest-vn1_vm1-92923363 passed 2026-01-08 04:11:16,706 - DEBUG - Verifying the vm in opserver 2026-01-08 04:11:16,706 - DEBUG - Verifying in collector 10.0.0.27 ... 2026-01-08 04:11:16,706 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat 2026-01-08 04:11:16,723 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d?flat 2026-01-08 04:11:16,743 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d?flat 2026-01-08 04:11:16,811 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat 2026-01-08 04:11:16,877 - DEBUG - Verifying vm in vn uve 2026-01-08 04:11:16,877 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d?flat 2026-01-08 04:11:16,957 - DEBUG - VM uve shows interface as {'virtual_network': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'ip_address': '192.168.1.3', 'vhostuser_mode': 0, 'vn_uuid': '18f94d0b-be10-40a9-b6d8-7627d7319de6', 'vm_name': 'ctest-vn1_vm1-92923363', 'mac_address': '02:21:b1:b3:27:c4', 'rx_vlan': 65535, 'gateway': '192.168.1.1', 'uuid': '21b1b327-c496-4908-a012-1d8e171a764d', 'tx_vlan': 65535, 'label': 25, 'admin_state': True, 'active': True, 'ip4_active': True, 'is_health_check_active': True, 'fixed_ip4_list': ['192.168.1.3'], 'ip6_active': False, 'port_mirror_enabled': False, 'l2_active': True, '__T': 1767845337548921, 'vm_uuid': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'ip6_address': '::'} 2026-01-08 04:11:16,957 - DEBUG - VM uve shows ip address as ['192.168.1.3', '::'] 2026-01-08 04:11:16,957 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:16,957 - INFO - Verifying through opserver in 10.0.0.242 2026-01-08 04:11:16,957 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat 2026-01-08 04:11:16,983 - DEBUG - expected vm list 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:16,983 - DEBUG - Extracted vm list ['4539ff81-ff1f-4a76-b2a5-0ff2aa129437'] 2026-01-08 04:11:16,983 - INFO - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is present in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:16,983 - DEBUG - Verifying vm in vrouter uve 2026-01-08 04:11:16,983 - DEBUG - Getting info from collector 10.0.0.27.. 2026-01-08 04:11:16,983 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat 2026-01-08 04:11:17,053 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4976-2'] 2026-01-08 04:11:17,053 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:17,090 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:11:17,121 - DEBUG - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:17,121 - DEBUG - Validated that VM ctest-vn1_vm1-92923363 is in Vrouter an-jenkins-deploy-platform-ansible-os-4976-2 UVE 2026-01-08 04:11:17,121 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2026-01-08 04:11:17,130 - DEBUG - Expected tap interface of VM uuid 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d 2026-01-08 04:11:17,130 - DEBUG - Expected VN of VM uuid 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:17,130 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:17,172 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:11:17,250 - DEBUG - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:17,250 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-28338633:21b1b327-c496-4908-a012-1d8e171a764d of vm 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:17,250 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 of vm 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:17,250 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.242 2026-01-08 04:11:17,250 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:11:17,263 - DEBUG - VM link and name as {'name': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat'} 2026-01-08 04:11:17,263 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.50 2026-01-08 04:11:17,263 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:11:17,320 - DEBUG - VM link and name as {'name': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat'} 2026-01-08 04:11:17,320 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.27 2026-01-08 04:11:17,320 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:11:17,333 - DEBUG - VM link and name as {'name': '4539ff81-ff1f-4a76-b2a5-0ff2aa129437', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437?flat'} 2026-01-08 04:11:17,333 - INFO - VM ctest-vn1_vm1-92923363 validations in Opserver passed 2026-01-08 04:11:17,422 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:11:17,422 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:11:17,422 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:17,430 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/bc68d0dd-4197-464d-83e0-ed8f02ca49ea 2026-01-08 04:11:17,440 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:17,448 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/bc68d0dd-4197-464d-83e0-ed8f02ca49ea 2026-01-08 04:11:17,458 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/6ba9b93a-ea34-4265-9984-5962b63adc0d 2026-01-08 04:11:17,468 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:17,468 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:17,476 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/bc68d0dd-4197-464d-83e0-ed8f02ca49ea 2026-01-08 04:11:17,486 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/6ba9b93a-ea34-4265-9984-5962b63adc0d 2026-01-08 04:11:17,494 - INFO - VM ctest-vn1_vm2-09771033 verfication in all API Servers passed 2026-01-08 04:11:17,520 - DEBUG - VM ctest-vn1_vm2-09771033 Tap interface: {'index': '3', 'name': 'tapbc68d0dd-41', 'uuid': 'bc68d0dd-4197-464d-83e0-ed8f02ca49ea', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'vm_uuid': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'vm_name': 'ctest-vn1_vm2-09771033', 'ip_addr': '192.168.1.4', 'mac_addr': '02:bc:68:d0:dd:41', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '123', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '28', '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': []} 2026-01-08 04:11:17,520 - DEBUG - Agent 10.0.0.57 vrf name: default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012 2026-01-08 04:11:17,526 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.129:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2026-01-08 04:11:17,611 - DEBUG - VM ctest-vn1_vm2-09771033 : Tap interface tapbc68d0dd-41 is set to Active 2026-01-08 04:11:17,611 - DEBUG - Tap interface tapbc68d0dd-41 detail : {'index': '3', 'name': 'tapbc68d0dd-41', 'uuid': 'bc68d0dd-4197-464d-83e0-ed8f02ca49ea', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012:ctest-vn1-74620012', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'vm_uuid': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'vm_name': 'ctest-vn1_vm2-09771033', 'ip_addr': '192.168.1.4', 'mac_addr': '02:bc:68:d0:dd:41', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '123', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '28', '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': []} 2026-01-08 04:11:17,732 - DEBUG - Starting Layer 2 verification in Agent 2026-01-08 04:11:17,743 - DEBUG - Layer 2 path is seen for VM MAC 02:bc:68:d0:dd:41 in agent 10.0.0.57 2026-01-08 04:11:17,743 - DEBUG - Active layer 2 route in agent is present for VMI tapbc68d0dd-41 2026-01-08 04:11:17,744 - DEBUG - L2 label(29) matches bw route table and interface table 2026-01-08 04:11:17,750 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is found in Agent of node 10.0.0.57 2026-01-08 04:11:17,883 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is consistent in agent 10.0.0.57 2026-01-08 04:11:17,883 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.57 2026-01-08 04:11:17,883 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 verification for VM ctest-vn1_vm2-09771033 in Agent 10.0.0.57 passed 2026-01-08 04:11:17,995 - DEBUG - Starting all layer 2 verification in agent 10.0.0.57 2026-01-08 04:11:18,007 - DEBUG - Route for VM MAC 02:bc:68:d0:dd:41 is consistent in agent 10.0.0.57 2026-01-08 04:11:18,013 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is found in Agent of node 10.0.0.56 2026-01-08 04:11:18,145 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 is consistent in agent 10.0.0.56 2026-01-08 04:11:18,146 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.56 2026-01-08 04:11:18,146 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 verification for VM ctest-vn1_vm2-09771033 in Agent 10.0.0.56 passed 2026-01-08 04:11:18,265 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56 2026-01-08 04:11:18,279 - DEBUG - Route for VM MAC 02:bc:68:d0:dd:41 is consistent in agent 10.0.0.56 2026-01-08 04:11:18,279 - INFO - VM ctest-vn1_vm2-09771033 verifications in Compute nodes passed 2026-01-08 04:11:18,524 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.57 2026-01-08 04:11:18,529 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2026-01-08 04:11:18,641 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.56 2026-01-08 04:11:18,645 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.129, 25; Got 10.20.0.129,25 2026-01-08 04:11:18,645 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.56 2026-01-08 04:11:18,645 - INFO - Validated routes of VM ctest-vn1_vm2-09771033 in all vrouters 2026-01-08 04:11:19,171 - DEBUG - Starting all layer2 verification in 10.0.0.242 Control Node 2026-01-08 04:11:19,299 - DEBUG - Layer2 route found for VM MAC 02:bc:68:d0:dd:41 in Control-node 10.0.0.242 2026-01-08 04:11:19,299 - DEBUG - L2 Label for VM ctest-vn1_vm2-09771033 same between Control-node 10.0.0.242 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:19,299 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2026-01-08 04:11:19,428 - DEBUG - Layer2 route found for VM MAC 02:bc:68:d0:dd:41 in Control-node 10.0.0.50 2026-01-08 04:11:19,428 - DEBUG - L2 Label for VM ctest-vn1_vm2-09771033 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:19,428 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node 2026-01-08 04:11:19,560 - DEBUG - Layer2 route found for VM MAC 02:bc:68:d0:dd:41 in Control-node 10.0.0.27 2026-01-08 04:11:19,560 - DEBUG - L2 Label for VM ctest-vn1_vm2-09771033 same between Control-node 10.0.0.27 and Agent, Expected: 29, Seen: 29 2026-01-08 04:11:19,561 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-09771033 passed 2026-01-08 04:11:19,561 - DEBUG - Verifying the vm in opserver 2026-01-08 04:11:19,561 - DEBUG - Verifying in collector 10.0.0.27 ... 2026-01-08 04:11:19,561 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat 2026-01-08 04:11:19,582 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea?flat 2026-01-08 04:11:19,607 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea?flat 2026-01-08 04:11:19,628 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat 2026-01-08 04:11:19,646 - DEBUG - Verifying vm in vn uve 2026-01-08 04:11:19,646 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea?flat 2026-01-08 04:11:19,668 - DEBUG - VM uve shows interface as {'virtual_network': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012', 'ip_address': '192.168.1.4', 'vhostuser_mode': 0, 'vn_uuid': '18f94d0b-be10-40a9-b6d8-7627d7319de6', 'vm_name': 'ctest-vn1_vm2-09771033', 'mac_address': '02:bc:68:d0:dd:41', 'rx_vlan': 65535, 'gateway': '192.168.1.1', 'uuid': 'bc68d0dd-4197-464d-83e0-ed8f02ca49ea', 'tx_vlan': 65535, 'label': 25, 'admin_state': True, 'active': True, 'ip4_active': True, 'is_health_check_active': True, 'fixed_ip4_list': ['192.168.1.4'], 'ip6_active': False, 'port_mirror_enabled': False, 'l2_active': True, '__T': 1767845329077965, 'vm_uuid': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'ip6_address': '::'} 2026-01-08 04:11:19,668 - DEBUG - VM uve shows ip address as ['192.168.1.4', '::'] 2026-01-08 04:11:19,668 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:19,668 - INFO - Verifying through opserver in 10.0.0.242 2026-01-08 04:11:19,668 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat 2026-01-08 04:11:19,699 - DEBUG - expected vm list 91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:19,699 - DEBUG - Extracted vm list ['91e6f6a9-a27d-49be-8834-2e4c0985b34d'] 2026-01-08 04:11:19,700 - INFO - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is present in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:19,700 - DEBUG - Verifying vm in vrouter uve 2026-01-08 04:11:19,700 - DEBUG - Getting info from collector 10.0.0.27.. 2026-01-08 04:11:19,700 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat 2026-01-08 04:11:19,716 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4976-1'] 2026-01-08 04:11:19,716 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:19,776 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:19,808 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:19,808 - DEBUG - Validated that VM ctest-vn1_vm2-09771033 is in Vrouter an-jenkins-deploy-platform-ansible-os-4976-1 UVE 2026-01-08 04:11:19,808 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2026-01-08 04:11:19,817 - DEBUG - Expected tap interface of VM uuid 91e6f6a9-a27d-49be-8834-2e4c0985b34d is default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea 2026-01-08 04:11:19,817 - DEBUG - Expected VN of VM uuid 91e6f6a9-a27d-49be-8834-2e4c0985b34d is default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:19,817 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:19,869 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:19,903 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:19,903 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-28338633:bc68d0dd-4197-464d-83e0-ed8f02ca49ea of vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:19,903 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 of vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:19,903 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.242 2026-01-08 04:11:19,903 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:11:19,915 - DEBUG - VM link and name as {'name': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat'} 2026-01-08 04:11:19,915 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.50 2026-01-08 04:11:19,915 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:11:19,928 - DEBUG - VM link and name as {'name': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat'} 2026-01-08 04:11:19,928 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.27 2026-01-08 04:11:19,928 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:11:19,941 - DEBUG - VM link and name as {'name': '91e6f6a9-a27d-49be-8834-2e4c0985b34d', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d?flat'} 2026-01-08 04:11:19,941 - INFO - VM ctest-vn1_vm2-09771033 validations in Opserver passed 2026-01-08 04:11:19,941 - INFO - Checking the ping between the VM again 2026-01-08 04:11:19,941 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:11:19,941 - 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 2026-01-08 04:11:19,942 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4 2026-01-08 04:11:22,474 - 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=5.58 ms 64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=1.09 ms 64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.31 ms --- 192.168.1.4 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.097/2.662/5.581/2.066 ms 2026-01-08 04:11:22,474 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-92923363 passed 2026-01-08 04:11:22,474 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:11:22,474 - 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.57, gateway password: c0ntrail123 2026-01-08 04:11:22,474 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3 2026-01-08 04:11:25,021 - 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.06 ms 64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.53 ms 64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=2.17 ms --- 192.168.1.3 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.539/2.259/3.064/0.627 ms 2026-01-08 04:11:25,021 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-09771033 passed 2026-01-08 04:11:25,021 - INFO - Deleting VM ctest-vn1_vm2-09771033 2026-01-08 04:11:25,097 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:25,097 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:25,107 - DEBUG - VM ID 91e6f6a9-a27d-49be-8834-2e4c0985b34d of VM ctest-vn1_vm2-09771033 is still found in API Server 2026-01-08 04:11:27,108 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:27,109 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:27,117 - DEBUG - Response Code: 404 2026-01-08 04:11:27,117 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:27,123 - DEBUG - Response Code: 404 2026-01-08 04:11:27,124 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/91e6f6a9-a27d-49be-8834-2e4c0985b34d 2026-01-08 04:11:27,129 - DEBUG - Response Code: 404 2026-01-08 04:11:27,129 - INFO - VM ctest-vn1_vm2-09771033 is fully removed in API-Server 2026-01-08 04:11:27,283 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2026-01-08 04:11:27,319 - DEBUG - Validated that vrouter 10.0.0.57 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:27,436 - DEBUG - VM route 192.168.1.4 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 of compute 10.0.0.56 2026-01-08 04:11:27,441 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:27,441 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:27,442 - INFO - VM ctest-vn1_vm2-09771033 is removed in Compute, and routes are removed in all compute nodes 2026-01-08 04:11:27,700 - INFO - Routes for VM ctest-vn1_vm2-09771033 is removed in all control-nodes 2026-01-08 04:11:27,700 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:27,751 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:27,784 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:27,784 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:27,784 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:27,785 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:30,790 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:30,842 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:30,874 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:30,874 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:30,874 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:30,874 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:33,874 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:33,920 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:33,948 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:33,949 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:33,949 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:33,949 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:36,950 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:36,998 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:37,031 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:37,031 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:37,031 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:37,031 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:40,031 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:40,083 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:40,114 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:40,114 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:40,114 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:40,114 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:43,115 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:43,170 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:43,208 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:43,208 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:43,208 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:43,208 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:46,209 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:46,258 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:46,289 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:46,289 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:46,289 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:46,289 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:49,289 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:49,339 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:11:49,375 - DEBUG - VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is not present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:11:49,376 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:49,376 - DEBUG - interface for vm 91e6f6a9-a27d-49be-8834-2e4c0985b34d deleted from vrouter uve ... 2026-01-08 04:11:49,376 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:49,376 - DEBUG - Validated that VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is removed in Vrouter UVE 2026-01-08 04:11:49,376 - DEBUG - Verifying through opserver in 10.0.0.242 2026-01-08 04:11:49,376 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat 2026-01-08 04:11:49,403 - DEBUG - 91e6f6a9-a27d-49be-8834-2e4c0985b34d BM not in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 uve 2026-01-08 04:11:49,403 - DEBUG - Validated that VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is not present in the VN UVE 2026-01-08 04:11:49,403 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.242 2026-01-08 04:11:49,403 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:11:49,418 - INFO - 91e6f6a9-a27d-49be-8834-2e4c0985b34d vm uve deleted from opserver 2026-01-08 04:11:49,418 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.50 2026-01-08 04:11:49,418 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:11:49,432 - INFO - 91e6f6a9-a27d-49be-8834-2e4c0985b34d vm uve deleted from opserver 2026-01-08 04:11:49,432 - DEBUG - Verifying the 91e6f6a9-a27d-49be-8834-2e4c0985b34d virtual network link through opserver 10.0.0.27 2026-01-08 04:11:49,432 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:11:49,447 - INFO - 91e6f6a9-a27d-49be-8834-2e4c0985b34d vm uve deleted from opserver 2026-01-08 04:11:49,447 - INFO - Validated that VM 91e6f6a9-a27d-49be-8834-2e4c0985b34d is removed from Opserver 2026-01-08 04:11:49,447 - INFO - Deleting VM ctest-vn1_vm1-92923363 2026-01-08 04:11:49,523 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:49,523 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:49,533 - DEBUG - VM ID 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 of VM ctest-vn1_vm1-92923363 is still found in API Server 2026-01-08 04:11:51,534 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:11:51,535 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:51,542 - DEBUG - Response Code: 404 2026-01-08 04:11:51,542 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:51,559 - DEBUG - Response Code: 404 2026-01-08 04:11:51,559 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/4539ff81-ff1f-4a76-b2a5-0ff2aa129437 2026-01-08 04:11:51,565 - DEBUG - Response Code: 404 2026-01-08 04:11:51,566 - INFO - VM ctest-vn1_vm1-92923363 is fully removed in API-Server 2026-01-08 04:11:51,728 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2026-01-08 04:11:51,783 - DEBUG - Validated that vrouter 10.0.0.57 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:51,795 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:51,795 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 2026-01-08 04:11:51,795 - INFO - VM ctest-vn1_vm1-92923363 is removed in Compute, and routes are removed in all compute nodes 2026-01-08 04:11:52,043 - INFO - Routes for VM ctest-vn1_vm1-92923363 is removed in all control-nodes 2026-01-08 04:11:52,043 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:52,079 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:11:52,113 - DEBUG - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:52,113 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:52,113 - DEBUG - interface for vm 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 deleted from vrouter uve ... 2026-01-08 04:11:52,114 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:55,115 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:55,149 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:11:55,181 - DEBUG - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:55,181 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:55,181 - DEBUG - interface for vm 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 deleted from vrouter uve ... 2026-01-08 04:11:55,181 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:58,182 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:11:58,221 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:11:58,251 - DEBUG - VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:11:58,251 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:11:58,251 - DEBUG - interface for vm 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 deleted from vrouter uve ... 2026-01-08 04:11:58,251 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:11:58,251 - DEBUG - Validated that VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is removed in Vrouter UVE 2026-01-08 04:11:58,251 - DEBUG - Verifying through opserver in 10.0.0.242 2026-01-08 04:11:58,251 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012?flat 2026-01-08 04:11:58,270 - DEBUG - 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 BM not in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-74620012 uve 2026-01-08 04:11:58,270 - DEBUG - Validated that VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is not present in the VN UVE 2026-01-08 04:11:58,270 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.242 2026-01-08 04:11:58,270 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:11:58,283 - INFO - 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 vm uve deleted from opserver 2026-01-08 04:11:58,283 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.50 2026-01-08 04:11:58,283 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:11:58,298 - INFO - 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 vm uve deleted from opserver 2026-01-08 04:11:58,298 - DEBUG - Verifying the 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 virtual network link through opserver 10.0.0.27 2026-01-08 04:11:58,298 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:11:58,311 - INFO - 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 vm uve deleted from opserver 2026-01-08 04:11:58,311 - INFO - Validated that VM 4539ff81-ff1f-4a76-b2a5-0ff2aa129437 is removed from Opserver 2026-01-08 04:11:58,311 - INFO - Deleting VN ctest-vn1-74620012 2026-01-08 04:11:58,537 - DEBUG - Response for deleting network () 2026-01-08 04:11:58,537 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/9bc94b16-5b67-4999-8db0-fcda38646fe4 2026-01-08 04:11:58,544 - DEBUG - Response Code: 404 2026-01-08 04:11:58,544 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:11:58,553 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:11:58,617 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:11:58,725 - INFO - Validated that VN ctest-vn1-74620012 is not found in API Server 2026-01-08 04:11:58,737 - DEBUG - VN ctest-vn1-74620012 is not present in Agent 10.0.0.57 2026-01-08 04:11:58,749 - DEBUG - VN ctest-vn1-74620012 is not present in Agent 10.0.0.56 2026-01-08 04:11:58,749 - INFO - Validated that VN ctest-vn1-74620012 is not in any agent 2026-01-08 04:11:58,783 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-74620012 info 2026-01-08 04:12:00,042 - DEBUG - Skipping xmpp flap check
2026-01-08 04:12:00,042 - INFO - END TEST : test_control_node_switchover : PASSED[0:03:22]
2026-01-08 04:12:00,042 - INFO - -------------------------------------------------------------------------------- 2026-01-08 04:12:00,045 - INFO - ================================================================================ 2026-01-08 04:12:00,045 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns 2026-01-08 04:12:00,045 - 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 2026-01-08 04:12:01,323 - DEBUG - Skipping xmpp flap check 2026-01-08 04:12:01,323 - INFO - Initial checks done. Running the testcase now 2026-01-08 04:12:01,323 - INFO - 2026-01-08 04:12:01,331 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672, 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-28338633:ctest-vn2-09734861, 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] 2026-01-08 04:12:01,615 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861, 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-28338633:ctest-vn1-01848672, 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] 2026-01-08 04:12:02,172 - INFO - Created VN ctest-vn1-01848672, UUID :3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,502 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:12:02,510 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:12:02,521 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:12:02,631 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,642 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,652 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:12:02,661 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:12:02,671 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/dcf54a2f-ef13-4fe8-8223-20707fbc5efa 2026-01-08 04:12:02,678 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:12:02,678 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,687 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:12:02,706 - INFO - Verified VN network id 13 for VN 3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,706 - INFO - Verifications in API Server for VN ctest-vn1-01848672 passed 2026-01-08 04:12:02,706 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,715 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:12:02,724 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:12:02,732 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/dcf54a2f-ef13-4fe8-8223-20707fbc5efa 2026-01-08 04:12:02,745 - DEBUG - Control-node 10.0.0.242 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:02', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.414505'} 2026-01-08 04:12:02,753 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:12:02,767 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:02', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.439054'} 2026-01-08 04:12:02,775 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:12:02,780 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:02', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.465453'} 2026-01-08 04:12:02,789 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:12:02,789 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-01848672 passed 2026-01-08 04:12:02,789 - DEBUG - ====Verifying policy data for ctest-vn1-01848672 in API_Server ====== 2026-01-08 04:12:02,789 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:12:02,796 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:12:02,808 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:12:02,903 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:12:02,912 - DEBUG - =>VN ctest-vn1-01848672 has no policy to be verified 2026-01-08 04:12:02,912 - DEBUG - Verifying the vn in opserver 2026-01-08 04:12:02,912 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.242 2026-01-08 04:12:02,912 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-networks 2026-01-08 04:12:02,924 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:12:02,924 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.50 2026-01-08 04:12:02,924 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2026-01-08 04:12:02,936 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:12:02,937 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.27 2026-01-08 04:12:02,937 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks 2026-01-08 04:12:02,952 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:12:02,952 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is found in opserver 2026-01-08 04:12:02,975 - DEBUG - Do not have enough data to verify VN in agent 2026-01-08 04:12:02,985 - DEBUG - VRF ids for VN ctest-vn1-01848672: {} 2026-01-08 04:12:03,684 - INFO - Created VN ctest-vn2-09734861, UUID :5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,031 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:12:04,037 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:12:04,050 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:12:04,144 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,158 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,168 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:12:04,181 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:12:04,191 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/f7a34337-df9b-444a-8d7d-50a5b485e23d 2026-01-08 04:12:04,200 - DEBUG - Route Targets: ['target:64512:8000006'] 2026-01-08 04:12:04,200 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,213 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:12:04,234 - INFO - Verified VN network id 14 for VN 5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,234 - INFO - Verifications in API Server for VN ctest-vn2-09734861 passed 2026-01-08 04:12:04,234 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,245 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:12:04,255 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:12:04,263 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/f7a34337-df9b-444a-8d7d-50a5b485e23d 2026-01-08 04:12:04,277 - DEBUG - Control-node 10.0.0.242 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6887121833083881787', 'uuid-lslong': '12209274235163448183'}, 'enable': 'true', 'created': '2026-01-08T04:12:03', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.441054'} 2026-01-08 04:12:04,284 - DEBUG - Route Targets: ['target:64512:8000006'] 2026-01-08 04:12:04,291 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6887121833083881787', 'uuid-lslong': '12209274235163448183'}, 'enable': 'true', 'created': '2026-01-08T04:12:03', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.463411'} 2026-01-08 04:12:04,298 - DEBUG - Route Targets: ['target:64512:8000006'] 2026-01-08 04:12:04,304 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '6887121833083881787', 'uuid-lslong': '12209274235163448183'}, 'enable': 'true', 'created': '2026-01-08T04:12:03', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.468011'} 2026-01-08 04:12:04,313 - DEBUG - Route Targets: ['target:64512:8000006'] 2026-01-08 04:12:04,313 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-09734861 passed 2026-01-08 04:12:04,314 - DEBUG - ====Verifying policy data for ctest-vn2-09734861 in API_Server ====== 2026-01-08 04:12:04,314 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:12:04,321 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:12:04,335 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:12:04,433 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/5f93f8d1-51cd-493b-a970-0e3ab83f1377 2026-01-08 04:12:04,447 - DEBUG - =>VN ctest-vn2-09734861 has no policy to be verified 2026-01-08 04:12:04,447 - DEBUG - Verifying the vn in opserver 2026-01-08 04:12:04,447 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 virtual network link through opserver 10.0.0.242 2026-01-08 04:12:04,447 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-networks 2026-01-08 04:12:04,461 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861?flat'} 2026-01-08 04:12:04,462 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 virtual network link through opserver 10.0.0.50 2026-01-08 04:12:04,462 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2026-01-08 04:12:04,474 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861?flat'} 2026-01-08 04:12:04,474 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 virtual network link through opserver 10.0.0.27 2026-01-08 04:12:04,474 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks 2026-01-08 04:12:04,488 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861?flat'} 2026-01-08 04:12:04,488 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is found in opserver 2026-01-08 04:12:04,516 - DEBUG - Do not have enough data to verify VN in agent 2026-01-08 04:12:04,529 - DEBUG - VRF ids for VN ctest-vn2-09734861: {} 2026-01-08 04:12:06,215 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-2) 2026-01-08 04:12:07,749 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-1) 2026-01-08 04:12:07,749 - INFO - Waiting for VM ctest-vn1_vm1-07589933 to be up.. 2026-01-08 04:12:07,869 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-08 04:12:12,963 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:12:12,963 - INFO - VM name : ctest-vn1_vm1-07589933 2026-01-08 04:12:13,057 - DEBUG - VM ctest-vn1_vm1-07589933 ID is ec41b5a7-e03d-4ee1-849d-d689b5149b2c 2026-01-08 04:12:13,057 - DEBUG - VM ctest-vn1_vm1-07589933 launched on Node an-jenkins-deploy-platform-ansible-os-4976-2 2026-01-08 04:12:13,150 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/ec41b5a7-e03d-4ee1-849d-d689b5149b2c 2026-01-08 04:12:13,162 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/b7337969-2c8b-4f7e-b54b-e0c99c3a3a68 2026-01-08 04:12:16,361 - 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 1034ms') 2026-01-08 04:12:16,361 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:16,377 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:20,453 - 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') 2026-01-08 04:12:20,453 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:20,470 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:24,554 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2026-01-08 04:12:24,554 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:24,570 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:28,652 - 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') 2026-01-08 04:12:28,652 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:28,667 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:32,745 - 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') 2026-01-08 04:12:32,745 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:32,760 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:36,840 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2026-01-08 04:12:36,840 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:36,856 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:40,938 - 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') 2026-01-08 04:12:40,938 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:40,952 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:45,035 - 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') 2026-01-08 04:12:45,035 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 failed! 2026-01-08 04:12:45,050 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:12:47,117 - 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.33 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.27 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.267/4.296/7.325/3.029 ms') 2026-01-08 04:12:47,117 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-07589933 passed 2026-01-08 04:12:47,188 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:12:47,188 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-07589933, IP 192.168.1.252, Port 22 2026-01-08 04:12:47,256 - 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': ''} 2026-01-08 04:12:47,344 - DEBUG - VM ctest-vn1_vm1-07589933 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:12:52,345 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:12:52,345 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-07589933, IP 192.168.1.252, Port 22 2026-01-08 04:12:52,401 - 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': ''} 2026-01-08 04:12:52,493 - DEBUG - VM ctest-vn1_vm1-07589933 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:12:57,494 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:12:57,494 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-07589933, IP 192.168.1.252, Port 22 2026-01-08 04:12:57,563 - 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': ''} 2026-01-08 04:12:57,666 - DEBUG - VM ctest-vn1_vm1-07589933 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:13:02,666 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:13:02,666 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-07589933, IP 192.168.1.252, Port 22 2026-01-08 04:13:02,726 - 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': ''} 2026-01-08 04:13:02,810 - DEBUG - VM ctest-vn1_vm1-07589933 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:13:07,811 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:13:07,812 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-07589933, IP 192.168.1.252, Port 22 2026-01-08 04:13:07,981 - DEBUG - VM ctest-vn1_vm1-07589933 is ready for SSH connections 2026-01-08 04:13:07,982 - INFO - Waiting for VM ctest-vn2_vm1-37544786 to be up.. 2026-01-08 04:13:08,085 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:13:08,085 - INFO - VM name : ctest-vn2_vm1-37544786 2026-01-08 04:13:08,175 - DEBUG - VM ctest-vn2_vm1-37544786 ID is 551a796c-2870-4584-a6b3-eb77bd5f4ced 2026-01-08 04:13:08,176 - DEBUG - VM ctest-vn2_vm1-37544786 launched on Node an-jenkins-deploy-platform-ansible-os-4976-1 2026-01-08 04:13:08,261 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/551a796c-2870-4584-a6b3-eb77bd5f4ced 2026-01-08 04:13:08,271 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/0988c2b3-d5cc-4d80-b225-0692521c218d 2026-01-08 04:13:09,442 - 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.16 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.03 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.032/2.593/4.155/1.561 ms') 2026-01-08 04:13:09,442 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2_vm1-37544786 passed 2026-01-08 04:13:09,512 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:13:09,512 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-37544786, IP 192.168.2.252, Port 22 2026-01-08 04:13:09,594 - 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': ''} 2026-01-08 04:13:09,684 - DEBUG - VM ctest-vn2_vm1-37544786 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:13:14,684 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:13:14,685 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-37544786, IP 192.168.2.252, Port 22 2026-01-08 04:13:14,853 - DEBUG - VM ctest-vn2_vm1-37544786 is ready for SSH connections 2026-01-08 04:13:14,853 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:13:14,853 - 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 2026-01-08 04:13:14,853 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.252 2026-01-08 04:13:32,307 - 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=2.87 ms 64 bytes from 192.168.2.252: icmp_req=3 ttl=63 time=2.31 ms --- 192.168.2.252 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2005ms rtt min/avg/max/mdev = 2.313/3.867/6.414/1.815 ms 2026-01-08 04:13:32,307 - INFO - Ping to IP 192.168.2.252 from VM ctest-vn1_vm1-07589933 passed 2026-01-08 04:13:35,751 - INFO - 10.0.0.57 2026-01-08 04:13:35,755 - INFO - agent:initializing 2026-01-08 04:13:35,755 - DEBUG - defaultdict(, {'10.0.0.57': {'agent': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:13:35,756 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:13:40,856 - INFO - 10.0.0.57 2026-01-08 04:13:40,861 - INFO - agent:active 2026-01-08 04:13:40,862 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.57 2026-01-08 04:13:44,239 - INFO - 10.0.0.56 2026-01-08 04:13:44,242 - INFO - agent:initializing 2026-01-08 04:13:44,243 - DEBUG - defaultdict(, {'10.0.0.56': {'agent': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:13:44,243 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:13:49,332 - INFO - 10.0.0.56 2026-01-08 04:13:49,338 - INFO - agent:active 2026-01-08 04:13:49,338 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.56 2026-01-08 04:13:49,986 - INFO - 10.0.0.242 2026-01-08 04:13:49,990 - INFO - control:initializing 2026-01-08 04:13:49,990 - DEBUG - defaultdict(, {'10.0.0.242': {'control': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:13:49,990 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:13:55,133 - INFO - 10.0.0.242 2026-01-08 04:13:55,138 - INFO - control:active 2026-01-08 04:13:55,139 - INFO - Contrail services ['control'] are up on nodes 10.0.0.242 2026-01-08 04:13:55,589 - INFO - 10.0.0.50 2026-01-08 04:13:55,602 - INFO - control:initializing 2026-01-08 04:13:55,603 - DEBUG - defaultdict(, {'10.0.0.50': {'control': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:13:55,603 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:14:00,706 - INFO - 10.0.0.50 2026-01-08 04:14:00,715 - INFO - control:active 2026-01-08 04:14:00,715 - INFO - Contrail services ['control'] are up on nodes 10.0.0.50 2026-01-08 04:14:01,166 - INFO - 10.0.0.27 2026-01-08 04:14:01,173 - INFO - control:initializing 2026-01-08 04:14:01,173 - DEBUG - defaultdict(, {'10.0.0.27': {'control': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:01,173 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:14:06,276 - INFO - 10.0.0.27 2026-01-08 04:14:06,282 - INFO - control:active 2026-01-08 04:14:06,283 - INFO - Contrail services ['control'] are up on nodes 10.0.0.27 2026-01-08 04:14:07,131 - INFO - 10.0.0.242 2026-01-08 04:14:07,140 - INFO - api-server:initializing 2026-01-08 04:14:07,140 - DEBUG - defaultdict(, {'10.0.0.242': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:07,140 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:14:12,288 - INFO - 10.0.0.242 2026-01-08 04:14:12,293 - INFO - api-server:initializing 2026-01-08 04:14:12,293 - DEBUG - defaultdict(, {'10.0.0.242': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:12,293 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2026-01-08 04:14:17,406 - INFO - 10.0.0.242 2026-01-08 04:14:17,411 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2026-01-08 04:14:17,411 - DEBUG - defaultdict(, {'10.0.0.242': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2026-01-08 04:14:17,411 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2026-01-08 04:14:22,533 - INFO - 10.0.0.242 2026-01-08 04:14:22,537 - INFO - api-server:active 2026-01-08 04:14:22,537 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.242 2026-01-08 04:14:23,194 - INFO - 10.0.0.50 2026-01-08 04:14:23,199 - INFO - api-server:initializing 2026-01-08 04:14:23,199 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:23,199 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:14:28,301 - INFO - 10.0.0.50 2026-01-08 04:14:28,305 - INFO - api-server:initializing 2026-01-08 04:14:28,305 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:28,305 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2026-01-08 04:14:33,403 - INFO - 10.0.0.50 2026-01-08 04:14:33,408 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2026-01-08 04:14:33,408 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2026-01-08 04:14:33,408 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2026-01-08 04:14:38,508 - INFO - 10.0.0.50 2026-01-08 04:14:38,513 - INFO - api-server:active 2026-01-08 04:14:38,513 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.50 2026-01-08 04:14:39,206 - INFO - 10.0.0.27 2026-01-08 04:14:39,210 - INFO - api-server:initializing 2026-01-08 04:14:39,210 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:39,210 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2026-01-08 04:14:44,314 - INFO - 10.0.0.27 2026-01-08 04:14:44,318 - INFO - api-server:initializing 2026-01-08 04:14:44,318 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': None}}}) 2026-01-08 04:14:44,318 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2026-01-08 04:14:49,408 - INFO - 10.0.0.27 2026-01-08 04:14:49,414 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2026-01-08 04:14:49,414 - DEBUG - defaultdict(, {'10.0.0.27': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2026-01-08 04:14:49,414 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2026-01-08 04:14:54,504 - INFO - 10.0.0.27 2026-01-08 04:14:54,511 - INFO - api-server:active 2026-01-08 04:14:54,511 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.27 2026-01-08 04:14:54,628 - INFO - 10.0.0.242 2026-01-08 04:14:54,628 - INFO - config 2026-01-08 04:14:54,635 - INFO - config-nodemgr:active 2026-01-08 04:14:54,641 - INFO - api-server:active 2026-01-08 04:14:54,646 - INFO - schema:active 2026-01-08 04:14:54,650 - INFO - svc-monitor:active 2026-01-08 04:14:54,654 - INFO - device-manager:active 2026-01-08 04:14:54,654 - INFO - config-database 2026-01-08 04:14:54,654 - INFO - config-cassandra:active 2026-01-08 04:14:54,654 - INFO - config-zookeeper:active 2026-01-08 04:14:54,654 - INFO - config-rabbitmq:active 2026-01-08 04:14:54,654 - INFO - control 2026-01-08 04:14:54,658 - INFO - control-nodemgr:active 2026-01-08 04:14:54,663 - INFO - control:active 2026-01-08 04:14:54,663 - INFO - named:active 2026-01-08 04:14:54,670 - INFO - dns:active 2026-01-08 04:14:54,670 - INFO - analytics 2026-01-08 04:14:54,676 - INFO - analytics-nodemgr:active 2026-01-08 04:14:54,681 - INFO - analytics-api:active 2026-01-08 04:14:54,686 - INFO - collector:active 2026-01-08 04:14:54,687 - INFO - analytics-database 2026-01-08 04:14:54,687 - INFO - analytics-cassandra:active 2026-01-08 04:14:54,692 - INFO - analyticsdb-nodemgr:active 2026-01-08 04:14:54,697 - INFO - query-engine:active 2026-01-08 04:14:54,698 - INFO - webui 2026-01-08 04:14:54,698 - INFO - webui:active 2026-01-08 04:14:54,698 - INFO - webui-middleware:active 2026-01-08 04:14:54,698 - INFO - redis:active 2026-01-08 04:14:54,698 - INFO - analytics_snmp 2026-01-08 04:14:54,703 - INFO - snmp-collector:active 2026-01-08 04:14:54,703 - INFO - snmp-topology:active 2026-01-08 04:14:54,703 - INFO - analytics_alarm 2026-01-08 04:14:54,703 - INFO - alarmgen:active 2026-01-08 04:14:54,834 - INFO - 10.0.0.50 2026-01-08 04:14:54,834 - INFO - config 2026-01-08 04:14:54,842 - INFO - config-nodemgr:active 2026-01-08 04:14:54,847 - INFO - api-server:active 2026-01-08 04:14:54,850 - INFO - schema:backup 2026-01-08 04:14:54,853 - INFO - svc-monitor:backup 2026-01-08 04:14:54,857 - INFO - device-manager:backup 2026-01-08 04:14:54,857 - INFO - config-database 2026-01-08 04:14:54,857 - INFO - config-cassandra:active 2026-01-08 04:14:54,857 - INFO - config-zookeeper:active 2026-01-08 04:14:54,857 - INFO - config-rabbitmq:active 2026-01-08 04:14:54,857 - INFO - control 2026-01-08 04:14:54,863 - INFO - control-nodemgr:active 2026-01-08 04:14:54,870 - INFO - control:active 2026-01-08 04:14:54,870 - INFO - named:active 2026-01-08 04:14:54,878 - INFO - dns:active 2026-01-08 04:14:54,879 - INFO - analytics 2026-01-08 04:14:54,884 - INFO - analytics-nodemgr:active 2026-01-08 04:14:54,888 - INFO - analytics-api:active 2026-01-08 04:14:54,893 - INFO - collector:active 2026-01-08 04:14:54,893 - INFO - analytics-database 2026-01-08 04:14:54,893 - INFO - analytics-cassandra:active 2026-01-08 04:14:54,898 - INFO - analyticsdb-nodemgr:active 2026-01-08 04:14:54,907 - INFO - query-engine:active 2026-01-08 04:14:54,907 - INFO - webui 2026-01-08 04:14:54,907 - INFO - webui:active 2026-01-08 04:14:54,907 - INFO - webui-middleware:active 2026-01-08 04:14:54,907 - INFO - redis:active 2026-01-08 04:14:54,907 - INFO - analytics_snmp 2026-01-08 04:14:54,912 - INFO - snmp-collector:active 2026-01-08 04:14:54,913 - INFO - snmp-topology:active 2026-01-08 04:14:54,913 - INFO - analytics_alarm 2026-01-08 04:14:54,913 - INFO - alarmgen:active 2026-01-08 04:14:55,021 - INFO - 10.0.0.27 2026-01-08 04:14:55,021 - INFO - config 2026-01-08 04:14:55,027 - INFO - config-nodemgr:active 2026-01-08 04:14:55,032 - INFO - api-server:active 2026-01-08 04:14:55,035 - INFO - schema:backup 2026-01-08 04:14:55,038 - INFO - svc-monitor:backup 2026-01-08 04:14:55,042 - INFO - device-manager:backup 2026-01-08 04:14:55,042 - INFO - config-database 2026-01-08 04:14:55,042 - INFO - config-cassandra:active 2026-01-08 04:14:55,042 - INFO - config-zookeeper:active 2026-01-08 04:14:55,042 - INFO - config-rabbitmq:active 2026-01-08 04:14:55,042 - INFO - control 2026-01-08 04:14:55,049 - INFO - control-nodemgr:active 2026-01-08 04:14:55,058 - INFO - control:active 2026-01-08 04:14:55,058 - INFO - named:active 2026-01-08 04:14:55,064 - INFO - dns:active 2026-01-08 04:14:55,064 - INFO - analytics 2026-01-08 04:14:55,069 - INFO - analytics-nodemgr:active 2026-01-08 04:14:55,074 - INFO - analytics-api:active 2026-01-08 04:14:55,079 - INFO - collector:active 2026-01-08 04:14:55,079 - INFO - analytics-database 2026-01-08 04:14:55,079 - INFO - analytics-cassandra:active 2026-01-08 04:14:55,084 - INFO - analyticsdb-nodemgr:active 2026-01-08 04:14:55,090 - INFO - query-engine:active 2026-01-08 04:14:55,090 - INFO - webui 2026-01-08 04:14:55,090 - INFO - webui:active 2026-01-08 04:14:55,090 - INFO - webui-middleware:active 2026-01-08 04:14:55,090 - INFO - redis:active 2026-01-08 04:14:55,090 - INFO - analytics_snmp 2026-01-08 04:14:55,094 - INFO - snmp-collector:active 2026-01-08 04:14:55,094 - INFO - snmp-topology:active 2026-01-08 04:14:55,094 - INFO - analytics_alarm 2026-01-08 04:14:55,095 - INFO - alarmgen:active 2026-01-08 04:14:55,187 - INFO - 10.0.0.57 2026-01-08 04:14:55,187 - INFO - vrouter 2026-01-08 04:14:55,194 - INFO - vrouter-nodemgr:active 2026-01-08 04:14:55,200 - INFO - agent:active 2026-01-08 04:14:55,299 - INFO - 10.0.0.56 2026-01-08 04:14:55,299 - INFO - vrouter 2026-01-08 04:14:55,305 - INFO - vrouter-nodemgr:active 2026-01-08 04:14:55,312 - INFO - agent:active 2026-01-08 04:14:55,312 - INFO - All the contrail services are up on all nodes 2026-01-08 04:14:55,312 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:14:56,053 - WARNING - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.25:5269'] servers NOT UP 2026-01-08 04:14:56,053 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.17:5269'] servers UP 2026-01-08 04:14:56,053 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1 connected to xmpp 10.20.0.17 2026-01-08 04:14:56,054 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.193:5269'] servers UP 2026-01-08 04:14:56,054 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1 connected to xmpp 10.20.0.193 2026-01-08 04:14:56,054 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.25:53'] servers UP 2026-01-08 04:14:56,054 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1 connected to dns 10.20.0.25 2026-01-08 04:14:56,055 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.17:53'] servers UP 2026-01-08 04:14:56,055 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1 connected to dns 10.20.0.17 2026-01-08 04:14:56,055 - WARNING - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.20.0.193:53'] servers NOT UP 2026-01-08 04:14:56,055 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.0.0.242:8086'] servers UP 2026-01-08 04:14:56,056 - INFO - an-jenkins-deploy-platform-ansible-os-4976-1 connected to collector 10.0.0.242 2026-01-08 04:14:56,056 - WARNING - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.0.0.50:8086'] servers NOT UP 2026-01-08 04:14:56,056 - WARNING - an-jenkins-deploy-platform-ansible-os-4976-1:contrail-vrouter-agent module connection to ['10.0.0.27:8086'] servers NOT UP 2026-01-08 04:14:56,056 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:14:56,835 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-1:contrail-control module connection to 10.0.0.242:9041 servers UP 2026-01-08 04:14:56,836 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-1:contrail-control module connection to 10.0.0.242:5673 servers UP 2026-01-08 04:14:56,836 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-1:contrail-control module connection to ['10.0.0.242:8086'] servers UP 2026-01-08 04:14:56,837 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:14:56,860 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-2:contrail-control module connection to 10.0.0.242:9041 servers UP 2026-01-08 04:14:56,861 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-2:contrail-control module connection to 10.0.0.242:5673 servers UP 2026-01-08 04:14:56,861 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-2:contrail-control module connection to ['10.0.0.242:8086'] servers UP 2026-01-08 04:14:56,861 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4976-3?flat 2026-01-08 04:14:57,234 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-3:contrail-control module connection to 10.0.0.242:9041 servers UP 2026-01-08 04:14:57,235 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-3:contrail-control module connection to 10.0.0.242:5673 servers UP 2026-01-08 04:14:57,240 - INFO - cn-jenkins-deploy-platform-ansible-os-4976-3:contrail-control module connection to ['10.0.0.242:8086'] servers UP 2026-01-08 04:14:57,241 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4976-1.?flat 2026-01-08 04:14:57,271 - DEBUG - contrail-api is running 2026-01-08 04:14:57,271 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4976-2.?flat 2026-01-08 04:14:57,296 - DEBUG - contrail-api is running 2026-01-08 04:14:57,296 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4976-3.?flat 2026-01-08 04:14:57,324 - DEBUG - contrail-api is running 2026-01-08 04:14:57,651 - INFO - Created VN ctest-vn3-57814506, UUID :b2c4637d-c0c2-4a63-bfbf-3b88442a2351 2026-01-08 04:14:58,084 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:14:58,116 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:14:58,131 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:14:58,237 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,267 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,278 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:14:58,289 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:14:58,299 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/dcf54a2f-ef13-4fe8-8223-20707fbc5efa 2026-01-08 04:14:58,312 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:14:58,313 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,324 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:14:58,341 - INFO - Verified VN network id 13 for VN 3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,341 - INFO - Verifications in API Server for VN ctest-vn1-01848672 passed 2026-01-08 04:14:58,341 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,355 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:14:58,364 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:14:58,372 - DEBUG - Requesting: http://10.0.0.242:8082/route-target/dcf54a2f-ef13-4fe8-8223-20707fbc5efa 2026-01-08 04:14:58,388 - DEBUG - Control-node 10.0.0.242 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '0', 'advertised': '0', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:07.906942'} 2026-01-08 04:14:58,394 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:14:58,400 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:02.497360'} 2026-01-08 04:14:58,408 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:14:58,415 - DEBUG - Control-node 10.0.0.27 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-28338633', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '4149174900985841324', 'uuid-lslong': '13071900466417890264'}, 'enable': 'true', 'created': '2026-01-08T04:12:02', 'last-modified': '2026-01-08T04:12:03', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:56.795967'} 2026-01-08 04:14:58,422 - DEBUG - Route Targets: ['target:64512:8000004'] 2026-01-08 04:14:58,422 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-01848672 passed 2026-01-08 04:14:58,423 - DEBUG - ====Verifying policy data for ctest-vn1-01848672 in API_Server ====== 2026-01-08 04:14:58,423 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:14:58,430 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:14:58,443 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:14:58,546 - DEBUG - Requesting: http://10.0.0.242:8082/virtual-network/3994d496-d43a-46ac-b568-b8376019f3d8 2026-01-08 04:14:58,560 - DEBUG - ==>Verifying data for policy with id: 86180606-53b4-4305-806c-fd4d2414aeb9, fqn: ['default-domain', 'ctest-TestBasicVMVN0-28338633', 'policy1'] 2026-01-08 04:14:58,560 - INFO - VN ctest-vn1-01848672 Policy verification: verify_vn_policy_in_api_server, status: True 2026-01-08 04:14:58,560 - DEBUG - Verifying the vn in opserver 2026-01-08 04:14:58,560 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.242 2026-01-08 04:14:58,560 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-networks 2026-01-08 04:14:58,576 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:14:58,576 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.50 2026-01-08 04:14:58,576 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2026-01-08 04:14:58,653 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:14:58,653 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 virtual network link through opserver 10.0.0.27 2026-01-08 04:14:58,653 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-networks 2026-01-08 04:14:58,727 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat'} 2026-01-08 04:14:58,727 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is found in opserver 2026-01-08 04:14:58,749 - DEBUG - VRF ids for VN ctest-vn1-01848672: {'10.0.0.56': '2'} 2026-01-08 04:15:00,100 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-2) 2026-01-08 04:15:00,163 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-08 04:15:05,252 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:15:05,253 - INFO - VM name : ctest-vn1_vm2-01978855 2026-01-08 04:15:05,341 - DEBUG - VM ctest-vn1_vm2-01978855 ID is 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:05,429 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:15:05,430 - DEBUG - VM ctest-vn1_vm2-01978855 launched on Node an-jenkins-deploy-platform-ansible-os-4976-2 2026-01-08 04:15:05,510 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:05,548 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:05,555 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/94b903af-550d-49e7-aefe-5d9235ab3e09 2026-01-08 04:15:05,565 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:05,572 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/94b903af-550d-49e7-aefe-5d9235ab3e09 2026-01-08 04:15:05,585 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/49961336-d2e1-4f18-81ad-6391c2113249 2026-01-08 04:15:05,596 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:15:05,596 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:05,605 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/94b903af-550d-49e7-aefe-5d9235ab3e09 2026-01-08 04:15:05,615 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/49961336-d2e1-4f18-81ad-6391c2113249 2026-01-08 04:15:05,622 - INFO - VM ctest-vn1_vm2-01978855 verfication in all API Servers passed 2026-01-08 04:15:05,646 - DEBUG - VM ctest-vn1_vm2-01978855 Tap interface: {'index': '4', 'name': 'tap94b903af-55', 'uuid': '94b903af-550d-49e7-aefe-5d9235ab3e09', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672:ctest-vn1-01848672', '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-28338633:ctest-vn1-01848672', 'vm_uuid': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'vm_name': 'ctest-vn1_vm2-01978855', 'ip_addr': '192.168.1.251', 'mac_addr': '02:94:b9:03:af:55', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '169', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '25', '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': []} 2026-01-08 04:15:05,646 - DEBUG - Agent 10.0.0.56 vrf name: default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672:ctest-vn1-01848672 2026-01-08 04:15:05,653 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672:ctest-vn1-01848672', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.192:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2026-01-08 04:15:05,740 - DEBUG - VM ctest-vn1_vm2-01978855 : Tap interface tap94b903af-55 is set to Active 2026-01-08 04:15:05,741 - DEBUG - Tap interface tap94b903af-55 detail : {'index': '4', 'name': 'tap94b903af-55', 'uuid': '94b903af-550d-49e7-aefe-5d9235ab3e09', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672:ctest-vn1-01848672', '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-28338633:ctest-vn1-01848672', 'vm_uuid': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'vm_name': 'ctest-vn1_vm2-01978855', 'ip_addr': '192.168.1.251', 'mac_addr': '02:94:b9:03:af:55', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '169', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '25', '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': []} 2026-01-08 04:15:05,856 - DEBUG - Starting Layer 2 verification in Agent 2026-01-08 04:15:05,870 - DEBUG - Layer 2 path is seen for VM MAC 02:94:b9:03:af:55 in agent 10.0.0.56 2026-01-08 04:15:05,871 - DEBUG - Active layer 2 route in agent is present for VMI tap94b903af-55 2026-01-08 04:15:05,871 - DEBUG - L2 label(34) matches bw route table and interface table 2026-01-08 04:15:05,884 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is found in Agent of node 10.0.0.56 2026-01-08 04:15:06,024 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is consistent in agent 10.0.0.56 2026-01-08 04:15:06,024 - DEBUG - Route for VM IP ['192.168.1.251'] is consistent in agent 10.0.0.56 2026-01-08 04:15:06,024 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 verification for VM ctest-vn1_vm2-01978855 in Agent 10.0.0.56 passed 2026-01-08 04:15:06,156 - DEBUG - Starting all layer 2 verification in agent 10.0.0.56 2026-01-08 04:15:06,171 - DEBUG - Route for VM MAC 02:94:b9:03:af:55 is consistent in agent 10.0.0.56 2026-01-08 04:15:09,357 - 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 1005ms') 2026-01-08 04:15:09,358 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:09,371 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:13,454 - 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') 2026-01-08 04:15:13,454 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:13,470 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:17,539 - 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') 2026-01-08 04:15:17,539 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:17,554 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:21,641 - 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 1022ms') 2026-01-08 04:15:21,641 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:21,657 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:25,734 - 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') 2026-01-08 04:15:25,734 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:25,748 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:29,839 - 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 1022ms') 2026-01-08 04:15:29,839 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:29,856 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:33,927 - 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') 2026-01-08 04:15:33,927 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:33,943 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:38,020 - 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') 2026-01-08 04:15:38,020 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 failed! 2026-01-08 04:15:38,033 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 is 192.168.1.254 and allocation pool is NOT set 2026-01-08 04:15:42,117 - 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=2 ttl=63 time=6.41 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1026ms\r\nrtt min/avg/max/mdev = 6.407/6.407/6.407/0.000 ms') 2026-01-08 04:15:42,117 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 passed 2026-01-08 04:15:42,118 - INFO - VM ctest-vn1_vm2-01978855 verifications in Compute nodes passed 2026-01-08 04:15:42,354 - DEBUG - Validated VM route 192.168.1.251 in vrouter of 10.0.0.56 2026-01-08 04:15:42,361 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2026-01-08 04:15:42,361 - INFO - Validated routes of VM ctest-vn1_vm2-01978855 in all vrouters 2026-01-08 04:15:42,791 - DEBUG - Starting all layer2 verification in 10.0.0.242 Control Node 2026-01-08 04:15:42,918 - DEBUG - Layer2 route found for VM MAC 02:94:b9:03:af:55 in Control-node 10.0.0.242 2026-01-08 04:15:42,918 - DEBUG - L2 Label for VM ctest-vn1_vm2-01978855 same between Control-node 10.0.0.242 and Agent, Expected: 34, Seen: 34 2026-01-08 04:15:42,918 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2026-01-08 04:15:43,050 - DEBUG - Layer2 route found for VM MAC 02:94:b9:03:af:55 in Control-node 10.0.0.50 2026-01-08 04:15:43,050 - DEBUG - L2 Label for VM ctest-vn1_vm2-01978855 same between Control-node 10.0.0.50 and Agent, Expected: 34, Seen: 34 2026-01-08 04:15:43,050 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node 2026-01-08 04:15:43,180 - DEBUG - Layer2 route found for VM MAC 02:94:b9:03:af:55 in Control-node 10.0.0.27 2026-01-08 04:15:43,180 - DEBUG - L2 Label for VM ctest-vn1_vm2-01978855 same between Control-node 10.0.0.27 and Agent, Expected: 34, Seen: 34 2026-01-08 04:15:43,180 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-01978855 passed 2026-01-08 04:15:43,181 - DEBUG - Verifying the vm in opserver 2026-01-08 04:15:43,181 - DEBUG - Verifying in collector 10.0.0.27 ... 2026-01-08 04:15:43,181 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat 2026-01-08 04:15:43,271 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09?flat 2026-01-08 04:15:43,292 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09?flat 2026-01-08 04:15:43,312 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat 2026-01-08 04:15:43,395 - DEBUG - Verifying vm in vn uve 2026-01-08 04:15:43,395 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09?flat 2026-01-08 04:15:43,416 - DEBUG - VM uve shows interface as {'virtual_network': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672', 'ip_address': '192.168.1.251', 'vhostuser_mode': 0, 'vn_uuid': '3994d496-d43a-46ac-b568-b8376019f3d8', 'vm_name': 'ctest-vn1_vm2-01978855', 'mac_address': '02:94:b9:03:af:55', 'rx_vlan': 65535, 'gateway': '192.168.1.254', 'uuid': '94b903af-550d-49e7-aefe-5d9235ab3e09', 'tx_vlan': 65535, 'label': 30, 'admin_state': True, 'active': True, 'ip4_active': True, 'is_health_check_active': True, 'fixed_ip4_list': ['192.168.1.251'], 'ip6_active': False, 'port_mirror_enabled': False, 'l2_active': True, '__T': 1767845714856516, 'vm_uuid': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'ip6_address': '::'} 2026-01-08 04:15:43,416 - DEBUG - VM uve shows ip address as ['192.168.1.251', '::'] 2026-01-08 04:15:43,416 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:15:43,416 - INFO - Verifying through opserver in 10.0.0.242 2026-01-08 04:15:43,416 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat 2026-01-08 04:15:43,443 - DEBUG - expected vm list 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:15:43,443 - DEBUG - Extracted vm list ['3ccd4e7c-8b0d-45ad-ac7e-e9415f760549'] 2026-01-08 04:15:43,443 - INFO - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is present in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:15:43,443 - DEBUG - Verifying vm in vrouter uve 2026-01-08 04:15:43,443 - DEBUG - Getting info from collector 10.0.0.27.. 2026-01-08 04:15:43,443 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat 2026-01-08 04:15:43,459 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4976-2'] 2026-01-08 04:15:43,459 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:15:43,500 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:15:43,596 - DEBUG - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:15:43,596 - DEBUG - Validated that VM ctest-vn1_vm2-01978855 is in Vrouter an-jenkins-deploy-platform-ansible-os-4976-2 UVE 2026-01-08 04:15:43,596 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2026-01-08 04:15:43,606 - DEBUG - Expected tap interface of VM uuid 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09 2026-01-08 04:15:43,606 - DEBUG - Expected VN of VM uuid 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:15:43,606 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:15:43,644 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:15:43,725 - DEBUG - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:15:43,725 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-28338633:94b903af-550d-49e7-aefe-5d9235ab3e09 of vm 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:15:43,725 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 of vm 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:15:43,725 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.242 2026-01-08 04:15:43,726 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:15:43,739 - DEBUG - VM link and name as {'name': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat'} 2026-01-08 04:15:43,739 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.50 2026-01-08 04:15:43,739 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:15:43,751 - DEBUG - VM link and name as {'name': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat'} 2026-01-08 04:15:43,751 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.27 2026-01-08 04:15:43,751 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:15:43,766 - DEBUG - VM link and name as {'name': '3ccd4e7c-8b0d-45ad-ac7e-e9415f760549', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549?flat'} 2026-01-08 04:15:43,766 - INFO - VM ctest-vn1_vm2-01978855 validations in Opserver passed 2026-01-08 04:15:45,164 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4976-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4976-1) 2026-01-08 04:15:45,208 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-01-08 04:15:50,333 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:15:50,333 - INFO - VM name : ctest-vn2_vm2-03356912 2026-01-08 04:15:50,430 - DEBUG - VM ctest-vn2_vm2-03356912 ID is c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:15:50,542 - DEBUG - VM is in ACTIVE state now 2026-01-08 04:15:50,542 - DEBUG - VM ctest-vn2_vm2-03356912 launched on Node an-jenkins-deploy-platform-ansible-os-4976-1 2026-01-08 04:15:50,652 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:15:50,663 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:15:50,671 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/6acf28ac-8481-449e-9441-0856a8872753 2026-01-08 04:15:50,681 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:15:50,690 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/6acf28ac-8481-449e-9441-0856a8872753 2026-01-08 04:15:50,701 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/ef2e1f7a-b7f3-4e5a-b27f-f6c8a135d2a7 2026-01-08 04:15:50,713 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:15:50,713 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:15:50,720 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/6acf28ac-8481-449e-9441-0856a8872753 2026-01-08 04:15:50,729 - DEBUG - Requesting: http://10.0.0.27:8082/instance-ip/ef2e1f7a-b7f3-4e5a-b27f-f6c8a135d2a7 2026-01-08 04:15:50,738 - INFO - VM ctest-vn2_vm2-03356912 verfication in all API Servers passed 2026-01-08 04:15:50,761 - DEBUG - VM ctest-vn2_vm2-03356912 Tap interface: {'index': '4', 'name': 'tap6acf28ac-84', 'uuid': '6acf28ac-8481-449e-9441-0856a8872753', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861:ctest-vn2-09734861', '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': '14', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'vm_uuid': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'vm_name': 'ctest-vn2_vm2-03356912', 'ip_addr': '192.168.2.251', 'mac_addr': '02:6a:cf:28:ac:84', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '127', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '28', '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': []} 2026-01-08 04:15:50,761 - DEBUG - Agent 10.0.0.57 vrf name: default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861:ctest-vn2-09734861 2026-01-08 04:15:50,771 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861:ctest-vn2-09734861', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'table_label': '-1', 'vxlan_id': '14', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.129:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2026-01-08 04:15:50,859 - DEBUG - VM ctest-vn2_vm2-03356912 : Tap interface tap6acf28ac-84 is set to Active 2026-01-08 04:15:50,859 - DEBUG - Tap interface tap6acf28ac-84 detail : {'index': '4', 'name': 'tap6acf28ac-84', 'uuid': '6acf28ac-8481-449e-9441-0856a8872753', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861:ctest-vn2-09734861', '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': '14', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'vm_uuid': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'vm_name': 'ctest-vn2_vm2-03356912', 'ip_addr': '192.168.2.251', 'mac_addr': '02:6a:cf:28:ac:84', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '127', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753', 'sg_uuid_list': ['d75b8255-b8a7-4d57-a0b6-01d922cb00ca'], 'static_route_list': None, 'vm_project_uuid': '37b535a1-897e-41de-bc03-b246e39c9243', 'admin_state': 'Enabled', 'flow_key_idx': '28', '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': []} 2026-01-08 04:15:50,972 - DEBUG - Starting Layer 2 verification in Agent 2026-01-08 04:15:50,988 - DEBUG - Layer 2 path is seen for VM MAC 02:6a:cf:28:ac:84 in agent 10.0.0.57 2026-01-08 04:15:50,988 - DEBUG - Active layer 2 route in agent is present for VMI tap6acf28ac-84 2026-01-08 04:15:50,988 - DEBUG - L2 label(34) matches bw route table and interface table 2026-01-08 04:15:50,997 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is found in Agent of node 10.0.0.57 2026-01-08 04:15:51,143 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is consistent in agent 10.0.0.57 2026-01-08 04:15:51,144 - DEBUG - Route for VM IP ['192.168.2.251'] is consistent in agent 10.0.0.57 2026-01-08 04:15:51,144 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 verification for VM ctest-vn2_vm2-03356912 in Agent 10.0.0.57 passed 2026-01-08 04:15:51,257 - DEBUG - Starting all layer 2 verification in agent 10.0.0.57 2026-01-08 04:15:51,271 - DEBUG - Route for VM MAC 02:6a:cf:28:ac:84 is consistent in agent 10.0.0.57 2026-01-08 04:15:54,498 - 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 1035ms') 2026-01-08 04:15:54,498 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:15:54,514 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:15:58,590 - 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 1008ms') 2026-01-08 04:15:58,591 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:15:58,609 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:02,681 - 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') 2026-01-08 04:16:02,681 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:02,704 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:06,779 - 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') 2026-01-08 04:16:06,779 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:06,799 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:10,879 - 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') 2026-01-08 04:16:10,879 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:10,896 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:14,974 - 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') 2026-01-08 04:16:14,974 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:14,991 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:19,068 - 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') 2026-01-08 04:16:19,068 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:19,082 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:23,166 - 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') 2026-01-08 04:16:23,166 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:23,180 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:27,263 - 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') 2026-01-08 04:16:27,263 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 failed! 2026-01-08 04:16:27,276 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 is 192.168.2.254 and allocation pool is NOT set 2026-01-08 04:16:29,342 - 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=8.73 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.59 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.586/5.158/8.731/3.572 ms') 2026-01-08 04:16:29,342 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 passed 2026-01-08 04:16:29,343 - INFO - VM ctest-vn2_vm2-03356912 verifications in Compute nodes passed 2026-01-08 04:16:29,569 - DEBUG - Validated VM route 192.168.2.251 in vrouter of 10.0.0.57 2026-01-08 04:16:29,574 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2026-01-08 04:16:29,574 - INFO - Validated routes of VM ctest-vn2_vm2-03356912 in all vrouters 2026-01-08 04:16:30,024 - DEBUG - Starting all layer2 verification in 10.0.0.242 Control Node 2026-01-08 04:16:30,148 - DEBUG - Layer2 route found for VM MAC 02:6a:cf:28:ac:84 in Control-node 10.0.0.242 2026-01-08 04:16:30,148 - DEBUG - L2 Label for VM ctest-vn2_vm2-03356912 same between Control-node 10.0.0.242 and Agent, Expected: 34, Seen: 34 2026-01-08 04:16:30,148 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2026-01-08 04:16:30,279 - DEBUG - Layer2 route found for VM MAC 02:6a:cf:28:ac:84 in Control-node 10.0.0.50 2026-01-08 04:16:30,279 - DEBUG - L2 Label for VM ctest-vn2_vm2-03356912 same between Control-node 10.0.0.50 and Agent, Expected: 34, Seen: 34 2026-01-08 04:16:30,279 - DEBUG - Starting all layer2 verification in 10.0.0.27 Control Node 2026-01-08 04:16:30,414 - DEBUG - Layer2 route found for VM MAC 02:6a:cf:28:ac:84 in Control-node 10.0.0.27 2026-01-08 04:16:30,415 - DEBUG - L2 Label for VM ctest-vn2_vm2-03356912 same between Control-node 10.0.0.27 and Agent, Expected: 34, Seen: 34 2026-01-08 04:16:30,415 - INFO - Verification in Control-nodes for VM ctest-vn2_vm2-03356912 passed 2026-01-08 04:16:30,415 - DEBUG - Verifying the vm in opserver 2026-01-08 04:16:30,415 - DEBUG - Verifying in collector 10.0.0.27 ... 2026-01-08 04:16:30,415 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat 2026-01-08 04:16:30,432 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753?flat 2026-01-08 04:16:30,455 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753?flat 2026-01-08 04:16:30,478 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat 2026-01-08 04:16:30,497 - DEBUG - Verifying vm in vn uve 2026-01-08 04:16:30,498 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753?flat 2026-01-08 04:16:30,519 - DEBUG - VM uve shows interface as {'port_mirror_enabled': False, 'active': True, 'is_health_check_active': True, 'tx_vlan': 65535, 'l2_active': True, 'label': 30, 'vm_name': 'ctest-vn2_vm2-03356912', 'ip6_address': '::', 'vn_uuid': '5f93f8d1-51cd-493b-a970-0e3ab83f1377', 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861', 'mac_address': '02:6a:cf:28:ac:84', 'vhostuser_mode': 0, '__T': 1767845766453063, 'vm_uuid': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'rx_vlan': 65535, 'gateway': '192.168.2.254', 'ip4_active': True, 'ip6_active': False, 'admin_state': True, 'ip_address': '192.168.2.251', 'fixed_ip4_list': ['192.168.2.251'], 'uuid': '6acf28ac-8481-449e-9441-0856a8872753'} 2026-01-08 04:16:30,519 - DEBUG - VM uve shows ip address as ['192.168.2.251', '::'] 2026-01-08 04:16:30,519 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:16:30,519 - INFO - Verifying through opserver in 10.0.0.242 2026-01-08 04:16:30,520 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861?flat 2026-01-08 04:16:30,550 - DEBUG - expected vm list c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:16:30,551 - DEBUG - Extracted vm list ['c99ba16c-34aa-4cc1-9925-d5b22a96d930'] 2026-01-08 04:16:30,551 - INFO - VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is present in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:16:30,551 - DEBUG - Verifying vm in vrouter uve 2026-01-08 04:16:30,551 - DEBUG - Getting info from collector 10.0.0.27.. 2026-01-08 04:16:30,551 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat 2026-01-08 04:16:30,568 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4976-1'] 2026-01-08 04:16:30,568 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:16:30,637 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:16:30,674 - DEBUG - VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:16:30,674 - DEBUG - Validated that VM ctest-vn2_vm2-03356912 is in Vrouter an-jenkins-deploy-platform-ansible-os-4976-1 UVE 2026-01-08 04:16:30,674 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2026-01-08 04:16:30,686 - DEBUG - Expected tap interface of VM uuid c99ba16c-34aa-4cc1-9925-d5b22a96d930 is default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753 2026-01-08 04:16:30,686 - DEBUG - Expected VN of VM uuid c99ba16c-34aa-4cc1-9925-d5b22a96d930 is default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:16:30,686 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:16:30,736 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:16:30,781 - DEBUG - VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:16:30,781 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-28338633:6acf28ac-8481-449e-9441-0856a8872753 of vm c99ba16c-34aa-4cc1-9925-d5b22a96d930 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:16:30,781 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 of vm c99ba16c-34aa-4cc1-9925-d5b22a96d930 is present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:16:30,782 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.242 2026-01-08 04:16:30,782 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:16:30,796 - DEBUG - VM link and name as {'name': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'href': 'http://10.0.0.242:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat'} 2026-01-08 04:16:30,796 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.50 2026-01-08 04:16:30,796 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:16:30,809 - DEBUG - VM link and name as {'name': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat'} 2026-01-08 04:16:30,809 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.27 2026-01-08 04:16:30,809 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:16:30,822 - DEBUG - VM link and name as {'name': 'c99ba16c-34aa-4cc1-9925-d5b22a96d930', 'href': 'http://10.0.0.27:8081/analytics/uves/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930?flat'} 2026-01-08 04:16:30,822 - INFO - VM ctest-vn2_vm2-03356912 validations in Opserver passed 2026-01-08 04:16:30,823 - INFO - Waiting for VM ctest-vn1_vm2-01978855 to be up.. 2026-01-08 04:16:30,823 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:30,823 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:16:30,831 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/94b903af-550d-49e7-aefe-5d9235ab3e09 2026-01-08 04:16:31,999 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=3.47 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.440 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.440/1.954/3.468/1.514 ms') 2026-01-08 04:16:31,999 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-01978855 passed 2026-01-08 04:16:32,072 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:32,072 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-01978855, IP 192.168.1.251, Port 22 2026-01-08 04:16:32,248 - DEBUG - VM ctest-vn1_vm2-01978855 is ready for SSH connections 2026-01-08 04:16:32,248 - INFO - Waiting for VM ctest-vn2_vm2-03356912 to be up.. 2026-01-08 04:16:32,248 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:32,249 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:16:32,258 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine-interface/6acf28ac-8481-449e-9441-0856a8872753 2026-01-08 04:16:33,429 - 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.60 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.603 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.603/1.603/2.604/1.000 ms') 2026-01-08 04:16:33,429 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-03356912 passed 2026-01-08 04:16:33,495 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:33,495 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-03356912, IP 192.168.2.251, Port 22 2026-01-08 04:16:33,565 - 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': ''} 2026-01-08 04:16:33,663 - DEBUG - VM ctest-vn2_vm2-03356912 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:16:38,664 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:38,664 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-03356912, IP 192.168.2.251, Port 22 2026-01-08 04:16:38,732 - 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': ''} 2026-01-08 04:16:38,822 - DEBUG - VM ctest-vn2_vm2-03356912 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:16:43,822 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:43,823 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-03356912, IP 192.168.2.251, Port 22 2026-01-08 04:16:43,892 - 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': ''} 2026-01-08 04:16:43,993 - DEBUG - VM ctest-vn2_vm2-03356912 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:16:48,994 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:48,995 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-03356912, IP 192.168.2.251, Port 22 2026-01-08 04:16:49,054 - 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': ''} 2026-01-08 04:16:49,143 - DEBUG - VM ctest-vn2_vm2-03356912 is NOT ready for SSH connections, VM status: ACTIVE 2026-01-08 04:16:54,144 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:54,144 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-03356912, IP 192.168.2.251, Port 22 2026-01-08 04:16:54,317 - DEBUG - VM ctest-vn2_vm2-03356912 is ready for SSH connections 2026-01-08 04:16:54,318 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-01-08 04:16:54,318 - 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 2026-01-08 04:16:54,318 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.251 2026-01-08 04:17:35,712 - 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=10.1 ms 64 bytes from 192.168.2.251: icmp_req=2 ttl=63 time=1.42 ms 64 bytes from 192.168.2.251: icmp_req=3 ttl=63 time=1.21 ms --- 192.168.2.251 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2002ms rtt min/avg/max/mdev = 1.216/4.258/10.134/4.155 ms 2026-01-08 04:17:35,712 - INFO - Ping to IP 192.168.2.251 from VM ctest-vn1_vm2-01978855 passed 2026-01-08 04:17:35,712 - INFO - Deleting VM ctest-vn2_vm2-03356912 2026-01-08 04:17:35,784 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:17:35,784 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:17:35,793 - DEBUG - VM ID c99ba16c-34aa-4cc1-9925-d5b22a96d930 of VM ctest-vn2_vm2-03356912 is still found in API Server 2026-01-08 04:17:37,794 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:17:37,794 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:17:37,803 - DEBUG - Response Code: 404 2026-01-08 04:17:37,803 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:17:37,868 - DEBUG - Response Code: 404 2026-01-08 04:17:37,869 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/c99ba16c-34aa-4cc1-9925-d5b22a96d930 2026-01-08 04:17:37,876 - DEBUG - Response Code: 404 2026-01-08 04:17:37,876 - INFO - VM ctest-vn2_vm2-03356912 is fully removed in API-Server 2026-01-08 04:17:38,032 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2026-01-08 04:17:38,195 - DEBUG - VM route 192.168.2.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 of compute 10.0.0.57 2026-01-08 04:17:38,200 - DEBUG - Validated that vrouter 10.0.0.57 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:17:38,200 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:17:38,200 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 2026-01-08 04:17:38,200 - INFO - VM ctest-vn2_vm2-03356912 is removed in Compute, and routes are removed in all compute nodes 2026-01-08 04:17:38,418 - INFO - Routes for VM ctest-vn2_vm2-03356912 is removed in all control-nodes 2026-01-08 04:17:38,418 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-1:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:17:38,467 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-1?flat 2026-01-08 04:17:38,497 - DEBUG - VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4976-1 uve 2026-01-08 04:17:38,498 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:17:38,498 - DEBUG - interface for vm c99ba16c-34aa-4cc1-9925-d5b22a96d930 deleted from vrouter uve ... 2026-01-08 04:17:38,498 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:17:38,498 - DEBUG - Validated that VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is removed in Vrouter UVE 2026-01-08 04:17:38,498 - DEBUG - Verifying through opserver in 10.0.0.242 2026-01-08 04:17:38,498 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861?flat 2026-01-08 04:17:38,521 - DEBUG - c99ba16c-34aa-4cc1-9925-d5b22a96d930 BM not in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn2-09734861 uve 2026-01-08 04:17:38,521 - DEBUG - Validated that VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is not present in the VN UVE 2026-01-08 04:17:38,521 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.242 2026-01-08 04:17:38,521 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:17:38,536 - INFO - c99ba16c-34aa-4cc1-9925-d5b22a96d930 vm uve deleted from opserver 2026-01-08 04:17:38,536 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.50 2026-01-08 04:17:38,536 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:17:38,551 - INFO - c99ba16c-34aa-4cc1-9925-d5b22a96d930 vm uve deleted from opserver 2026-01-08 04:17:38,551 - DEBUG - Verifying the c99ba16c-34aa-4cc1-9925-d5b22a96d930 virtual network link through opserver 10.0.0.27 2026-01-08 04:17:38,551 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:17:38,563 - INFO - c99ba16c-34aa-4cc1-9925-d5b22a96d930 vm uve deleted from opserver 2026-01-08 04:17:38,564 - INFO - Validated that VM c99ba16c-34aa-4cc1-9925-d5b22a96d930 is removed from Opserver 2026-01-08 04:17:38,564 - INFO - Deleting VM ctest-vn1_vm2-01978855 2026-01-08 04:17:38,634 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:17:38,634 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:17:38,644 - DEBUG - VM ID 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 of VM ctest-vn1_vm2-01978855 is still found in API Server 2026-01-08 04:17:40,645 - DEBUG - Verifying in api server 10.0.0.27 2026-01-08 04:17:40,645 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:17:40,652 - DEBUG - Response Code: 404 2026-01-08 04:17:40,653 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:17:40,659 - DEBUG - Response Code: 404 2026-01-08 04:17:40,659 - DEBUG - Requesting: http://10.0.0.27:8082/virtual-machine/3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 2026-01-08 04:17:40,666 - DEBUG - Response Code: 404 2026-01-08 04:17:40,666 - INFO - VM ctest-vn1_vm2-01978855 is fully removed in API-Server 2026-01-08 04:17:40,818 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2026-01-08 04:17:40,852 - DEBUG - Validated that vrouter 10.0.0.57 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:17:40,993 - DEBUG - VM route 192.168.1.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 of compute 10.0.0.56 2026-01-08 04:17:41,002 - DEBUG - Validated that vrouter 10.0.0.56 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:17:41,002 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:17:41,002 - INFO - VM ctest-vn1_vm2-01978855 is removed in Compute, and routes are removed in all compute nodes 2026-01-08 04:17:41,232 - INFO - Routes for VM ctest-vn1_vm2-01978855 is removed in all control-nodes 2026-01-08 04:17:41,232 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:17:41,275 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:17:41,307 - DEBUG - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:17:41,307 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:17:41,307 - DEBUG - interface for vm 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 deleted from vrouter uve ... 2026-01-08 04:17:41,307 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:17:44,308 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:17:44,341 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:17:44,371 - DEBUG - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:17:44,371 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:17:44,371 - DEBUG - interface for vm 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 deleted from vrouter uve ... 2026-01-08 04:17:44,371 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:17:47,373 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4976-2:Compute:contrail-vrouter-agent:0?flat 2026-01-08 04:17:47,406 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4976-2?flat 2026-01-08 04:17:47,435 - DEBUG - VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4976-2 uve 2026-01-08 04:17:47,435 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2026-01-08 04:17:47,435 - DEBUG - interface for vm 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 deleted from vrouter uve ... 2026-01-08 04:17:47,435 - DEBUG - Deleted interface not in error interface list ... 2026-01-08 04:17:47,435 - DEBUG - Validated that VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is removed in Vrouter UVE 2026-01-08 04:17:47,435 - DEBUG - Verifying through opserver in 10.0.0.242 2026-01-08 04:17:47,435 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672?flat 2026-01-08 04:17:47,457 - DEBUG - 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 BM not in default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 uve 2026-01-08 04:17:47,457 - DEBUG - Validated that VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is not present in the VN UVE 2026-01-08 04:17:47,458 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.242 2026-01-08 04:17:47,458 - DEBUG - Requesting: http://10.0.0.242:8081/analytics/uves/virtual-machines 2026-01-08 04:17:47,469 - INFO - 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 vm uve deleted from opserver 2026-01-08 04:17:47,469 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.50 2026-01-08 04:17:47,469 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2026-01-08 04:17:47,484 - INFO - 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 vm uve deleted from opserver 2026-01-08 04:17:47,484 - DEBUG - Verifying the 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 virtual network link through opserver 10.0.0.27 2026-01-08 04:17:47,484 - DEBUG - Requesting: http://10.0.0.27:8081/analytics/uves/virtual-machines 2026-01-08 04:17:47,498 - INFO - 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 vm uve deleted from opserver 2026-01-08 04:17:47,498 - INFO - Validated that VM 3ccd4e7c-8b0d-45ad-ac7e-e9415f760549 is removed from Opserver 2026-01-08 04:17:47,498 - INFO - Deleting VN ctest-vn3-57814506 2026-01-08 04:17:47,612 - INFO - Deleting VM ctest-vn2_vm1-37544786 2026-01-08 04:17:47,705 - INFO - Deleting VM ctest-vn1_vm1-07589933 2026-01-08 04:17:47,930 - INFO - Deleting VN ctest-vn2-09734861 2026-01-08 04:17:47,999 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.27:8082/virtual-machine-interface/0988c2b3-d5cc-4d80-b225-0692521c218d'] while deleting VN ctest-vn2-09734861..Will retry 2026-01-08 04:17:50,115 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/949bc08f-b529-40db-a990-ea43fe3202b8 2026-01-08 04:17:50,120 - DEBUG - Response Code: 404 2026-01-08 04:17:50,121 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:17:50,130 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:17:50,141 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:17:50,232 - INFO - Validated that VN ctest-vn2-09734861 is not found in API Server 2026-01-08 04:17:50,245 - DEBUG - VN ctest-vn2-09734861 is not present in Agent 10.0.0.57 2026-01-08 04:17:50,259 - DEBUG - VN ctest-vn2-09734861 is not present in Agent 10.0.0.56 2026-01-08 04:17:50,259 - INFO - Validated that VN ctest-vn2-09734861 is not in any agent 2026-01-08 04:17:50,296 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-09734861 info 2026-01-08 04:17:50,442 - INFO - Deleting VN ctest-vn1-01848672 2026-01-08 04:17:50,579 - DEBUG - Requesting: http://10.0.0.242:8082/routing-instance/2631ccc0-6bbb-4af2-8737-fe59de17237a 2026-01-08 04:17:50,585 - DEBUG - Response Code: 404 2026-01-08 04:17:50,585 - DEBUG - Requesting: http://10.0.0.242:8082/domains 2026-01-08 04:17:50,602 - DEBUG - Requesting: http://10.0.0.242:8082/domain/01640a83-288f-426f-a2f2-0c0b4b93ac50 2026-01-08 04:17:50,621 - DEBUG - Requesting: http://10.0.0.242:8082/project/37b535a1-897e-41de-bc03-b246e39c9243 2026-01-08 04:17:50,711 - INFO - Validated that VN ctest-vn1-01848672 is not found in API Server 2026-01-08 04:17:50,721 - DEBUG - VN ctest-vn1-01848672 is not present in Agent 10.0.0.57 2026-01-08 04:17:50,730 - DEBUG - VN ctest-vn1-01848672 is not present in Agent 10.0.0.56 2026-01-08 04:17:50,730 - INFO - Validated that VN ctest-vn1-01848672 is not in any agent 2026-01-08 04:17:50,735 - DEBUG - VRF 2 is not seen in agent 10.0.0.56 2026-01-08 04:17:50,741 - DEBUG - Vrouter 10.0.0.56 does not have vrf 2 for VN ctest-vn1-01848672 2026-01-08 04:17:50,741 - INFO - Validated that all vrouters do not have the route table for VN default-domain:ctest-TestBasicVMVN0-28338633:ctest-vn1-01848672 2026-01-08 04:17:50,761 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-01848672 info 2026-01-08 04:17:50,798 - INFO - Deleted policy policy2 2026-01-08 04:17:50,842 - INFO - Deleted policy policy1 2026-01-08 04:17:52,112 - DEBUG - Skipping xmpp flap check
2026-01-08 04:17:52,112 - INFO - END TEST : test_process_restart_in_policy_between_vns : PASSED[0:05:52]
2026-01-08 04:17:52,113 - INFO - -------------------------------------------------------------------------------- 2026-01-08 04:17:52,115 - INFO - ================================================================================ 2026-01-08 04:17:52,115 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling 2026-01-08 04:17:52,115 - 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 2026-01-08 04:17:53,390 - DEBUG - Skipping xmpp flap check 2026-01-08 04:17:53,390 - INFO - Initial checks done. Running the testcase now 2026-01-08 04:17:53,390 - INFO - 2026-01-08 04:17:53,797 - INFO - Agent interface name: ens6 2026-01-08 04:17:53,882 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U host 10.20.0.255 -w /tmp/ens6_ctest-random-22871946.pcap 2026-01-08 04:17:58,972 - INFO - Pinging broacast address 10.20.0.255 from compute 10.20.0.129 2026-01-08 04:18:13,277 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2026-01-08 04:18:15,417 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-22871946.pcap | grep -c length 2026-01-08 04:18:15,433 - DEBUG - STDOUT: 10 2026-01-08 04:18:15,433 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-22871946.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2026-01-08 04:18:15,433 - INFO - 10 packets are found in tcpdump output as expected 2026-01-08 04:18:15,434 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2026-01-08 04:18:17,480 - INFO - Packet count matched: Compute 10.0.0.56 has receive only 10 packet from source IP 10.20.0.255. No duplicate packet seen 2026-01-08 04:18:18,772 - DEBUG - Skipping xmpp flap check
2026-01-08 04:18:18,772 - INFO - END TEST : test_underlay_broadcast_traffic_handling : PASSED[0:00:26]
2026-01-08 04:18:18,772 - INFO - -------------------------------------------------------------------------------- 2026-01-08 04:18:19,611 - INFO - Deleted project: ctest-TestBasicVMVN0-28338633, ID : 37b535a1-897e-41de-bc03-b246e39c9243