2025-08-15 11:31:15,081 - INFO - Domain Default found not creating 2025-08-15 11:31:15,221 - INFO - Project ctest-TestBasicVMVN0-91341447 not found, creating it 2025-08-15 11:31:15,700 - INFO - Created Project:ctest-TestBasicVMVN0-91341447, ID : b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:31:17,073 - INFO - ================================================================================ 2025-08-15 11:31:17,073 - INFO - STARTING TEST : test_control_node_switchover 2025-08-15 11:31:17,073 - INFO - TEST DESCRIPTION : Stop the control node and check peering with agent fallback to other control node. 1. Pick one VN from respource pool which has 2 VM's in it 2. Verify ping between VM's 3. Find active control node in cluster by agent inspect 4. Stop control service on active control node 5. Verify agents are connected to new active control-node using xmpp connections 6. Bring back control service on previous active node 7. Verify ping between VM's again after bringing up control serveice Pass criteria: Step 2,5 and 7 should pass 2025-08-15 11:31:18,319 - DEBUG - Skipping xmpp flap check 2025-08-15 11:31:18,319 - INFO - Initial checks done. Running the testcase now 2025-08-15 11:31:18,319 - INFO - 2025-08-15 11:31:18,969 - DEBUG - Response for create_network : {'network': {'id': '83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc', 'name': 'ctest-vn1-17847578', 'tenant_id': 'b284f49ec20a42ff98ed9106ec628dee', 'project_id': 'b284f49ec20a42ff98ed9106ec628dee', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-91341447', 'ctest-vn1-17847578'], 'port_security_enabled': True, 'description': ''}} 2025-08-15 11:31:19,205 - DEBUG - Response for create_subnet : {'subnet': {'id': '96e14eb4-1da3-4a47-9e20-c74681034da6', 'name': '', 'tenant_id': 'b284f49ec20a42ff98ed9106ec628dee', 'network_id': '83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc', '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': 'b284f49ec20a42ff98ed9106ec628dee'}} 2025-08-15 11:31:19,231 - INFO - Created VN ctest-vn1-17847578 2025-08-15 11:31:19,241 - DEBUG - VN ctest-vn1-17847578 UUID is 83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,309 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:31:19,632 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:31:19,662 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:31:19,677 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:31:19,777 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,789 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,797 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:31:19,805 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:31:19,811 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/110a5b48-aaea-499b-a367-a1373f531144 2025-08-15 11:31:19,817 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:31:19,817 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,837 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:31:19,854 - INFO - Verified VN network id 15 for VN 83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,854 - INFO - Verifications in API Server for VN ctest-vn1-17847578 passed 2025-08-15 11:31:19,854 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:19,864 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:31:19,873 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:31:19,880 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/110a5b48-aaea-499b-a367-a1373f531144 2025-08-15 11:31:19,891 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '9487325967713650140', 'uuid-lslong': '11509149792819431372'}, 'enable': 'true', 'created': '2025-08-15T11:31:18', 'last-modified': '2025-08-15T11:31:19', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.725560'} 2025-08-15 11:31:19,899 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:31:19,905 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '9487325967713650140', 'uuid-lslong': '11509149792819431372'}, 'enable': 'true', 'created': '2025-08-15T11:31:18', 'last-modified': '2025-08-15T11:31:19', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.740560'} 2025-08-15 11:31:19,912 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:31:19,918 - DEBUG - Control-node 10.0.0.19 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '9487325967713650140', 'uuid-lslong': '11509149792819431372'}, 'enable': 'true', 'created': '2025-08-15T11:31:18', 'last-modified': '2025-08-15T11:31:19', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.743911'} 2025-08-15 11:31:19,924 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:31:19,924 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-17847578 passed 2025-08-15 11:31:19,924 - DEBUG - ====Verifying policy data for ctest-vn1-17847578 in API_Server ====== 2025-08-15 11:31:19,924 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:31:19,930 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:31:19,945 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:31:20,053 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc 2025-08-15 11:31:20,063 - DEBUG - =>VN ctest-vn1-17847578 has no policy to be verified 2025-08-15 11:31:20,063 - DEBUG - Verifying the vn in opserver 2025-08-15 11:31:20,063 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 virtual network link through opserver 10.0.0.50 2025-08-15 11:31:20,063 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-08-15 11:31:20,360 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-08-15 11:31:20,412 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat'} 2025-08-15 11:31:20,412 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 virtual network link through opserver 10.0.0.22 2025-08-15 11:31:20,412 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-08-15 11:31:20,699 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-08-15 11:31:20,755 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat'} 2025-08-15 11:31:20,755 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 virtual network link through opserver 10.0.0.19 2025-08-15 11:31:20,755 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-networks 2025-08-15 11:31:21,051 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-networks 2025-08-15 11:31:21,108 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat'} 2025-08-15 11:31:21,108 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is found in opserver 2025-08-15 11:31:21,128 - DEBUG - Do not have enough data to verify VN in agent 2025-08-15 11:31:21,139 - DEBUG - VRF ids for VN ctest-vn1-17847578: {} 2025-08-15 11:31:21,184 - DEBUG - Services list from nova: [, , , ] 2025-08-15 11:31:22,183 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 11:31:23,377 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 11:31:23,378 - INFO - Waiting for VM ctest-vn1_vm1-23985696 to be up.. 2025-08-15 11:31:23,450 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 11:31:28,526 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:31:28,526 - INFO - VM name : ctest-vn1_vm1-23985696 2025-08-15 11:31:28,596 - DEBUG - VM ctest-vn1_vm1-23985696 ID is 0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:31:28,617 - DEBUG - VM ctest-vn1_vm1-23985696 launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 11:31:28,685 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:31:28,975 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:31:29,004 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/732d4bf0-5535-4cf2-81f0-e4e1c95c813b 2025-08-15 11:31:32,183 - 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 1025ms') 2025-08-15 11:31:32,183 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:32,195 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:36,282 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:31:36,282 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:36,294 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:40,368 - 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 1019ms') 2025-08-15 11:31:40,368 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:40,381 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:44,471 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms') 2025-08-15 11:31:44,471 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:44,484 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:48,563 - 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 1019ms') 2025-08-15 11:31:48,563 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:48,577 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:52,659 - 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 1019ms') 2025-08-15 11:31:52,659 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:52,672 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:31:56,755 - 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 1019ms') 2025-08-15 11:31:56,755 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 failed! 2025-08-15 11:31:56,768 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is 192.168.1.1 and allocation pool is NOT set 2025-08-15 11:32:00,849 - 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=2 ttl=63 time=5.94 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1020ms\r\nrtt min/avg/max/mdev = 5.943/5.943/5.943/0.000 ms') 2025-08-15 11:32:00,849 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-23985696 passed 2025-08-15 11:32:00,914 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:00,914 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-23985696, IP 192.168.1.3, Port 22 2025-08-15 11:32:00,985 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:32:01,057 - DEBUG - VM ctest-vn1_vm1-23985696 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:32:06,057 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:06,058 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-23985696, IP 192.168.1.3, Port 22 2025-08-15 11:32:06,114 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:32:06,190 - DEBUG - VM ctest-vn1_vm1-23985696 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:32:11,191 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:11,191 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-23985696, IP 192.168.1.3, Port 22 2025-08-15 11:32:11,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': ''} 2025-08-15 11:32:11,362 - DEBUG - VM ctest-vn1_vm1-23985696 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:32:16,363 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:16,363 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-23985696, IP 192.168.1.3, Port 22 2025-08-15 11:32:16,428 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:32:16,497 - DEBUG - VM ctest-vn1_vm1-23985696 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:32:21,497 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:21,497 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-23985696, IP 192.168.1.3, Port 22 2025-08-15 11:32:21,668 - DEBUG - VM ctest-vn1_vm1-23985696 is ready for SSH connections 2025-08-15 11:32:21,668 - INFO - Waiting for VM ctest-vn1_vm2-68351972 to be up.. 2025-08-15 11:32:21,749 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:32:21,750 - INFO - VM name : ctest-vn1_vm2-68351972 2025-08-15 11:32:21,815 - DEBUG - VM ctest-vn1_vm2-68351972 ID is 83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:32:21,816 - DEBUG - VM ctest-vn1_vm2-68351972 launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 11:32:21,884 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:32:21,893 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6d98f38a-2904-4ef5-bcd0-5dbf035984bf 2025-08-15 11:32:23,048 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=1.81 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.63 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.805/2.215/2.626/0.410 ms') 2025-08-15 11:32:23,048 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm2-68351972 passed 2025-08-15 11:32:23,115 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:23,115 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-68351972, IP 192.168.1.4, Port 22 2025-08-15 11:32:23,286 - DEBUG - VM ctest-vn1_vm2-68351972 is ready for SSH connections 2025-08-15 11:32:23,286 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:23,286 - 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.242, gateway password: c0ntrail123 2025-08-15 11:32:23,286 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4 2025-08-15 11:32:40,914 - 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=9.66 ms 64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=4.11 ms 64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.10 ms --- 192.168.1.4 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.101/4.958/9.665/3.548 ms 2025-08-15 11:32:40,914 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-23985696 passed 2025-08-15 11:32:40,914 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:32:40,914 - 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.241, gateway password: c0ntrail123 2025-08-15 11:32:40,914 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3 2025-08-15 11:33:19,607 - DEBUG - PING 192.168.1.3 (192.168.1.3) 56(84) bytes of data. 64 bytes from 192.168.1.3: icmp_req=1 ttl=64 time=7.08 ms 64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.08 ms 64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=0.982 ms --- 192.168.1.3 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 0.982/3.049/7.082/2.852 ms 2025-08-15 11:33:19,607 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-68351972 passed 2025-08-15 11:33:19,614 - INFO - Active control node from the Agent 10.0.0.242 is 10.0.0.19 2025-08-15 11:33:19,614 - INFO - Stoping the Control service in 10.0.0.19 2025-08-15 11:33:20,034 - INFO - 10.0.0.19 2025-08-15 11:33:20,034 - INFO - control:inactive 2025-08-15 11:33:20,034 - INFO - Contrail services control are down on nodes 10.0.0.19 2025-08-15 11:33:25,042 - INFO - Active control node from the Agent 10.0.0.242 is 10.0.0.22 2025-08-15 11:33:25,042 - INFO - Starting the Control service in 10.0.0.19 2025-08-15 11:33:25,352 - INFO - 10.0.0.19 2025-08-15 11:33:25,356 - INFO - control:initializing 2025-08-15 11:33:25,356 - DEBUG - defaultdict(, {'10.0.0.19': {'control': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:33:25,356 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:33:30,460 - INFO - 10.0.0.19 2025-08-15 11:33:30,465 - INFO - control:active 2025-08-15 11:33:30,465 - INFO - Contrail services ['control'] are up on nodes 10.0.0.19 2025-08-15 11:33:35,554 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:33:35,554 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:33:35,554 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:33:35,560 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/732d4bf0-5535-4cf2-81f0-e4e1c95c813b 2025-08-15 11:33:35,568 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:33:35,574 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/732d4bf0-5535-4cf2-81f0-e4e1c95c813b 2025-08-15 11:33:35,583 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/61cba86d-5635-4748-b4cf-11bbf532a47f 2025-08-15 11:33:35,591 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:33:35,591 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:33:35,596 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/732d4bf0-5535-4cf2-81f0-e4e1c95c813b 2025-08-15 11:33:35,605 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/61cba86d-5635-4748-b4cf-11bbf532a47f 2025-08-15 11:33:35,611 - INFO - VM ctest-vn1_vm1-23985696 verfication in all API Servers passed 2025-08-15 11:33:35,626 - DEBUG - VM ctest-vn1_vm1-23985696 Tap interface: {'index': '3', 'name': 'tap732d4bf0-55', 'uuid': '732d4bf0-5535-4cf2-81f0-e4e1c95c813b', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', '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': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'vm_uuid': '0da397d7-4a34-4419-881d-497638b9889c', 'vm_name': 'ctest-vn1_vm1-23985696', 'ip_addr': '192.168.1.3', 'mac_addr': '02:73:2d:4b:f0:55', '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-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '31', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:33:35,627 - DEBUG - Agent 10.0.0.242 vrf name: default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578 2025-08-15 11:33:35,631 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'table_label': '-1', 'vxlan_id': '15', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.18:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2025-08-15 11:33:35,707 - DEBUG - VM ctest-vn1_vm1-23985696 : Tap interface tap732d4bf0-55 is set to Active 2025-08-15 11:33:35,708 - DEBUG - Tap interface tap732d4bf0-55 detail : {'index': '3', 'name': 'tap732d4bf0-55', 'uuid': '732d4bf0-5535-4cf2-81f0-e4e1c95c813b', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', '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': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'vm_uuid': '0da397d7-4a34-4419-881d-497638b9889c', 'vm_name': 'ctest-vn1_vm1-23985696', 'ip_addr': '192.168.1.3', 'mac_addr': '02:73:2d:4b:f0:55', '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-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '31', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:33:35,819 - DEBUG - Starting Layer 2 verification in Agent 2025-08-15 11:33:35,828 - DEBUG - Layer 2 path is seen for VM MAC 02:73:2d:4b:f0:55 in agent 10.0.0.242 2025-08-15 11:33:35,828 - DEBUG - Active layer 2 route in agent is present for VMI tap732d4bf0-55 2025-08-15 11:33:35,828 - DEBUG - L2 label(29) matches bw route table and interface table 2025-08-15 11:33:35,834 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is found in Agent of node 10.0.0.241 2025-08-15 11:33:35,961 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is consistent in agent 10.0.0.241 2025-08-15 11:33:35,961 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.241 2025-08-15 11:33:35,961 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 verification for VM ctest-vn1_vm1-23985696 in Agent 10.0.0.241 passed 2025-08-15 11:33:36,067 - DEBUG - Starting all layer 2 verification in agent 10.0.0.241 2025-08-15 11:33:36,076 - DEBUG - Route for VM MAC 02:73:2d:4b:f0:55 is consistent in agent 10.0.0.241 2025-08-15 11:33:36,082 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is found in Agent of node 10.0.0.242 2025-08-15 11:33:36,205 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is consistent in agent 10.0.0.242 2025-08-15 11:33:36,205 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.242 2025-08-15 11:33:36,205 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 verification for VM ctest-vn1_vm1-23985696 in Agent 10.0.0.242 passed 2025-08-15 11:33:36,311 - DEBUG - Starting all layer 2 verification in agent 10.0.0.242 2025-08-15 11:33:36,322 - DEBUG - Route for VM MAC 02:73:2d:4b:f0:55 is consistent in agent 10.0.0.242 2025-08-15 11:33:36,322 - INFO - VM ctest-vn1_vm1-23985696 verifications in Compute nodes passed 2025-08-15 11:33:36,549 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.241 2025-08-15 11:33:36,551 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.18, 25; Got 10.20.0.18,25 2025-08-15 11:33:36,552 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.241 2025-08-15 11:33:36,650 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.242 2025-08-15 11:33:36,652 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2025-08-15 11:33:36,652 - INFO - Validated routes of VM ctest-vn1_vm1-23985696 in all vrouters 2025-08-15 11:33:37,159 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2025-08-15 11:33:37,302 - DEBUG - Layer2 route found for VM MAC 02:73:2d:4b:f0:55 in Control-node 10.0.0.50 2025-08-15 11:33:37,302 - DEBUG - L2 Label for VM ctest-vn1_vm1-23985696 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:37,302 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node 2025-08-15 11:33:37,425 - DEBUG - Layer2 route found for VM MAC 02:73:2d:4b:f0:55 in Control-node 10.0.0.22 2025-08-15 11:33:37,425 - DEBUG - L2 Label for VM ctest-vn1_vm1-23985696 same between Control-node 10.0.0.22 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:37,425 - DEBUG - Starting all layer2 verification in 10.0.0.19 Control Node 2025-08-15 11:33:37,547 - DEBUG - Layer2 route found for VM MAC 02:73:2d:4b:f0:55 in Control-node 10.0.0.19 2025-08-15 11:33:37,547 - DEBUG - L2 Label for VM ctest-vn1_vm1-23985696 same between Control-node 10.0.0.19 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:37,547 - INFO - Verification in Control-nodes for VM ctest-vn1_vm1-23985696 passed 2025-08-15 11:33:37,547 - DEBUG - Verifying the vm in opserver 2025-08-15 11:33:37,547 - DEBUG - Verifying in collector 10.0.0.19 ... 2025-08-15 11:33:37,547 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat 2025-08-15 11:33:37,600 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b?flat 2025-08-15 11:33:37,623 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b?flat 2025-08-15 11:33:37,673 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat 2025-08-15 11:33:37,687 - DEBUG - Verifying vm in vn uve 2025-08-15 11:33:37,687 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b?flat 2025-08-15 11:33:37,740 - DEBUG - VM uve shows interface as {'fixed_ip4_list': ['192.168.1.3'], 'label': 25, 'l2_active': True, 'port_mirror_enabled': False, 'ip4_active': True, 'ip6_address': '::', 'admin_state': True, 'ip6_active': False, 'vm_uuid': '0da397d7-4a34-4419-881d-497638b9889c', 'vhostuser_mode': 0, 'tx_vlan': 65535, 'rx_vlan': 65535, 'ip_address': '192.168.1.3', '__T': 1755257617517424, 'vm_name': 'ctest-vn1_vm1-23985696', 'active': True, 'mac_address': '02:73:2d:4b:f0:55', 'vn_uuid': '83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc', 'gateway': '192.168.1.1', 'uuid': '732d4bf0-5535-4cf2-81f0-e4e1c95c813b', 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'is_health_check_active': True} 2025-08-15 11:33:37,740 - DEBUG - VM uve shows ip address as ['192.168.1.3', '::'] 2025-08-15 11:33:37,740 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:37,740 - INFO - Verifying through opserver in 10.0.0.50 2025-08-15 11:33:37,740 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat 2025-08-15 11:33:37,764 - DEBUG - expected vm list 0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:33:37,764 - DEBUG - Extracted vm list ['0da397d7-4a34-4419-881d-497638b9889c'] 2025-08-15 11:33:37,764 - INFO - VM 0da397d7-4a34-4419-881d-497638b9889c is present in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:37,764 - DEBUG - Verifying vm in vrouter uve 2025-08-15 11:33:37,764 - DEBUG - Getting info from collector 10.0.0.19.. 2025-08-15 11:33:37,764 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat 2025-08-15 11:33:37,814 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-3861-2'] 2025-08-15 11:33:37,814 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:37,870 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:33:37,901 - DEBUG - VM 0da397d7-4a34-4419-881d-497638b9889c is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:33:37,901 - DEBUG - Validated that VM ctest-vn1_vm1-23985696 is in Vrouter an-jenkins-deploy-platform-ansible-os-3861-2 UVE 2025-08-15 11:33:37,901 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2025-08-15 11:33:37,908 - DEBUG - Expected tap interface of VM uuid 0da397d7-4a34-4419-881d-497638b9889c is default-domain:ctest-TestBasicVMVN0-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b 2025-08-15 11:33:37,908 - DEBUG - Expected VN of VM uuid 0da397d7-4a34-4419-881d-497638b9889c is default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:37,908 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:37,962 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:33:37,991 - DEBUG - VM 0da397d7-4a34-4419-881d-497638b9889c is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:33:37,991 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-91341447:732d4bf0-5535-4cf2-81f0-e4e1c95c813b of vm 0da397d7-4a34-4419-881d-497638b9889c is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:33:37,991 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 of vm 0da397d7-4a34-4419-881d-497638b9889c is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:33:37,991 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.50 2025-08-15 11:33:37,991 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:33:38,002 - DEBUG - VM link and name as {'name': '0da397d7-4a34-4419-881d-497638b9889c', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat'} 2025-08-15 11:33:38,002 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.22 2025-08-15 11:33:38,002 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:33:38,049 - DEBUG - VM link and name as {'name': '0da397d7-4a34-4419-881d-497638b9889c', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat'} 2025-08-15 11:33:38,049 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.19 2025-08-15 11:33:38,049 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:33:38,059 - DEBUG - VM link and name as {'name': '0da397d7-4a34-4419-881d-497638b9889c', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c?flat'} 2025-08-15 11:33:38,059 - INFO - VM ctest-vn1_vm1-23985696 validations in Opserver passed 2025-08-15 11:33:38,125 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:33:38,125 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:33:38,125 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:38,132 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6d98f38a-2904-4ef5-bcd0-5dbf035984bf 2025-08-15 11:33:38,141 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:38,146 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6d98f38a-2904-4ef5-bcd0-5dbf035984bf 2025-08-15 11:33:38,154 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/2faa2ec1-d320-459a-b082-bc0b74050306 2025-08-15 11:33:38,162 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:33:38,162 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:38,167 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6d98f38a-2904-4ef5-bcd0-5dbf035984bf 2025-08-15 11:33:38,174 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/2faa2ec1-d320-459a-b082-bc0b74050306 2025-08-15 11:33:38,181 - INFO - VM ctest-vn1_vm2-68351972 verfication in all API Servers passed 2025-08-15 11:33:38,198 - DEBUG - VM ctest-vn1_vm2-68351972 Tap interface: {'index': '3', 'name': 'tap6d98f38a-29', 'uuid': '6d98f38a-2904-4ef5-bcd0-5dbf035984bf', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', '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': '24', 'l2_label': '29', 'vxlan_id': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'vm_uuid': '83293257-25f1-4cab-9c90-0532af29a6d7', 'vm_name': 'ctest-vn1_vm2-68351972', 'ip_addr': '192.168.1.4', 'mac_addr': '02:6d:98:f3:8a:29', '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-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', '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': []} 2025-08-15 11:33:38,199 - DEBUG - Agent 10.0.0.241 vrf name: default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578 2025-08-15 11:33:38,204 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'table_label': '-1', 'vxlan_id': '15', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.193:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2025-08-15 11:33:38,275 - DEBUG - VM ctest-vn1_vm2-68351972 : Tap interface tap6d98f38a-29 is set to Active 2025-08-15 11:33:38,276 - DEBUG - Tap interface tap6d98f38a-29 detail : {'index': '3', 'name': 'tap6d98f38a-29', 'uuid': '6d98f38a-2904-4ef5-bcd0-5dbf035984bf', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578:ctest-vn1-17847578', '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': '24', 'l2_label': '29', 'vxlan_id': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'vm_uuid': '83293257-25f1-4cab-9c90-0532af29a6d7', 'vm_name': 'ctest-vn1_vm2-68351972', 'ip_addr': '192.168.1.4', 'mac_addr': '02:6d:98:f3:8a:29', '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-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', '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': []} 2025-08-15 11:33:38,388 - DEBUG - Starting Layer 2 verification in Agent 2025-08-15 11:33:38,398 - DEBUG - Layer 2 path is seen for VM MAC 02:6d:98:f3:8a:29 in agent 10.0.0.241 2025-08-15 11:33:38,398 - DEBUG - Active layer 2 route in agent is present for VMI tap6d98f38a-29 2025-08-15 11:33:38,398 - DEBUG - L2 label(29) matches bw route table and interface table 2025-08-15 11:33:38,403 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is found in Agent of node 10.0.0.241 2025-08-15 11:33:38,532 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is consistent in agent 10.0.0.241 2025-08-15 11:33:38,532 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.241 2025-08-15 11:33:38,532 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 verification for VM ctest-vn1_vm2-68351972 in Agent 10.0.0.241 passed 2025-08-15 11:33:38,639 - DEBUG - Starting all layer 2 verification in agent 10.0.0.241 2025-08-15 11:33:38,648 - DEBUG - Route for VM MAC 02:6d:98:f3:8a:29 is consistent in agent 10.0.0.241 2025-08-15 11:33:38,654 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is found in Agent of node 10.0.0.242 2025-08-15 11:33:38,771 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 is consistent in agent 10.0.0.242 2025-08-15 11:33:38,771 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.242 2025-08-15 11:33:38,771 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 verification for VM ctest-vn1_vm2-68351972 in Agent 10.0.0.242 passed 2025-08-15 11:33:38,883 - DEBUG - Starting all layer 2 verification in agent 10.0.0.242 2025-08-15 11:33:38,892 - DEBUG - Route for VM MAC 02:6d:98:f3:8a:29 is consistent in agent 10.0.0.242 2025-08-15 11:33:38,893 - INFO - VM ctest-vn1_vm2-68351972 verifications in Compute nodes passed 2025-08-15 11:33:39,164 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.241 2025-08-15 11:33:39,167 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2025-08-15 11:33:39,266 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.242 2025-08-15 11:33:39,268 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.193, 24; Got 10.20.0.193,24 2025-08-15 11:33:39,269 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.242 2025-08-15 11:33:39,269 - INFO - Validated routes of VM ctest-vn1_vm2-68351972 in all vrouters 2025-08-15 11:33:39,756 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2025-08-15 11:33:39,875 - DEBUG - Layer2 route found for VM MAC 02:6d:98:f3:8a:29 in Control-node 10.0.0.50 2025-08-15 11:33:39,875 - DEBUG - L2 Label for VM ctest-vn1_vm2-68351972 same between Control-node 10.0.0.50 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:39,875 - DEBUG - Starting all layer2 verification in 10.0.0.22 Control Node 2025-08-15 11:33:39,992 - DEBUG - Layer2 route found for VM MAC 02:6d:98:f3:8a:29 in Control-node 10.0.0.22 2025-08-15 11:33:39,992 - DEBUG - L2 Label for VM ctest-vn1_vm2-68351972 same between Control-node 10.0.0.22 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:39,992 - DEBUG - Starting all layer2 verification in 10.0.0.19 Control Node 2025-08-15 11:33:40,116 - DEBUG - Layer2 route found for VM MAC 02:6d:98:f3:8a:29 in Control-node 10.0.0.19 2025-08-15 11:33:40,116 - DEBUG - L2 Label for VM ctest-vn1_vm2-68351972 same between Control-node 10.0.0.19 and Agent, Expected: 29, Seen: 29 2025-08-15 11:33:40,116 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-68351972 passed 2025-08-15 11:33:40,116 - DEBUG - Verifying the vm in opserver 2025-08-15 11:33:40,116 - DEBUG - Verifying in collector 10.0.0.19 ... 2025-08-15 11:33:40,116 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat 2025-08-15 11:33:40,131 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf?flat 2025-08-15 11:33:40,150 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf?flat 2025-08-15 11:33:40,165 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat 2025-08-15 11:33:40,180 - DEBUG - Verifying vm in vn uve 2025-08-15 11:33:40,180 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf?flat 2025-08-15 11:33:40,197 - DEBUG - VM uve shows interface as {'fixed_ip4_list': ['192.168.1.4'], 'label': 24, 'l2_active': True, 'port_mirror_enabled': False, 'ip4_active': True, 'ip6_address': '::', 'admin_state': True, 'ip6_active': False, 'vm_uuid': '83293257-25f1-4cab-9c90-0532af29a6d7', 'vhostuser_mode': 0, 'tx_vlan': 65535, 'rx_vlan': 65535, 'ip_address': '192.168.1.4', '__T': 1755257489083269, 'vm_name': 'ctest-vn1_vm2-68351972', 'active': True, 'mac_address': '02:6d:98:f3:8a:29', 'vn_uuid': '83a9c0b3-9de9-45dc-9fb8-b6c22bc347cc', 'gateway': '192.168.1.1', 'uuid': '6d98f38a-2904-4ef5-bcd0-5dbf035984bf', 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578', 'is_health_check_active': True} 2025-08-15 11:33:40,197 - DEBUG - VM uve shows ip address as ['192.168.1.4', '::'] 2025-08-15 11:33:40,197 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:40,197 - INFO - Verifying through opserver in 10.0.0.50 2025-08-15 11:33:40,197 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat 2025-08-15 11:33:40,221 - DEBUG - expected vm list 83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:40,221 - DEBUG - Extracted vm list ['83293257-25f1-4cab-9c90-0532af29a6d7'] 2025-08-15 11:33:40,221 - INFO - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is present in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:40,221 - DEBUG - Verifying vm in vrouter uve 2025-08-15 11:33:40,221 - DEBUG - Getting info from collector 10.0.0.19.. 2025-08-15 11:33:40,221 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat 2025-08-15 11:33:40,235 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-3861-1'] 2025-08-15 11:33:40,236 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:40,266 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:40,295 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:40,295 - DEBUG - Validated that VM ctest-vn1_vm2-68351972 is in Vrouter an-jenkins-deploy-platform-ansible-os-3861-1 UVE 2025-08-15 11:33:40,295 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2025-08-15 11:33:40,302 - DEBUG - Expected tap interface of VM uuid 83293257-25f1-4cab-9c90-0532af29a6d7 is default-domain:ctest-TestBasicVMVN0-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf 2025-08-15 11:33:40,302 - DEBUG - Expected VN of VM uuid 83293257-25f1-4cab-9c90-0532af29a6d7 is default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:40,302 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:40,333 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:40,363 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:40,363 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-91341447:6d98f38a-2904-4ef5-bcd0-5dbf035984bf of vm 83293257-25f1-4cab-9c90-0532af29a6d7 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:40,363 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 of vm 83293257-25f1-4cab-9c90-0532af29a6d7 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:40,363 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.50 2025-08-15 11:33:40,363 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:33:40,374 - DEBUG - VM link and name as {'name': '83293257-25f1-4cab-9c90-0532af29a6d7', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat'} 2025-08-15 11:33:40,374 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.22 2025-08-15 11:33:40,374 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:33:40,386 - DEBUG - VM link and name as {'name': '83293257-25f1-4cab-9c90-0532af29a6d7', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat'} 2025-08-15 11:33:40,386 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.19 2025-08-15 11:33:40,386 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:33:40,398 - DEBUG - VM link and name as {'name': '83293257-25f1-4cab-9c90-0532af29a6d7', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7?flat'} 2025-08-15 11:33:40,398 - INFO - VM ctest-vn1_vm2-68351972 validations in Opserver passed 2025-08-15 11:33:40,398 - INFO - Checking the ping between the VM again 2025-08-15 11:33:40,398 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:33:40,398 - 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.242, gateway password: c0ntrail123 2025-08-15 11:33:40,398 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4 2025-08-15 11:33:42,843 - DEBUG - PING 192.168.1.4 (192.168.1.4) 56(84) bytes of data. 64 bytes from 192.168.1.4: icmp_req=1 ttl=64 time=3.50 ms 64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=1.12 ms 64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.00 ms --- 192.168.1.4 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.007/1.878/3.507/1.153 ms 2025-08-15 11:33:42,843 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-23985696 passed 2025-08-15 11:33:42,843 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:33:42,843 - 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.241, gateway password: c0ntrail123 2025-08-15 11:33:42,843 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3 2025-08-15 11:33:45,298 - 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.50 ms 64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=0.897 ms 64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=0.861 ms --- 192.168.1.3 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2003ms rtt min/avg/max/mdev = 0.861/1.755/3.508/1.239 ms 2025-08-15 11:33:45,298 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-68351972 passed 2025-08-15 11:33:45,298 - INFO - Deleting VM ctest-vn1_vm2-68351972 2025-08-15 11:33:45,354 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:33:45,354 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:45,363 - DEBUG - VM ID 83293257-25f1-4cab-9c90-0532af29a6d7 of VM ctest-vn1_vm2-68351972 is still found in API Server 2025-08-15 11:33:47,365 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:33:47,365 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:47,405 - DEBUG - Response Code: 404 2025-08-15 11:33:47,406 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:47,415 - DEBUG - Response Code: 404 2025-08-15 11:33:47,415 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/83293257-25f1-4cab-9c90-0532af29a6d7 2025-08-15 11:33:47,420 - DEBUG - Response Code: 404 2025-08-15 11:33:47,420 - INFO - VM ctest-vn1_vm2-68351972 is fully removed in API-Server 2025-08-15 11:33:47,571 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2025-08-15 11:33:47,605 - DEBUG - Validated that vrouter 10.0.0.241 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:47,712 - DEBUG - VM route 192.168.1.4 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 of compute 10.0.0.242 2025-08-15 11:33:47,715 - DEBUG - Validated that vrouter 10.0.0.242 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:47,715 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:33:47,715 - INFO - VM ctest-vn1_vm2-68351972 is removed in Compute, and routes are removed in all compute nodes 2025-08-15 11:33:47,962 - INFO - Routes for VM ctest-vn1_vm2-68351972 is removed in all control-nodes 2025-08-15 11:33:47,963 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:47,997 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:48,031 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:48,031 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:33:48,031 - DEBUG - interface for vm 83293257-25f1-4cab-9c90-0532af29a6d7 deleted from vrouter uve ... 2025-08-15 11:33:48,031 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:33:51,032 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:51,066 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:51,100 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:51,100 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:33:51,100 - DEBUG - interface for vm 83293257-25f1-4cab-9c90-0532af29a6d7 deleted from vrouter uve ... 2025-08-15 11:33:51,100 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:33:54,101 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:54,135 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:54,163 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:54,163 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:33:54,163 - DEBUG - interface for vm 83293257-25f1-4cab-9c90-0532af29a6d7 deleted from vrouter uve ... 2025-08-15 11:33:54,163 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:33:57,164 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:33:57,200 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:33:57,231 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:33:57,231 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:33:57,231 - DEBUG - interface for vm 83293257-25f1-4cab-9c90-0532af29a6d7 deleted from vrouter uve ... 2025-08-15 11:33:57,231 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:34:00,231 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:34:00,264 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:34:00,294 - DEBUG - VM 83293257-25f1-4cab-9c90-0532af29a6d7 is not present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:34:00,294 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:34:00,294 - DEBUG - interface for vm 83293257-25f1-4cab-9c90-0532af29a6d7 deleted from vrouter uve ... 2025-08-15 11:34:00,294 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:34:00,294 - DEBUG - Validated that VM 83293257-25f1-4cab-9c90-0532af29a6d7 is removed in Vrouter UVE 2025-08-15 11:34:00,294 - DEBUG - Verifying through opserver in 10.0.0.50 2025-08-15 11:34:00,294 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat 2025-08-15 11:34:00,319 - DEBUG - 83293257-25f1-4cab-9c90-0532af29a6d7 BM not in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 uve 2025-08-15 11:34:00,319 - DEBUG - Validated that VM 83293257-25f1-4cab-9c90-0532af29a6d7 is not present in the VN UVE 2025-08-15 11:34:00,319 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.50 2025-08-15 11:34:00,319 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:34:00,330 - INFO - 83293257-25f1-4cab-9c90-0532af29a6d7 vm uve deleted from opserver 2025-08-15 11:34:00,330 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.22 2025-08-15 11:34:00,330 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:34:00,342 - INFO - 83293257-25f1-4cab-9c90-0532af29a6d7 vm uve deleted from opserver 2025-08-15 11:34:00,342 - DEBUG - Verifying the 83293257-25f1-4cab-9c90-0532af29a6d7 virtual network link through opserver 10.0.0.19 2025-08-15 11:34:00,342 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:34:00,352 - INFO - 83293257-25f1-4cab-9c90-0532af29a6d7 vm uve deleted from opserver 2025-08-15 11:34:00,352 - INFO - Validated that VM 83293257-25f1-4cab-9c90-0532af29a6d7 is removed from Opserver 2025-08-15 11:34:00,352 - INFO - Deleting VM ctest-vn1_vm1-23985696 2025-08-15 11:34:00,414 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:34:00,414 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:34:00,422 - DEBUG - VM ID 0da397d7-4a34-4419-881d-497638b9889c of VM ctest-vn1_vm1-23985696 is still found in API Server 2025-08-15 11:34:02,423 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:34:02,423 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:34:02,429 - DEBUG - Response Code: 404 2025-08-15 11:34:02,429 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:34:02,434 - DEBUG - Response Code: 404 2025-08-15 11:34:02,434 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/0da397d7-4a34-4419-881d-497638b9889c 2025-08-15 11:34:02,439 - DEBUG - Response Code: 404 2025-08-15 11:34:02,439 - INFO - VM ctest-vn1_vm1-23985696 is fully removed in API-Server 2025-08-15 11:34:02,586 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2025-08-15 11:34:02,626 - DEBUG - Validated that vrouter 10.0.0.241 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:34:02,635 - DEBUG - Validated that vrouter 10.0.0.242 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:34:02,635 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 2025-08-15 11:34:02,635 - INFO - VM ctest-vn1_vm1-23985696 is removed in Compute, and routes are removed in all compute nodes 2025-08-15 11:34:02,859 - INFO - Routes for VM ctest-vn1_vm1-23985696 is removed in all control-nodes 2025-08-15 11:34:02,859 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:34:02,916 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:34:02,952 - DEBUG - VM 0da397d7-4a34-4419-881d-497638b9889c is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:34:02,952 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:34:02,953 - DEBUG - interface for vm 0da397d7-4a34-4419-881d-497638b9889c deleted from vrouter uve ... 2025-08-15 11:34:02,953 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:34:05,954 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:34:06,009 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:34:06,044 - DEBUG - VM 0da397d7-4a34-4419-881d-497638b9889c is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:34:06,044 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:34:06,044 - DEBUG - interface for vm 0da397d7-4a34-4419-881d-497638b9889c deleted from vrouter uve ... 2025-08-15 11:34:06,044 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:34:09,045 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:34:09,101 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:34:09,130 - DEBUG - VM 0da397d7-4a34-4419-881d-497638b9889c is not present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:34:09,130 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:34:09,130 - DEBUG - interface for vm 0da397d7-4a34-4419-881d-497638b9889c deleted from vrouter uve ... 2025-08-15 11:34:09,130 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:34:09,130 - DEBUG - Validated that VM 0da397d7-4a34-4419-881d-497638b9889c is removed in Vrouter UVE 2025-08-15 11:34:09,130 - DEBUG - Verifying through opserver in 10.0.0.50 2025-08-15 11:34:09,130 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578?flat 2025-08-15 11:34:09,146 - DEBUG - 0da397d7-4a34-4419-881d-497638b9889c BM not in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-17847578 uve 2025-08-15 11:34:09,147 - DEBUG - Validated that VM 0da397d7-4a34-4419-881d-497638b9889c is not present in the VN UVE 2025-08-15 11:34:09,147 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.50 2025-08-15 11:34:09,147 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:34:09,156 - INFO - 0da397d7-4a34-4419-881d-497638b9889c vm uve deleted from opserver 2025-08-15 11:34:09,156 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.22 2025-08-15 11:34:09,157 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:34:09,168 - INFO - 0da397d7-4a34-4419-881d-497638b9889c vm uve deleted from opserver 2025-08-15 11:34:09,168 - DEBUG - Verifying the 0da397d7-4a34-4419-881d-497638b9889c virtual network link through opserver 10.0.0.19 2025-08-15 11:34:09,168 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:34:09,179 - INFO - 0da397d7-4a34-4419-881d-497638b9889c vm uve deleted from opserver 2025-08-15 11:34:09,179 - INFO - Validated that VM 0da397d7-4a34-4419-881d-497638b9889c is removed from Opserver 2025-08-15 11:34:09,179 - INFO - Deleting VN ctest-vn1-17847578 2025-08-15 11:34:09,330 - DEBUG - Response for deleting network () 2025-08-15 11:34:09,330 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/fa65aa6b-c3b0-42d3-88d8-42e5f0f166bd 2025-08-15 11:34:09,335 - DEBUG - Response Code: 404 2025-08-15 11:34:09,335 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:34:09,340 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:34:09,353 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:34:09,451 - INFO - Validated that VN ctest-vn1-17847578 is not found in API Server 2025-08-15 11:34:09,465 - DEBUG - VN ctest-vn1-17847578 is not present in Agent 10.0.0.241 2025-08-15 11:34:09,474 - DEBUG - VN ctest-vn1-17847578 is not present in Agent 10.0.0.242 2025-08-15 11:34:09,474 - INFO - Validated that VN ctest-vn1-17847578 is not in any agent 2025-08-15 11:34:09,507 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-17847578 info 2025-08-15 11:34:10,750 - DEBUG - Skipping xmpp flap check
2025-08-15 11:34:10,750 - INFO - END TEST : test_control_node_switchover : PASSED[0:02:53]
2025-08-15 11:34:10,750 - INFO - -------------------------------------------------------------------------------- 2025-08-15 11:34:10,753 - INFO - ================================================================================ 2025-08-15 11:34:10,753 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns 2025-08-15 11:34:10,753 - INFO - TEST DESCRIPTION : Test to validate that with policy having rule to check icmp fwding between VMs on different VNs , ping between VMs should pass with process restarts 1. Pick 2 VN's from resource pool which has one VM each 2. Create policy with icmp allow rule between those VN's and bind it networks 3. Ping from one VM to another VM 4. Restart process 'vrouter' and 'control' on setup 5. Ping again between VM's after process restart Pass criteria: Step 2,3,4 and 5 should pass 2025-08-15 11:34:12,011 - DEBUG - Skipping xmpp flap check 2025-08-15 11:34:12,011 - INFO - Initial checks done. Running the testcase now 2025-08-15 11:34:12,011 - INFO - 2025-08-15 11:34:12,016 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296, 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-91341447:ctest-vn2-30302845, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None] 2025-08-15 11:34:12,299 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845, 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-91341447:ctest-vn1-39202296, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None] 2025-08-15 11:34:12,807 - INFO - Created VN ctest-vn1-39202296, UUID :aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,109 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:34:13,115 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:34:13,125 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:34:13,214 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,225 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,233 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:34:13,240 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:34:13,247 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/78c7ef69-9811-486e-8e1a-099451b4579d 2025-08-15 11:34:13,254 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:34:13,254 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,261 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:34:13,274 - INFO - Verified VN network id 15 for VN aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,274 - INFO - Verifications in API Server for VN ctest-vn1-39202296 passed 2025-08-15 11:34:13,274 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,282 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:34:13,288 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:34:13,295 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/78c7ef69-9811-486e-8e1a-099451b4579d 2025-08-15 11:34:13,307 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.355399'} 2025-08-15 11:34:13,313 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:34:13,318 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.362965'} 2025-08-15 11:34:13,324 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:34:13,329 - DEBUG - Control-node 10.0.0.19 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.378452'} 2025-08-15 11:34:13,334 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:34:13,334 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-39202296 passed 2025-08-15 11:34:13,334 - DEBUG - ====Verifying policy data for ctest-vn1-39202296 in API_Server ====== 2025-08-15 11:34:13,334 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:34:13,341 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:34:13,352 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:34:13,446 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:34:13,456 - DEBUG - =>VN ctest-vn1-39202296 has no policy to be verified 2025-08-15 11:34:13,456 - DEBUG - Verifying the vn in opserver 2025-08-15 11:34:13,456 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.50 2025-08-15 11:34:13,456 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-08-15 11:34:13,467 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:34:13,467 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.22 2025-08-15 11:34:13,467 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-08-15 11:34:13,519 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:34:13,519 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.19 2025-08-15 11:34:13,519 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-networks 2025-08-15 11:34:13,530 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:34:13,532 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is found in opserver 2025-08-15 11:34:13,551 - DEBUG - Do not have enough data to verify VN in agent 2025-08-15 11:34:13,560 - DEBUG - VRF ids for VN ctest-vn1-39202296: {} 2025-08-15 11:34:14,163 - INFO - Created VN ctest-vn2-30302845, UUID :a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,462 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:34:14,467 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:34:14,477 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:34:14,565 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,576 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,584 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:34:14,591 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:34:14,597 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/5038996b-0b14-4a5e-9eef-14f8351bef9a 2025-08-15 11:34:14,604 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-08-15 11:34:14,604 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,613 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:34:14,627 - INFO - Verified VN network id 16 for VN a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,627 - INFO - Verifications in API Server for VN ctest-vn2-30302845 passed 2025-08-15 11:34:14,627 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,637 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:34:14,643 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:34:14,649 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/5038996b-0b14-4a5e-9eef-14f8351bef9a 2025-08-15 11:34:14,660 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11760207929667833695', 'uuid-lslong': '11443337144934654249'}, 'enable': 'true', 'created': '2025-08-15T11:34:14', 'last-modified': '2025-08-15T11:34:14', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.358517'} 2025-08-15 11:34:14,666 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-08-15 11:34:14,671 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11760207929667833695', 'uuid-lslong': '11443337144934654249'}, 'enable': 'true', 'created': '2025-08-15T11:34:14', 'last-modified': '2025-08-15T11:34:14', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.373619'} 2025-08-15 11:34:14,678 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-08-15 11:34:14,685 - DEBUG - Control-node 10.0.0.19 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '11760207929667833695', 'uuid-lslong': '11443337144934654249'}, 'enable': 'true', 'created': '2025-08-15T11:34:14', 'last-modified': '2025-08-15T11:34:14', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.386496'} 2025-08-15 11:34:14,691 - DEBUG - Route Targets: ['target:64512:8000006'] 2025-08-15 11:34:14,691 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-30302845 passed 2025-08-15 11:34:14,691 - DEBUG - ====Verifying policy data for ctest-vn2-30302845 in API_Server ====== 2025-08-15 11:34:14,691 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:34:14,696 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:34:14,710 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:34:14,795 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/a334a6cd-c495-4f5f-9ece-e68100dce129 2025-08-15 11:34:14,808 - DEBUG - =>VN ctest-vn2-30302845 has no policy to be verified 2025-08-15 11:34:14,808 - DEBUG - Verifying the vn in opserver 2025-08-15 11:34:14,808 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 virtual network link through opserver 10.0.0.50 2025-08-15 11:34:14,808 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-08-15 11:34:14,823 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845?flat'} 2025-08-15 11:34:14,823 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 virtual network link through opserver 10.0.0.22 2025-08-15 11:34:14,823 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-08-15 11:34:14,841 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845?flat'} 2025-08-15 11:34:14,841 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 virtual network link through opserver 10.0.0.19 2025-08-15 11:34:14,841 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-networks 2025-08-15 11:34:14,852 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845?flat'} 2025-08-15 11:34:14,852 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is found in opserver 2025-08-15 11:34:14,872 - DEBUG - Do not have enough data to verify VN in agent 2025-08-15 11:34:14,881 - DEBUG - VRF ids for VN ctest-vn2-30302845: {} 2025-08-15 11:34:16,259 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 11:34:17,463 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 11:34:17,463 - INFO - Waiting for VM ctest-vn1_vm1-63627639 to be up.. 2025-08-15 11:34:17,548 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 11:34:22,620 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:34:22,620 - INFO - VM name : ctest-vn1_vm1-63627639 2025-08-15 11:34:22,689 - DEBUG - VM ctest-vn1_vm1-63627639 ID is 6574f47d-2981-4649-bf76-186ac0389fb3 2025-08-15 11:34:22,690 - DEBUG - VM ctest-vn1_vm1-63627639 launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 11:34:22,764 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/6574f47d-2981-4649-bf76-186ac0389fb3 2025-08-15 11:34:22,774 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/45b9b939-1c9c-4e20-9ab6-cb70c16f9284 2025-08-15 11:34:25,939 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms') 2025-08-15 11:34:25,939 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:25,952 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:30,034 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2025-08-15 11:34:30,034 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:30,049 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:34,138 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:34:34,138 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:34,151 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:38,231 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-08-15 11:34:38,231 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:38,244 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:42,318 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2025-08-15 11:34:42,318 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:42,330 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:46,419 - 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 1026ms') 2025-08-15 11:34:46,419 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:46,431 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:50,514 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms') 2025-08-15 11:34:50,514 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 failed! 2025-08-15 11:34:50,528 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:34:54,610 - 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=2 ttl=63 time=6.65 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1018ms\r\nrtt min/avg/max/mdev = 6.652/6.652/6.652/0.000 ms') 2025-08-15 11:34:54,610 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-63627639 passed 2025-08-15 11:34:54,676 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:34:54,676 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-63627639, IP 192.168.1.252, Port 22 2025-08-15 11:34:54,734 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:34:54,827 - DEBUG - VM ctest-vn1_vm1-63627639 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:34:59,828 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:34:59,828 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-63627639, IP 192.168.1.252, Port 22 2025-08-15 11:34:59,892 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:34:59,958 - DEBUG - VM ctest-vn1_vm1-63627639 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:35:04,959 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:35:04,959 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-63627639, IP 192.168.1.252, Port 22 2025-08-15 11:35:05,024 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:35:05,097 - DEBUG - VM ctest-vn1_vm1-63627639 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:35:10,098 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:35:10,098 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-63627639, IP 192.168.1.252, Port 22 2025-08-15 11:35:10,254 - DEBUG - VM ctest-vn1_vm1-63627639 is ready for SSH connections 2025-08-15 11:35:10,254 - INFO - Waiting for VM ctest-vn2_vm1-73729752 to be up.. 2025-08-15 11:35:10,319 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:35:10,319 - INFO - VM name : ctest-vn2_vm1-73729752 2025-08-15 11:35:10,387 - DEBUG - VM ctest-vn2_vm1-73729752 ID is 315d96d0-9abd-42a3-8f77-d6ee119cdf49 2025-08-15 11:35:10,387 - DEBUG - VM ctest-vn2_vm1-73729752 launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 11:35:10,476 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/315d96d0-9abd-42a3-8f77-d6ee119cdf49 2025-08-15 11:35:10,486 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/44a539a6-76c1-48e2-afe8-614a7e20221e 2025-08-15 11:35:11,651 - 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.44 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.57 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 = 2.574/3.509/4.444/0.935 ms') 2025-08-15 11:35:11,651 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2_vm1-73729752 passed 2025-08-15 11:35:11,716 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:35:11,716 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-73729752, IP 192.168.2.252, Port 22 2025-08-15 11:35:11,783 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:35:11,862 - DEBUG - VM ctest-vn2_vm1-73729752 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:35:16,863 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:35:16,863 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-73729752, IP 192.168.2.252, Port 22 2025-08-15 11:35:17,020 - DEBUG - VM ctest-vn2_vm1-73729752 is ready for SSH connections 2025-08-15 11:35:17,020 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:35:17,020 - 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.242, gateway password: c0ntrail123 2025-08-15 11:35:17,020 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.252 2025-08-15 11:35:33,776 - 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=8.37 ms 64 bytes from 192.168.2.252: icmp_req=2 ttl=63 time=1.76 ms 64 bytes from 192.168.2.252: icmp_req=3 ttl=63 time=1.13 ms --- 192.168.2.252 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2004ms rtt min/avg/max/mdev = 1.138/3.758/8.376/3.275 ms 2025-08-15 11:35:33,776 - INFO - Ping to IP 192.168.2.252 from VM ctest-vn1_vm1-63627639 passed 2025-08-15 11:35:37,143 - INFO - 10.0.0.241 2025-08-15 11:35:37,146 - INFO - agent:initializing 2025-08-15 11:35:37,146 - DEBUG - defaultdict(, {'10.0.0.241': {'agent': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:35:37,147 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:35:42,240 - INFO - 10.0.0.241 2025-08-15 11:35:42,246 - INFO - agent:active 2025-08-15 11:35:42,247 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.241 2025-08-15 11:35:45,621 - INFO - 10.0.0.242 2025-08-15 11:35:45,624 - INFO - agent:initializing 2025-08-15 11:35:45,624 - DEBUG - defaultdict(, {'10.0.0.242': {'agent': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:35:45,624 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:35:50,713 - INFO - 10.0.0.242 2025-08-15 11:35:50,719 - INFO - agent:active 2025-08-15 11:35:50,719 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.242 2025-08-15 11:35:51,256 - INFO - 10.0.0.50 2025-08-15 11:35:51,260 - INFO - control:initializing 2025-08-15 11:35:51,260 - DEBUG - defaultdict(, {'10.0.0.50': {'control': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:35:51,260 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:35:56,371 - INFO - 10.0.0.50 2025-08-15 11:35:56,377 - INFO - control:active 2025-08-15 11:35:56,377 - INFO - Contrail services ['control'] are up on nodes 10.0.0.50 2025-08-15 11:35:56,812 - INFO - 10.0.0.22 2025-08-15 11:35:56,816 - INFO - control:initializing 2025-08-15 11:35:56,816 - DEBUG - defaultdict(, {'10.0.0.22': {'control': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:35:56,816 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:36:01,913 - INFO - 10.0.0.22 2025-08-15 11:36:01,921 - INFO - control:active 2025-08-15 11:36:01,921 - INFO - Contrail services ['control'] are up on nodes 10.0.0.22 2025-08-15 11:36:02,336 - INFO - 10.0.0.19 2025-08-15 11:36:02,339 - INFO - control:initializing 2025-08-15 11:36:02,339 - DEBUG - defaultdict(, {'10.0.0.19': {'control': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:02,339 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:36:07,425 - INFO - 10.0.0.19 2025-08-15 11:36:07,430 - INFO - control:active 2025-08-15 11:36:07,430 - INFO - Contrail services ['control'] are up on nodes 10.0.0.19 2025-08-15 11:36:08,031 - INFO - 10.0.0.50 2025-08-15 11:36:08,034 - INFO - api-server:initializing 2025-08-15 11:36:08,035 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:08,035 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:36:13,142 - INFO - 10.0.0.50 2025-08-15 11:36:13,145 - INFO - api-server:initializing 2025-08-15 11:36:13,145 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:13,145 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2025-08-15 11:36:18,265 - INFO - 10.0.0.50 2025-08-15 11:36:18,271 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2025-08-15 11:36:18,271 - DEBUG - defaultdict(, {'10.0.0.50': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2025-08-15 11:36:18,272 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2025-08-15 11:36:23,374 - INFO - 10.0.0.50 2025-08-15 11:36:23,378 - INFO - api-server:active 2025-08-15 11:36:23,378 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.50 2025-08-15 11:36:24,008 - INFO - 10.0.0.22 2025-08-15 11:36:24,011 - INFO - api-server:initializing 2025-08-15 11:36:24,011 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:24,011 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:36:29,112 - INFO - 10.0.0.22 2025-08-15 11:36:29,115 - INFO - api-server:initializing 2025-08-15 11:36:29,115 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:29,115 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2025-08-15 11:36:34,203 - INFO - 10.0.0.22 2025-08-15 11:36:34,207 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2025-08-15 11:36:34,207 - DEBUG - defaultdict(, {'10.0.0.22': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2025-08-15 11:36:34,207 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2025-08-15 11:36:39,305 - INFO - 10.0.0.22 2025-08-15 11:36:39,309 - INFO - api-server:active 2025-08-15 11:36:39,310 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.22 2025-08-15 11:36:39,929 - INFO - 10.0.0.19 2025-08-15 11:36:39,932 - INFO - api-server:initializing 2025-08-15 11:36:39,932 - DEBUG - defaultdict(, {'10.0.0.19': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:39,932 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0 2025-08-15 11:36:45,032 - INFO - 10.0.0.19 2025-08-15 11:36:45,036 - INFO - api-server:initializing 2025-08-15 11:36:45,036 - DEBUG - defaultdict(, {'10.0.0.19': {'api-server': {'status': 'initializing', 'description': None}}}) 2025-08-15 11:36:45,036 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1 2025-08-15 11:36:50,131 - INFO - 10.0.0.19 2025-08-15 11:36:50,175 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down) 2025-08-15 11:36:50,175 - DEBUG - defaultdict(, {'10.0.0.19': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}}) 2025-08-15 11:36:50,175 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2 2025-08-15 11:36:55,272 - INFO - 10.0.0.19 2025-08-15 11:36:55,276 - INFO - api-server:active 2025-08-15 11:36:55,277 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.19 2025-08-15 11:36:55,390 - INFO - 10.0.0.50 2025-08-15 11:36:55,390 - INFO - config 2025-08-15 11:36:55,395 - INFO - config-nodemgr:active 2025-08-15 11:36:55,398 - INFO - api-server:active 2025-08-15 11:36:55,401 - INFO - schema:active 2025-08-15 11:36:55,404 - INFO - svc-monitor:backup 2025-08-15 11:36:55,407 - INFO - device-manager:active 2025-08-15 11:36:55,407 - INFO - config-database 2025-08-15 11:36:55,407 - INFO - config-cassandra:active 2025-08-15 11:36:55,408 - INFO - config-zookeeper:active 2025-08-15 11:36:55,408 - INFO - config-rabbitmq:active 2025-08-15 11:36:55,408 - INFO - control 2025-08-15 11:36:55,412 - INFO - control-nodemgr:active 2025-08-15 11:36:55,417 - INFO - control:active 2025-08-15 11:36:55,417 - INFO - named:active 2025-08-15 11:36:55,422 - INFO - dns:active 2025-08-15 11:36:55,422 - INFO - analytics 2025-08-15 11:36:55,426 - INFO - analytics-nodemgr:active 2025-08-15 11:36:55,429 - INFO - analytics-api:active 2025-08-15 11:36:55,434 - INFO - collector:active 2025-08-15 11:36:55,434 - INFO - analytics-database 2025-08-15 11:36:55,434 - INFO - analytics-cassandra:active 2025-08-15 11:36:55,438 - INFO - analyticsdb-nodemgr:active 2025-08-15 11:36:55,443 - INFO - query-engine:active 2025-08-15 11:36:55,443 - INFO - webui 2025-08-15 11:36:55,444 - INFO - webui:active 2025-08-15 11:36:55,444 - INFO - webui-middleware:active 2025-08-15 11:36:55,444 - INFO - redis:active 2025-08-15 11:36:55,444 - INFO - analytics_snmp 2025-08-15 11:36:55,447 - INFO - snmp-collector:active 2025-08-15 11:36:55,448 - INFO - snmp-topology:active 2025-08-15 11:36:55,448 - INFO - analytics_alarm 2025-08-15 11:36:55,448 - INFO - alarmgen:active 2025-08-15 11:36:55,544 - INFO - 10.0.0.22 2025-08-15 11:36:55,544 - INFO - config 2025-08-15 11:36:55,549 - INFO - config-nodemgr:active 2025-08-15 11:36:55,553 - INFO - api-server:active 2025-08-15 11:36:55,556 - INFO - schema:backup 2025-08-15 11:36:55,559 - INFO - svc-monitor:backup 2025-08-15 11:36:55,561 - INFO - device-manager:backup 2025-08-15 11:36:55,561 - INFO - config-database 2025-08-15 11:36:55,561 - INFO - config-cassandra:active 2025-08-15 11:36:55,561 - INFO - config-zookeeper:active 2025-08-15 11:36:55,562 - INFO - config-rabbitmq:active 2025-08-15 11:36:55,562 - INFO - control 2025-08-15 11:36:55,566 - INFO - control-nodemgr:active 2025-08-15 11:36:55,571 - INFO - control:active 2025-08-15 11:36:55,571 - INFO - named:active 2025-08-15 11:36:55,576 - INFO - dns:active 2025-08-15 11:36:55,577 - INFO - analytics 2025-08-15 11:36:55,581 - INFO - analytics-nodemgr:active 2025-08-15 11:36:55,585 - INFO - analytics-api:active 2025-08-15 11:36:55,590 - INFO - collector:active 2025-08-15 11:36:55,590 - INFO - analytics-database 2025-08-15 11:36:55,590 - INFO - analytics-cassandra:active 2025-08-15 11:36:55,594 - INFO - analyticsdb-nodemgr:active 2025-08-15 11:36:55,599 - INFO - query-engine:active 2025-08-15 11:36:55,599 - INFO - webui 2025-08-15 11:36:55,599 - INFO - webui:active 2025-08-15 11:36:55,599 - INFO - webui-middleware:active 2025-08-15 11:36:55,599 - INFO - redis:active 2025-08-15 11:36:55,600 - INFO - analytics_snmp 2025-08-15 11:36:55,603 - INFO - snmp-collector:active 2025-08-15 11:36:55,603 - INFO - snmp-topology:active 2025-08-15 11:36:55,603 - INFO - analytics_alarm 2025-08-15 11:36:55,603 - INFO - alarmgen:active 2025-08-15 11:36:55,699 - INFO - 10.0.0.19 2025-08-15 11:36:55,699 - INFO - config 2025-08-15 11:36:55,704 - INFO - config-nodemgr:active 2025-08-15 11:36:55,708 - INFO - api-server:active 2025-08-15 11:36:55,711 - INFO - schema:backup 2025-08-15 11:36:55,714 - INFO - svc-monitor:active 2025-08-15 11:36:55,717 - INFO - device-manager:backup 2025-08-15 11:36:55,717 - INFO - config-database 2025-08-15 11:36:55,717 - INFO - config-cassandra:active 2025-08-15 11:36:55,717 - INFO - config-zookeeper:active 2025-08-15 11:36:55,717 - INFO - config-rabbitmq:active 2025-08-15 11:36:55,717 - INFO - control 2025-08-15 11:36:55,721 - INFO - control-nodemgr:active 2025-08-15 11:36:55,726 - INFO - control:active 2025-08-15 11:36:55,726 - INFO - named:active 2025-08-15 11:36:55,730 - INFO - dns:active 2025-08-15 11:36:55,730 - INFO - analytics 2025-08-15 11:36:55,734 - INFO - analytics-nodemgr:active 2025-08-15 11:36:55,738 - INFO - analytics-api:active 2025-08-15 11:36:55,743 - INFO - collector:active 2025-08-15 11:36:55,743 - INFO - analytics-database 2025-08-15 11:36:55,743 - INFO - analytics-cassandra:active 2025-08-15 11:36:55,747 - INFO - analyticsdb-nodemgr:active 2025-08-15 11:36:55,753 - INFO - query-engine:active 2025-08-15 11:36:55,753 - INFO - webui 2025-08-15 11:36:55,753 - INFO - webui:active 2025-08-15 11:36:55,753 - INFO - webui-middleware:active 2025-08-15 11:36:55,753 - INFO - redis:active 2025-08-15 11:36:55,753 - INFO - analytics_snmp 2025-08-15 11:36:55,756 - INFO - snmp-collector:active 2025-08-15 11:36:55,756 - INFO - snmp-topology:active 2025-08-15 11:36:55,756 - INFO - analytics_alarm 2025-08-15 11:36:55,756 - INFO - alarmgen:active 2025-08-15 11:36:55,853 - INFO - 10.0.0.241 2025-08-15 11:36:55,853 - INFO - vrouter 2025-08-15 11:36:55,860 - INFO - vrouter-nodemgr:active 2025-08-15 11:36:55,865 - INFO - agent:active 2025-08-15 11:36:55,964 - INFO - 10.0.0.242 2025-08-15 11:36:55,965 - INFO - vrouter 2025-08-15 11:36:55,969 - INFO - vrouter-nodemgr:active 2025-08-15 11:36:55,974 - INFO - agent:active 2025-08-15 11:36:55,974 - INFO - All the contrail services are up on all nodes 2025-08-15 11:36:55,974 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.254:5269'] servers UP 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1 connected to xmpp 10.20.0.254 2025-08-15 11:36:56,062 - WARNING - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.14:5269'] servers NOT UP 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.25:5269'] servers UP 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1 connected to xmpp 10.20.0.25 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.254:53'] servers UP 2025-08-15 11:36:56,062 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1 connected to dns 10.20.0.254 2025-08-15 11:36:56,063 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.14:53'] servers UP 2025-08-15 11:36:56,063 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1 connected to dns 10.20.0.14 2025-08-15 11:36:56,063 - WARNING - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.20.0.25:53'] servers NOT UP 2025-08-15 11:36:56,063 - WARNING - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.0.0.50:8086'] servers NOT UP 2025-08-15 11:36:56,063 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.0.0.22:8086'] servers UP 2025-08-15 11:36:56,063 - INFO - an-jenkins-deploy-platform-ansible-os-3861-1 connected to collector 10.0.0.22 2025-08-15 11:36:56,063 - WARNING - an-jenkins-deploy-platform-ansible-os-3861-1:contrail-vrouter-agent module connection to ['10.0.0.19:8086'] servers NOT UP 2025-08-15 11:36:56,063 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:36:56,127 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-1:contrail-control module connection to 10.0.0.50:9041 servers UP 2025-08-15 11:36:56,127 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-1:contrail-control module connection to 10.0.0.50:5673 servers UP 2025-08-15 11:36:56,127 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-1:contrail-control module connection to ['10.0.0.50:8086'] servers UP 2025-08-15 11:36:56,127 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:36:56,181 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-2:contrail-control module connection to 10.0.0.50:9041 servers UP 2025-08-15 11:36:56,182 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-2:contrail-control module connection to 10.0.0.50:5673 servers UP 2025-08-15 11:36:56,182 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-2:contrail-control module connection to ['10.0.0.50:8086'] servers UP 2025-08-15 11:36:56,182 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-3861-3?flat 2025-08-15 11:36:56,199 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-3:contrail-control module connection to 10.0.0.50:9041 servers UP 2025-08-15 11:36:56,199 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-3:contrail-control module connection to 10.0.0.50:5673 servers UP 2025-08-15 11:36:56,200 - INFO - cn-jenkins-deploy-platform-ansible-os-3861-3:contrail-control module connection to ['10.0.0.50:8086'] servers UP 2025-08-15 11:36:56,200 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-3861-1.?flat 2025-08-15 11:36:56,221 - DEBUG - contrail-api is running 2025-08-15 11:36:56,221 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-3861-2.?flat 2025-08-15 11:36:56,240 - DEBUG - contrail-api is running 2025-08-15 11:36:56,240 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-3861-3.?flat 2025-08-15 11:36:56,259 - DEBUG - contrail-api is running 2025-08-15 11:36:56,519 - INFO - Created VN ctest-vn3-61643000, UUID :1cebbd3e-8b4e-4d36-bd14-399f2beaa634 2025-08-15 11:36:56,888 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:36:56,912 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:36:56,922 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:36:57,025 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,037 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,047 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:36:57,055 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:36:57,062 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/78c7ef69-9811-486e-8e1a-099451b4579d 2025-08-15 11:36:57,068 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:36:57,068 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,095 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:36:57,114 - INFO - Verified VN network id 15 for VN aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,114 - INFO - Verifications in API Server for VN ctest-vn1-39202296 passed 2025-08-15 11:36:57,114 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,144 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:36:57,155 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:36:57,162 - DEBUG - Requesting: http://10.0.0.50:8082/route-target/78c7ef69-9811-486e-8e1a-099451b4579d 2025-08-15 11:36:57,177 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '1', 'advertised': '1', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:05.589387'} 2025-08-15 11:36:57,182 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:36:57,188 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:00.023401'} 2025-08-15 11:36:57,194 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:36:57,200 - DEBUG - Control-node 10.0.0.19 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-91341447', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12440466209766459287', 'uuid-lslong': '10247643594725285298'}, 'enable': 'true', 'created': '2025-08-15T11:34:12', 'last-modified': '2025-08-15T11:34:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:54.525993'} 2025-08-15 11:36:57,205 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-08-15 11:36:57,205 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-39202296 passed 2025-08-15 11:36:57,206 - DEBUG - ====Verifying policy data for ctest-vn1-39202296 in API_Server ====== 2025-08-15 11:36:57,206 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:36:57,211 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:36:57,222 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:36:57,317 - DEBUG - Requesting: http://10.0.0.50:8082/virtual-network/aca56a1a-f961-4797-8e36-f18e18685db2 2025-08-15 11:36:57,327 - DEBUG - ==>Verifying data for policy with id: 9cd8a5af-e2f7-45e1-8138-17a09a161125, fqn: ['default-domain', 'ctest-TestBasicVMVN0-91341447', 'policy1'] 2025-08-15 11:36:57,327 - INFO - VN ctest-vn1-39202296 Policy verification: verify_vn_policy_in_api_server, status: True 2025-08-15 11:36:57,327 - DEBUG - Verifying the vn in opserver 2025-08-15 11:36:57,327 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.50 2025-08-15 11:36:57,327 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks 2025-08-15 11:36:57,338 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:36:57,338 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.22 2025-08-15 11:36:57,338 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-08-15 11:36:57,388 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:36:57,388 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 virtual network link through opserver 10.0.0.19 2025-08-15 11:36:57,388 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-networks 2025-08-15 11:36:57,436 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat'} 2025-08-15 11:36:57,436 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is found in opserver 2025-08-15 11:36:57,446 - DEBUG - VRF ids for VN ctest-vn1-39202296: {'10.0.0.242': '2'} 2025-08-15 11:36:58,547 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-2) 2025-08-15 11:36:58,585 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 11:37:03,671 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:37:03,671 - INFO - VM name : ctest-vn1_vm2-95518324 2025-08-15 11:37:03,768 - DEBUG - VM ctest-vn1_vm2-95518324 ID is 64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:03,842 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:37:03,842 - DEBUG - VM ctest-vn1_vm2-95518324 launched on Node an-jenkins-deploy-platform-ansible-os-3861-2 2025-08-15 11:37:03,913 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:03,945 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:03,953 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/92f23c7d-ca52-4551-a8d3-683e97e260a3 2025-08-15 11:37:03,961 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:03,968 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/92f23c7d-ca52-4551-a8d3-683e97e260a3 2025-08-15 11:37:03,976 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/caedbe15-7a98-482c-aa99-014980410d9a 2025-08-15 11:37:03,984 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:37:03,984 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:03,991 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/92f23c7d-ca52-4551-a8d3-683e97e260a3 2025-08-15 11:37:03,999 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/caedbe15-7a98-482c-aa99-014980410d9a 2025-08-15 11:37:04,006 - INFO - VM ctest-vn1_vm2-95518324 verfication in all API Servers passed 2025-08-15 11:37:04,023 - DEBUG - VM ctest-vn1_vm2-95518324 Tap interface: {'index': '4', 'name': 'tap92f23c7d-ca', 'uuid': '92f23c7d-ca52-4551-a8d3-683e97e260a3', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296:ctest-vn1-39202296', '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': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'vm_uuid': '64b7c905-90df-4b53-99ea-0cef9825050a', 'vm_name': 'ctest-vn1_vm2-95518324', 'ip_addr': '192.168.1.251', 'mac_addr': '02:92:f2:3c:7d:ca', '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-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '33', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:37:04,023 - DEBUG - Agent 10.0.0.242 vrf name: default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296:ctest-vn1-39202296 2025-08-15 11:37:04,029 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296:ctest-vn1-39202296', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'table_label': '-1', 'vxlan_id': '15', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.18:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2025-08-15 11:37:04,113 - DEBUG - VM ctest-vn1_vm2-95518324 : Tap interface tap92f23c7d-ca is set to Active 2025-08-15 11:37:04,113 - DEBUG - Tap interface tap92f23c7d-ca detail : {'index': '4', 'name': 'tap92f23c7d-ca', 'uuid': '92f23c7d-ca52-4551-a8d3-683e97e260a3', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296:ctest-vn1-39202296', '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': '15', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'vm_uuid': '64b7c905-90df-4b53-99ea-0cef9825050a', 'vm_name': 'ctest-vn1_vm2-95518324', 'ip_addr': '192.168.1.251', 'mac_addr': '02:92:f2:3c:7d:ca', '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-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '33', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:37:04,220 - DEBUG - Starting Layer 2 verification in Agent 2025-08-15 11:37:04,233 - DEBUG - Layer 2 path is seen for VM MAC 02:92:f2:3c:7d:ca in agent 10.0.0.242 2025-08-15 11:37:04,233 - DEBUG - Active layer 2 route in agent is present for VMI tap92f23c7d-ca 2025-08-15 11:37:04,233 - DEBUG - L2 label(34) matches bw route table and interface table 2025-08-15 11:37:04,248 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is found in Agent of node 10.0.0.242 2025-08-15 11:37:04,380 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is consistent in agent 10.0.0.242 2025-08-15 11:37:04,380 - DEBUG - Route for VM IP ['192.168.1.251'] is consistent in agent 10.0.0.242 2025-08-15 11:37:04,380 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 verification for VM ctest-vn1_vm2-95518324 in Agent 10.0.0.242 passed 2025-08-15 11:37:04,498 - DEBUG - Starting all layer 2 verification in agent 10.0.0.242 2025-08-15 11:37:04,514 - DEBUG - Route for VM MAC 02:92:f2:3c:7d:ca is consistent in agent 10.0.0.242 2025-08-15 11:37:07,697 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2025-08-15 11:37:07,697 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:07,709 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:11,796 - 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 1028ms') 2025-08-15 11:37:11,796 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:11,815 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:15,893 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-08-15 11:37:15,893 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:15,906 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:19,986 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2025-08-15 11:37:19,986 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:19,998 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:24,086 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:37:24,086 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:24,098 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:28,177 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:37:28,177 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:28,190 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:32,269 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:37:32,269 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 failed! 2025-08-15 11:37:32,283 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 is 192.168.1.254 and allocation pool is NOT set 2025-08-15 11:37:36,367 - 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=4.80 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1027ms\r\nrtt min/avg/max/mdev = 4.799/4.799/4.799/0.000 ms') 2025-08-15 11:37:36,367 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 passed 2025-08-15 11:37:36,367 - INFO - VM ctest-vn1_vm2-95518324 verifications in Compute nodes passed 2025-08-15 11:37:36,608 - DEBUG - Validated VM route 192.168.1.251 in vrouter of 10.0.0.242 2025-08-15 11:37:36,611 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2025-08-15 11:37:36,611 - INFO - Validated routes of VM ctest-vn1_vm2-95518324 in all vrouters 2025-08-15 11:37:37,041 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2025-08-15 11:37:37,159 - DEBUG - Layer2 route found for VM MAC 02:92:f2:3c:7d:ca in Control-node 10.0.0.50 2025-08-15 11:37:37,159 - DEBUG - L2 Label for VM ctest-vn1_vm2-95518324 same between Control-node 10.0.0.50 and Agent, Expected: 34, Seen: 34 2025-08-15 11:37:37,159 - DEBUG - Starting all layer2 verification in 10.0.0.19 Control Node 2025-08-15 11:37:37,281 - DEBUG - Layer2 route found for VM MAC 02:92:f2:3c:7d:ca in Control-node 10.0.0.19 2025-08-15 11:37:37,281 - DEBUG - L2 Label for VM ctest-vn1_vm2-95518324 same between Control-node 10.0.0.19 and Agent, Expected: 34, Seen: 34 2025-08-15 11:37:37,281 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-95518324 passed 2025-08-15 11:37:37,281 - DEBUG - Verifying the vm in opserver 2025-08-15 11:37:37,281 - DEBUG - Verifying in collector 10.0.0.19 ... 2025-08-15 11:37:37,281 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat 2025-08-15 11:37:37,332 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3?flat 2025-08-15 11:37:37,356 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3?flat 2025-08-15 11:37:37,379 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat 2025-08-15 11:37:37,394 - DEBUG - Verifying vm in vn uve 2025-08-15 11:37:37,394 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3?flat 2025-08-15 11:37:37,416 - DEBUG - VM uve shows interface as {'ip6_address': '::', 'ip6_active': False, 'vhostuser_mode': 0, 'vm_uuid': '64b7c905-90df-4b53-99ea-0cef9825050a', 'ip4_active': True, 'admin_state': True, 'port_mirror_enabled': False, 'gateway': '192.168.1.254', 'label': 30, 'l2_active': True, 'mac_address': '02:92:f2:3c:7d:ca', 'active': True, 'tx_vlan': 65535, 'vn_uuid': 'aca56a1a-f961-4797-8e36-f18e18685db2', 'ip_address': '192.168.1.251', 'rx_vlan': 65535, '__T': 1755257836147938, 'uuid': '92f23c7d-ca52-4551-a8d3-683e97e260a3', 'is_health_check_active': True, 'fixed_ip4_list': ['192.168.1.251'], 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296', 'vm_name': 'ctest-vn1_vm2-95518324'} 2025-08-15 11:37:37,416 - DEBUG - VM uve shows ip address as ['192.168.1.251', '::'] 2025-08-15 11:37:37,416 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:37:37,416 - INFO - Verifying through opserver in 10.0.0.50 2025-08-15 11:37:37,416 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat 2025-08-15 11:37:37,446 - DEBUG - expected vm list 64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:37:37,446 - DEBUG - Extracted vm list ['64b7c905-90df-4b53-99ea-0cef9825050a'] 2025-08-15 11:37:37,446 - INFO - VM 64b7c905-90df-4b53-99ea-0cef9825050a is present in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:37:37,446 - DEBUG - Verifying vm in vrouter uve 2025-08-15 11:37:37,446 - DEBUG - Getting info from collector 10.0.0.19.. 2025-08-15 11:37:37,446 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat 2025-08-15 11:37:37,503 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-3861-2'] 2025-08-15 11:37:37,503 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:37:37,562 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:37:37,637 - DEBUG - VM 64b7c905-90df-4b53-99ea-0cef9825050a is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:37:37,637 - DEBUG - Validated that VM ctest-vn1_vm2-95518324 is in Vrouter an-jenkins-deploy-platform-ansible-os-3861-2 UVE 2025-08-15 11:37:37,637 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2025-08-15 11:37:37,644 - DEBUG - Expected tap interface of VM uuid 64b7c905-90df-4b53-99ea-0cef9825050a is default-domain:ctest-TestBasicVMVN0-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3 2025-08-15 11:37:37,644 - DEBUG - Expected VN of VM uuid 64b7c905-90df-4b53-99ea-0cef9825050a is default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:37:37,644 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:37:37,702 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:37:37,737 - DEBUG - VM 64b7c905-90df-4b53-99ea-0cef9825050a is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:37:37,737 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-91341447:92f23c7d-ca52-4551-a8d3-683e97e260a3 of vm 64b7c905-90df-4b53-99ea-0cef9825050a is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:37:37,737 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 of vm 64b7c905-90df-4b53-99ea-0cef9825050a is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:37:37,737 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.50 2025-08-15 11:37:37,737 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:37:37,749 - DEBUG - VM link and name as {'name': '64b7c905-90df-4b53-99ea-0cef9825050a', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat'} 2025-08-15 11:37:37,749 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.22 2025-08-15 11:37:37,749 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:37:37,795 - DEBUG - VM link and name as {'name': '64b7c905-90df-4b53-99ea-0cef9825050a', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat'} 2025-08-15 11:37:37,795 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.19 2025-08-15 11:37:37,795 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:37:37,806 - DEBUG - VM link and name as {'name': '64b7c905-90df-4b53-99ea-0cef9825050a', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a?flat'} 2025-08-15 11:37:37,806 - INFO - VM ctest-vn1_vm2-95518324 validations in Opserver passed 2025-08-15 11:37:38,902 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3861-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3861-1) 2025-08-15 11:37:38,955 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-08-15 11:37:44,021 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:37:44,021 - INFO - VM name : ctest-vn2_vm2-23788192 2025-08-15 11:37:44,087 - DEBUG - VM ctest-vn2_vm2-23788192 ID is 4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:37:44,155 - DEBUG - VM is in ACTIVE state now 2025-08-15 11:37:44,155 - DEBUG - VM ctest-vn2_vm2-23788192 launched on Node an-jenkins-deploy-platform-ansible-os-3861-1 2025-08-15 11:37:44,224 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:37:44,233 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:37:44,239 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6151cec9-e9ef-4625-a639-e43569646319 2025-08-15 11:37:44,248 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:37:44,254 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6151cec9-e9ef-4625-a639-e43569646319 2025-08-15 11:37:44,262 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/2c5df5c4-777f-42ab-b2c8-81abb8d80041 2025-08-15 11:37:44,271 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:37:44,271 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:37:44,277 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6151cec9-e9ef-4625-a639-e43569646319 2025-08-15 11:37:44,285 - DEBUG - Requesting: http://10.0.0.19:8082/instance-ip/2c5df5c4-777f-42ab-b2c8-81abb8d80041 2025-08-15 11:37:44,292 - INFO - VM ctest-vn2_vm2-23788192 verfication in all API Servers passed 2025-08-15 11:37:44,309 - DEBUG - VM ctest-vn2_vm2-23788192 Tap interface: {'index': '4', 'name': 'tap6151cec9-e9', 'uuid': '6151cec9-e9ef-4625-a639-e43569646319', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845:ctest-vn2-30302845', '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': '16', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'vm_uuid': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'vm_name': 'ctest-vn2_vm2-23788192', 'ip_addr': '192.168.2.251', 'mac_addr': '02:61:51:ce:c9:e9', '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-91341447:6151cec9-e9ef-4625-a639-e43569646319', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '30', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:37:44,310 - DEBUG - Agent 10.0.0.241 vrf name: default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845:ctest-vn2-30302845 2025-08-15 11:37:44,315 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845:ctest-vn2-30302845', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'table_label': '-1', 'vxlan_id': '16', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.193:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]} 2025-08-15 11:37:44,397 - DEBUG - VM ctest-vn2_vm2-23788192 : Tap interface tap6151cec9-e9 is set to Active 2025-08-15 11:37:44,398 - DEBUG - Tap interface tap6151cec9-e9 detail : {'index': '4', 'name': 'tap6151cec9-e9', 'uuid': '6151cec9-e9ef-4625-a639-e43569646319', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845:ctest-vn2-30302845', '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': '16', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'vm_uuid': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'vm_name': 'ctest-vn2_vm2-23788192', 'ip_addr': '192.168.2.251', 'mac_addr': '02:61:51:ce:c9:e9', '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-91341447:6151cec9-e9ef-4625-a639-e43569646319', 'sg_uuid_list': ['09a22155-3d23-44c5-b542-864b7df18680'], 'static_route_list': None, 'vm_project_uuid': 'b284f49e-c20a-42ff-98ed-9106ec628dee', 'admin_state': 'Enabled', 'flow_key_idx': '30', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []} 2025-08-15 11:37:44,503 - DEBUG - Starting Layer 2 verification in Agent 2025-08-15 11:37:44,516 - DEBUG - Layer 2 path is seen for VM MAC 02:61:51:ce:c9:e9 in agent 10.0.0.241 2025-08-15 11:37:44,516 - DEBUG - Active layer 2 route in agent is present for VMI tap6151cec9-e9 2025-08-15 11:37:44,516 - DEBUG - L2 label(34) matches bw route table and interface table 2025-08-15 11:37:44,524 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is found in Agent of node 10.0.0.241 2025-08-15 11:37:44,657 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is consistent in agent 10.0.0.241 2025-08-15 11:37:44,657 - DEBUG - Route for VM IP ['192.168.2.251'] is consistent in agent 10.0.0.241 2025-08-15 11:37:44,657 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 verification for VM ctest-vn2_vm2-23788192 in Agent 10.0.0.241 passed 2025-08-15 11:37:44,767 - DEBUG - Starting all layer 2 verification in agent 10.0.0.241 2025-08-15 11:37:44,780 - DEBUG - Route for VM MAC 02:61:51:ce:c9:e9 is consistent in agent 10.0.0.241 2025-08-15 11:37:47,975 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms') 2025-08-15 11:37:47,975 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:37:47,987 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:37:52,077 - 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 1028ms') 2025-08-15 11:37:52,077 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:37:52,089 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:37:56,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 1023ms') 2025-08-15 11:37:56,167 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:37:56,178 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:00,267 - 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 1025ms') 2025-08-15 11:38:00,268 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:38:00,280 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:04,355 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-08-15 11:38:04,356 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:38:04,368 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:08,457 - 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 1030ms') 2025-08-15 11:38:08,457 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:38:08,469 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:12,551 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:38:12,551 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:38:12,564 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:16,642 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1023ms') 2025-08-15 11:38:16,642 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 failed! 2025-08-15 11:38:16,659 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 is 192.168.2.254 and allocation pool is NOT set 2025-08-15 11:38:18,725 - 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=11.7 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.95 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.946/7.346/11.746/4.400 ms') 2025-08-15 11:38:18,725 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 passed 2025-08-15 11:38:18,725 - INFO - VM ctest-vn2_vm2-23788192 verifications in Compute nodes passed 2025-08-15 11:38:18,929 - DEBUG - Validated VM route 192.168.2.251 in vrouter of 10.0.0.241 2025-08-15 11:38:18,932 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0 2025-08-15 11:38:18,932 - INFO - Validated routes of VM ctest-vn2_vm2-23788192 in all vrouters 2025-08-15 11:38:19,363 - DEBUG - Starting all layer2 verification in 10.0.0.50 Control Node 2025-08-15 11:38:19,491 - DEBUG - Layer2 route found for VM MAC 02:61:51:ce:c9:e9 in Control-node 10.0.0.50 2025-08-15 11:38:19,491 - DEBUG - L2 Label for VM ctest-vn2_vm2-23788192 same between Control-node 10.0.0.50 and Agent, Expected: 34, Seen: 34 2025-08-15 11:38:19,491 - DEBUG - Starting all layer2 verification in 10.0.0.19 Control Node 2025-08-15 11:38:19,609 - DEBUG - Layer2 route found for VM MAC 02:61:51:ce:c9:e9 in Control-node 10.0.0.19 2025-08-15 11:38:19,609 - DEBUG - L2 Label for VM ctest-vn2_vm2-23788192 same between Control-node 10.0.0.19 and Agent, Expected: 34, Seen: 34 2025-08-15 11:38:19,610 - INFO - Verification in Control-nodes for VM ctest-vn2_vm2-23788192 passed 2025-08-15 11:38:19,610 - DEBUG - Verifying the vm in opserver 2025-08-15 11:38:19,610 - DEBUG - Verifying in collector 10.0.0.19 ... 2025-08-15 11:38:19,610 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat 2025-08-15 11:38:19,623 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6151cec9-e9ef-4625-a639-e43569646319?flat 2025-08-15 11:38:19,642 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6151cec9-e9ef-4625-a639-e43569646319?flat 2025-08-15 11:38:19,659 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat 2025-08-15 11:38:19,675 - DEBUG - Verifying vm in vn uve 2025-08-15 11:38:19,675 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-91341447:6151cec9-e9ef-4625-a639-e43569646319?flat 2025-08-15 11:38:19,692 - DEBUG - VM uve shows interface as {'ip6_address': '::', 'ip6_active': False, 'vhostuser_mode': 0, 'vm_uuid': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'ip4_active': True, 'admin_state': True, 'port_mirror_enabled': False, 'gateway': '192.168.2.254', 'label': 30, 'l2_active': True, 'mac_address': '02:61:51:ce:c9:e9', 'active': True, 'tx_vlan': 65535, 'vn_uuid': 'a334a6cd-c495-4f5f-9ece-e68100dce129', 'ip_address': '192.168.2.251', 'rx_vlan': 65535, '__T': 1755257887730699, 'uuid': '6151cec9-e9ef-4625-a639-e43569646319', 'is_health_check_active': True, 'fixed_ip4_list': ['192.168.2.251'], 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845', 'vm_name': 'ctest-vn2_vm2-23788192'} 2025-08-15 11:38:19,692 - DEBUG - VM uve shows ip address as ['192.168.2.251', '::'] 2025-08-15 11:38:19,692 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:38:19,692 - INFO - Verifying through opserver in 10.0.0.50 2025-08-15 11:38:19,692 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845?flat 2025-08-15 11:38:19,712 - DEBUG - expected vm list 4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:38:19,712 - DEBUG - Extracted vm list ['4e4975d3-897a-4480-a12b-2ab4c5c98070'] 2025-08-15 11:38:19,712 - INFO - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is present in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:38:19,712 - DEBUG - Verifying vm in vrouter uve 2025-08-15 11:38:19,712 - DEBUG - Getting info from collector 10.0.0.19.. 2025-08-15 11:38:19,713 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat 2025-08-15 11:38:19,725 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-3861-1'] 2025-08-15 11:38:19,725 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:38:19,769 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:38:19,802 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:38:19,802 - DEBUG - Validated that VM ctest-vn2_vm2-23788192 is in Vrouter an-jenkins-deploy-platform-ansible-os-3861-1 UVE 2025-08-15 11:38:19,802 - DEBUG - Verifying vm tap interface/vn in vrouter uve 2025-08-15 11:38:19,809 - DEBUG - Expected tap interface of VM uuid 4e4975d3-897a-4480-a12b-2ab4c5c98070 is default-domain:ctest-TestBasicVMVN0-91341447:6151cec9-e9ef-4625-a639-e43569646319 2025-08-15 11:38:19,809 - DEBUG - Expected VN of VM uuid 4e4975d3-897a-4480-a12b-2ab4c5c98070 is default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:38:19,809 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:38:19,853 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:38:19,885 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:38:19,885 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-91341447:6151cec9-e9ef-4625-a639-e43569646319 of vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:38:19,885 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 of vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 is present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:38:19,885 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.50 2025-08-15 11:38:19,885 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:38:19,895 - DEBUG - VM link and name as {'name': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat'} 2025-08-15 11:38:19,896 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.22 2025-08-15 11:38:19,896 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:38:19,907 - DEBUG - VM link and name as {'name': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat'} 2025-08-15 11:38:19,907 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.19 2025-08-15 11:38:19,907 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:38:19,917 - DEBUG - VM link and name as {'name': '4e4975d3-897a-4480-a12b-2ab4c5c98070', 'href': 'http://10.0.0.19:8081/analytics/uves/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070?flat'} 2025-08-15 11:38:19,917 - INFO - VM ctest-vn2_vm2-23788192 validations in Opserver passed 2025-08-15 11:38:19,917 - INFO - Waiting for VM ctest-vn1_vm2-95518324 to be up.. 2025-08-15 11:38:19,917 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:19,917 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:38:19,923 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/92f23c7d-ca52-4551-a8d3-683e97e260a3 2025-08-15 11:38:21,067 - 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.49 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.647 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.647/2.068/3.490/1.421 ms') 2025-08-15 11:38:21,067 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-95518324 passed 2025-08-15 11:38:21,131 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:21,131 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-95518324, IP 192.168.1.251, Port 22 2025-08-15 11:38:21,296 - DEBUG - VM ctest-vn1_vm2-95518324 is ready for SSH connections 2025-08-15 11:38:21,296 - INFO - Waiting for VM ctest-vn2_vm2-23788192 to be up.. 2025-08-15 11:38:21,296 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:21,296 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:38:21,304 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine-interface/6151cec9-e9ef-4625-a639-e43569646319 2025-08-15 11:38:22,464 - 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.21 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=1.10 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 1.099/2.153/3.208/1.054 ms') 2025-08-15 11:38:22,464 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-23788192 passed 2025-08-15 11:38:22,532 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:22,532 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-23788192, IP 192.168.2.251, Port 22 2025-08-15 11:38:22,599 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:38:22,674 - DEBUG - VM ctest-vn2_vm2-23788192 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:38:27,675 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:27,675 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-23788192, IP 192.168.2.251, Port 22 2025-08-15 11:38:27,742 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:38:27,843 - DEBUG - VM ctest-vn2_vm2-23788192 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:38:32,844 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:32,844 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-23788192, IP 192.168.2.251, Port 22 2025-08-15 11:38:32,911 - DEBUG - Error on ssh to ubuntu@169.254.0.4:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-08-15 11:38:32,990 - DEBUG - VM ctest-vn2_vm2-23788192 is NOT ready for SSH connections, VM status: ACTIVE 2025-08-15 11:38:37,991 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:37,991 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-23788192, IP 192.168.2.251, Port 22 2025-08-15 11:38:38,148 - DEBUG - VM ctest-vn2_vm2-23788192 is ready for SSH connections 2025-08-15 11:38:38,148 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-08-15 11:38:38,148 - 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.242, gateway password: c0ntrail123 2025-08-15 11:38:38,148 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.251 2025-08-15 11:39:15,658 - 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=11.9 ms 64 bytes from 192.168.2.251: icmp_req=2 ttl=63 time=1.32 ms 64 bytes from 192.168.2.251: icmp_req=3 ttl=63 time=1.03 ms --- 192.168.2.251 ping statistics --- 3 packets transmitted, 3 received, 0% packet loss, time 2003ms rtt min/avg/max/mdev = 1.032/4.758/11.915/5.062 ms 2025-08-15 11:39:15,659 - INFO - Ping to IP 192.168.2.251 from VM ctest-vn1_vm2-95518324 passed 2025-08-15 11:39:15,659 - INFO - Deleting VM ctest-vn2_vm2-23788192 2025-08-15 11:39:15,718 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:39:15,718 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:39:15,726 - DEBUG - VM ID 4e4975d3-897a-4480-a12b-2ab4c5c98070 of VM ctest-vn2_vm2-23788192 is still found in API Server 2025-08-15 11:39:17,726 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:39:17,727 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:39:17,733 - DEBUG - Response Code: 404 2025-08-15 11:39:17,733 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:39:17,738 - DEBUG - Response Code: 404 2025-08-15 11:39:17,738 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/4e4975d3-897a-4480-a12b-2ab4c5c98070 2025-08-15 11:39:17,742 - DEBUG - Response Code: 404 2025-08-15 11:39:17,743 - INFO - VM ctest-vn2_vm2-23788192 is fully removed in API-Server 2025-08-15 11:39:17,895 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2025-08-15 11:39:18,073 - DEBUG - VM route 192.168.2.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 of compute 10.0.0.241 2025-08-15 11:39:18,076 - DEBUG - Validated that vrouter 10.0.0.241 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:39:18,076 - DEBUG - Validated that vrouter 10.0.0.242 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:39:18,076 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 2025-08-15 11:39:18,077 - INFO - VM ctest-vn2_vm2-23788192 is removed in Compute, and routes are removed in all compute nodes 2025-08-15 11:39:18,283 - INFO - Routes for VM ctest-vn2_vm2-23788192 is removed in all control-nodes 2025-08-15 11:39:18,283 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:18,330 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:18,364 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:18,364 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:18,364 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:18,364 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:21,365 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:21,413 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:21,447 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:21,447 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:21,447 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:21,448 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:24,449 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:24,494 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:24,530 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:24,530 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:24,530 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:24,530 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:27,530 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:27,582 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:27,619 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:27,619 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:27,619 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:27,619 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:30,620 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:30,667 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:30,701 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:30,701 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:30,701 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:30,701 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:33,702 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:33,747 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:33,780 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:33,780 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:33,780 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:33,780 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:36,781 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:36,827 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:36,862 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:36,862 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:36,862 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:36,862 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:39,863 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-1:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:39,912 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-1?flat 2025-08-15 11:39:39,947 - DEBUG - VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is not present in vrouter an-jenkins-deploy-platform-ansible-os-3861-1 uve 2025-08-15 11:39:39,947 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:39,947 - DEBUG - interface for vm 4e4975d3-897a-4480-a12b-2ab4c5c98070 deleted from vrouter uve ... 2025-08-15 11:39:39,947 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:39,947 - DEBUG - Validated that VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is removed in Vrouter UVE 2025-08-15 11:39:39,947 - DEBUG - Verifying through opserver in 10.0.0.50 2025-08-15 11:39:39,947 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845?flat 2025-08-15 11:39:39,971 - DEBUG - 4e4975d3-897a-4480-a12b-2ab4c5c98070 BM not in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn2-30302845 uve 2025-08-15 11:39:39,971 - DEBUG - Validated that VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is not present in the VN UVE 2025-08-15 11:39:39,971 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.50 2025-08-15 11:39:39,971 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:39:39,983 - INFO - 4e4975d3-897a-4480-a12b-2ab4c5c98070 vm uve deleted from opserver 2025-08-15 11:39:39,983 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.22 2025-08-15 11:39:39,983 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:39:39,994 - INFO - 4e4975d3-897a-4480-a12b-2ab4c5c98070 vm uve deleted from opserver 2025-08-15 11:39:39,994 - DEBUG - Verifying the 4e4975d3-897a-4480-a12b-2ab4c5c98070 virtual network link through opserver 10.0.0.19 2025-08-15 11:39:39,994 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:39:40,005 - INFO - 4e4975d3-897a-4480-a12b-2ab4c5c98070 vm uve deleted from opserver 2025-08-15 11:39:40,005 - INFO - Validated that VM 4e4975d3-897a-4480-a12b-2ab4c5c98070 is removed from Opserver 2025-08-15 11:39:40,005 - INFO - Deleting VM ctest-vn1_vm2-95518324 2025-08-15 11:39:40,067 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:39:40,067 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:39:40,075 - DEBUG - VM ID 64b7c905-90df-4b53-99ea-0cef9825050a of VM ctest-vn1_vm2-95518324 is still found in API Server 2025-08-15 11:39:42,076 - DEBUG - Verifying in api server 10.0.0.19 2025-08-15 11:39:42,076 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:39:42,082 - DEBUG - Response Code: 404 2025-08-15 11:39:42,082 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:39:42,087 - DEBUG - Response Code: 404 2025-08-15 11:39:42,088 - DEBUG - Requesting: http://10.0.0.19:8082/virtual-machine/64b7c905-90df-4b53-99ea-0cef9825050a 2025-08-15 11:39:42,092 - DEBUG - Response Code: 404 2025-08-15 11:39:42,092 - INFO - VM ctest-vn1_vm2-95518324 is fully removed in API-Server 2025-08-15 11:39:42,247 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found 2025-08-15 11:39:42,278 - DEBUG - Validated that vrouter 10.0.0.241 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:39:42,400 - DEBUG - VM route 192.168.1.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 of compute 10.0.0.242 2025-08-15 11:39:42,404 - DEBUG - Validated that vrouter 10.0.0.242 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:39:42,404 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:39:42,404 - INFO - VM ctest-vn1_vm2-95518324 is removed in Compute, and routes are removed in all compute nodes 2025-08-15 11:39:42,613 - INFO - Routes for VM ctest-vn1_vm2-95518324 is removed in all control-nodes 2025-08-15 11:39:42,613 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:42,679 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:39:42,715 - DEBUG - VM 64b7c905-90df-4b53-99ea-0cef9825050a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:39:42,715 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:42,715 - DEBUG - interface for vm 64b7c905-90df-4b53-99ea-0cef9825050a deleted from vrouter uve ... 2025-08-15 11:39:42,715 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:45,716 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:45,778 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:39:45,815 - DEBUG - VM 64b7c905-90df-4b53-99ea-0cef9825050a is still present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:39:45,815 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:45,815 - DEBUG - interface for vm 64b7c905-90df-4b53-99ea-0cef9825050a deleted from vrouter uve ... 2025-08-15 11:39:45,815 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:48,815 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-3861-2:Compute:contrail-vrouter-agent:0?flat 2025-08-15 11:39:48,877 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-3861-2?flat 2025-08-15 11:39:48,922 - DEBUG - VM 64b7c905-90df-4b53-99ea-0cef9825050a is not present in vrouter an-jenkins-deploy-platform-ansible-os-3861-2 uve 2025-08-15 11:39:48,922 - DEBUG - Verifying if the vm interface deleted from vroter uve... 2025-08-15 11:39:48,922 - DEBUG - interface for vm 64b7c905-90df-4b53-99ea-0cef9825050a deleted from vrouter uve ... 2025-08-15 11:39:48,922 - DEBUG - Deleted interface not in error interface list ... 2025-08-15 11:39:48,922 - DEBUG - Validated that VM 64b7c905-90df-4b53-99ea-0cef9825050a is removed in Vrouter UVE 2025-08-15 11:39:48,922 - DEBUG - Verifying through opserver in 10.0.0.50 2025-08-15 11:39:48,922 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296?flat 2025-08-15 11:39:48,946 - DEBUG - 64b7c905-90df-4b53-99ea-0cef9825050a BM not in default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 uve 2025-08-15 11:39:48,946 - DEBUG - Validated that VM 64b7c905-90df-4b53-99ea-0cef9825050a is not present in the VN UVE 2025-08-15 11:39:48,946 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.50 2025-08-15 11:39:48,946 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-machines 2025-08-15 11:39:48,956 - INFO - 64b7c905-90df-4b53-99ea-0cef9825050a vm uve deleted from opserver 2025-08-15 11:39:48,956 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.22 2025-08-15 11:39:48,956 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-machines 2025-08-15 11:39:48,969 - INFO - 64b7c905-90df-4b53-99ea-0cef9825050a vm uve deleted from opserver 2025-08-15 11:39:48,969 - DEBUG - Verifying the 64b7c905-90df-4b53-99ea-0cef9825050a virtual network link through opserver 10.0.0.19 2025-08-15 11:39:48,969 - DEBUG - Requesting: http://10.0.0.19:8081/analytics/uves/virtual-machines 2025-08-15 11:39:48,980 - INFO - 64b7c905-90df-4b53-99ea-0cef9825050a vm uve deleted from opserver 2025-08-15 11:39:48,980 - INFO - Validated that VM 64b7c905-90df-4b53-99ea-0cef9825050a is removed from Opserver 2025-08-15 11:39:48,980 - INFO - Deleting VN ctest-vn3-61643000 2025-08-15 11:39:49,106 - INFO - Deleting VM ctest-vn2_vm1-73729752 2025-08-15 11:39:49,175 - INFO - Deleting VM ctest-vn1_vm1-63627639 2025-08-15 11:39:49,401 - INFO - Deleting VN ctest-vn2-30302845 2025-08-15 11:39:49,455 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.19:8082/virtual-machine-interface/44a539a6-76c1-48e2-afe8-614a7e20221e'] while deleting VN ctest-vn2-30302845..Will retry 2025-08-15 11:39:51,562 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/8aea0dee-bd74-46a2-be76-d62b572c180f 2025-08-15 11:39:51,569 - DEBUG - Response Code: 404 2025-08-15 11:39:51,570 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:39:51,575 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:39:51,599 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:39:51,691 - INFO - Validated that VN ctest-vn2-30302845 is not found in API Server 2025-08-15 11:39:51,701 - DEBUG - VN ctest-vn2-30302845 is not present in Agent 10.0.0.241 2025-08-15 11:39:51,710 - DEBUG - VN ctest-vn2-30302845 is not present in Agent 10.0.0.242 2025-08-15 11:39:51,710 - INFO - Validated that VN ctest-vn2-30302845 is not in any agent 2025-08-15 11:39:51,739 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-30302845 info 2025-08-15 11:39:51,870 - INFO - Deleting VN ctest-vn1-39202296 2025-08-15 11:39:51,963 - DEBUG - Requesting: http://10.0.0.50:8082/routing-instance/2b8766a4-36df-4984-8b6e-6be46ad83e59 2025-08-15 11:39:51,968 - DEBUG - Response Code: 404 2025-08-15 11:39:51,968 - DEBUG - Requesting: http://10.0.0.50:8082/domains 2025-08-15 11:39:51,974 - DEBUG - Requesting: http://10.0.0.50:8082/domain/4d954f05-13b9-4014-b839-289a92604c21 2025-08-15 11:39:51,989 - DEBUG - Requesting: http://10.0.0.50:8082/project/b284f49e-c20a-42ff-98ed-9106ec628dee 2025-08-15 11:39:52,082 - INFO - Validated that VN ctest-vn1-39202296 is not found in API Server 2025-08-15 11:39:52,092 - DEBUG - VN ctest-vn1-39202296 is not present in Agent 10.0.0.241 2025-08-15 11:39:52,102 - DEBUG - VN ctest-vn1-39202296 is not present in Agent 10.0.0.242 2025-08-15 11:39:52,102 - INFO - Validated that VN ctest-vn1-39202296 is not in any agent 2025-08-15 11:39:52,107 - DEBUG - VRF 2 is not seen in agent 10.0.0.242 2025-08-15 11:39:52,111 - DEBUG - Vrouter 10.0.0.242 does not have vrf 2 for VN ctest-vn1-39202296 2025-08-15 11:39:52,112 - INFO - Validated that all vrouters do not have the route table for VN default-domain:ctest-TestBasicVMVN0-91341447:ctest-vn1-39202296 2025-08-15 11:39:52,134 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-39202296 info 2025-08-15 11:39:52,166 - INFO - Deleted policy policy2 2025-08-15 11:39:52,194 - INFO - Deleted policy policy1 2025-08-15 11:39:53,434 - DEBUG - Skipping xmpp flap check
2025-08-15 11:39:53,435 - INFO - END TEST : test_process_restart_in_policy_between_vns : PASSED[0:05:43]
2025-08-15 11:39:53,435 - INFO - -------------------------------------------------------------------------------- 2025-08-15 11:39:53,437 - INFO - ================================================================================ 2025-08-15 11:39:53,437 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling 2025-08-15 11:39:53,437 - INFO - TEST DESCRIPTION : Test the underlay brocast traffic handling by vrouter. (Bug-1545229). 1. Send broadcast traffic from one compute node. 2. Other compute in same subnet should receive that traffic. 3. Receiving compute should treat this traffic as underlay. 4. Compute should not replicate the packet and send the copy back. Pass criteria: Step 3-4 should pass Maintainer : chhandak@juniper.net 2025-08-15 11:39:54,674 - DEBUG - Skipping xmpp flap check 2025-08-15 11:39:54,674 - INFO - Initial checks done. Running the testcase now 2025-08-15 11:39:54,675 - INFO - 2025-08-15 11:39:55,055 - INFO - Agent interface name: ens6 2025-08-15 11:39:55,127 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U host 10.20.0.255 -w /tmp/ens6_ctest-random-14462177.pcap 2025-08-15 11:40:00,473 - INFO - Pinging broacast address 10.20.0.255 from compute 10.20.0.193 2025-08-15 11:40:14,785 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-15 11:40:16,922 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14462177.pcap | grep -c length 2025-08-15 11:40:16,933 - DEBUG - STDOUT: 10 2025-08-15 11:40:16,933 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14462177.pcap, link-type EN10MB (Ethernet), snapshot length 262144 2025-08-15 11:40:16,933 - INFO - 10 packets are found in tcpdump output as expected 2025-08-15 11:40:16,934 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}') 2025-08-15 11:40:18,976 - INFO - Packet count matched: Compute 10.0.0.242 has receive only 10 packet from source IP 10.20.0.255. No duplicate packet seen 2025-08-15 11:40:20,206 - DEBUG - Skipping xmpp flap check
2025-08-15 11:40:20,206 - INFO - END TEST : test_underlay_broadcast_traffic_handling : PASSED[0:00:27]
2025-08-15 11:40:20,206 - INFO - -------------------------------------------------------------------------------- 2025-08-15 11:40:20,906 - INFO - Deleted project: ctest-TestBasicVMVN0-91341447, ID : b284f49e-c20a-42ff-98ed-9106ec628dee