2025-10-08 18:26:18,335 - INFO - Domain Default found not creating
2025-10-08 18:26:18,505 - INFO - Project ctest-TestBasicVMVN0-71676797 not found, creating it
2025-10-08 18:26:19,035 - INFO - Created Project:ctest-TestBasicVMVN0-71676797, ID : c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:26:20,414 - INFO - ================================================================================
2025-10-08 18:26:20,414 - INFO - STARTING TEST : test_control_node_switchover
2025-10-08 18:26:20,414 - 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-10-08 18:26:21,707 - DEBUG - Skipping xmpp flap check
2025-10-08 18:26:21,707 - INFO - Initial checks done. Running the testcase now
2025-10-08 18:26:21,707 - INFO -
2025-10-08 18:26:22,413 - DEBUG - Response for create_network : {'network': {'id': 'b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e', 'name': 'ctest-vn1-57208168', 'tenant_id': 'c77634c853f24f8b9224f7deebbf77db', 'project_id': 'c77634c853f24f8b9224f7deebbf77db', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-71676797', 'ctest-vn1-57208168'], 'port_security_enabled': True, 'description': ''}}
2025-10-08 18:26:22,727 - DEBUG - Response for create_subnet : {'subnet': {'id': 'b94f9957-0466-4154-94af-b57acc494f7e', 'name': '', 'tenant_id': 'c77634c853f24f8b9224f7deebbf77db', 'network_id': 'b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e', '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': 'c77634c853f24f8b9224f7deebbf77db'}}
2025-10-08 18:26:22,748 - INFO - Created VN ctest-vn1-57208168
2025-10-08 18:26:22,761 - DEBUG - VN ctest-vn1-57208168 UUID is b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:22,842 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:26:23,140 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:26:23,174 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:26:23,193 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:26:23,298 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,311 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,321 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:26:23,330 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:26:23,337 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/342c9824-9343-46b0-8229-4e8386bed1cc
2025-10-08 18:26:23,344 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:26:23,345 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,353 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:26:23,372 - INFO - Verified VN network id 13 for VN b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,372 - INFO - Verifications in API Server for VN ctest-vn1-57208168 passed
2025-10-08 18:26:23,372 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,392 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:26:23,399 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:26:23,409 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/342c9824-9343-46b0-8229-4e8386bed1cc
2025-10-08 18:26:23,425 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13131509391251293123', 'uuid-lslong': '10071532844988988574'}, 'enable': 'true', 'created': '2025-10-08T18:26:22', 'last-modified': '2025-10-08T18:26:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.746386'}
2025-10-08 18:26:23,430 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:26:23,436 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13131509391251293123', 'uuid-lslong': '10071532844988988574'}, 'enable': 'true', 'created': '2025-10-08T18:26:22', 'last-modified': '2025-10-08T18:26:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.757326'}
2025-10-08 18:26:23,443 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:26:23,449 - DEBUG - Control-node 10.0.0.41 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13131509391251293123', 'uuid-lslong': '10071532844988988574'}, 'enable': 'true', 'created': '2025-10-08T18:26:22', 'last-modified': '2025-10-08T18:26:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.775097'}
2025-10-08 18:26:23,456 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:26:23,456 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-57208168 passed
2025-10-08 18:26:23,456 - DEBUG - ====Verifying policy data for ctest-vn1-57208168 in API_Server ======
2025-10-08 18:26:23,456 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:26:23,462 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:26:23,474 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:26:23,565 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e
2025-10-08 18:26:23,575 - DEBUG - =>VN ctest-vn1-57208168 has no policy to be verified
2025-10-08 18:26:23,575 - DEBUG - Verifying the vn in opserver
2025-10-08 18:26:23,575 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 virtual network link through opserver 10.0.0.56
2025-10-08 18:26:23,575 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-08 18:26:23,866 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-08 18:26:23,920 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat'}
2025-10-08 18:26:23,920 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 virtual network link through opserver 10.0.0.249
2025-10-08 18:26:23,920 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-10-08 18:26:24,207 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-10-08 18:26:24,262 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat'}
2025-10-08 18:26:24,262 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 virtual network link through opserver 10.0.0.41
2025-10-08 18:26:24,262 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-networks
2025-10-08 18:26:24,551 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-networks
2025-10-08 18:26:24,609 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat'}
2025-10-08 18:26:24,609 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is found in opserver
2025-10-08 18:26:24,634 - DEBUG - Do not have enough data to verify VN in agent
2025-10-08 18:26:24,646 - DEBUG - VRF ids for VN ctest-vn1-57208168: {}
2025-10-08 18:26:24,705 - DEBUG - Services list from nova: [, , , ]
2025-10-08 18:26:25,763 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-1)
2025-10-08 18:26:27,108 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-2)
2025-10-08 18:26:27,109 - INFO - Waiting for VM ctest-vn1_vm1-03905860 to be up..
2025-10-08 18:26:27,217 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-08 18:26:32,323 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:26:32,323 - INFO - VM name : ctest-vn1_vm1-03905860
2025-10-08 18:26:32,413 - DEBUG - VM ctest-vn1_vm1-03905860 ID is 1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:26:32,439 - DEBUG - VM ctest-vn1_vm1-03905860 launched on Node an-jenkins-deploy-platform-ansible-os-4239-1
2025-10-08 18:26:32,533 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:26:32,880 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:26:32,920 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/dfbc9893-ba85-4d82-adc8-9b32a6f987fa
2025-10-08 18:26:36,120 - 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-10-08 18:26:36,120 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:36,137 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:26:40,211 - 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-10-08 18:26:40,211 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:40,245 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:26:44,317 - 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 1007ms')
2025-10-08 18:26:44,318 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:44,333 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:26:48,408 - 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-10-08 18:26:48,408 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:48,425 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:26:52,499 - 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-10-08 18:26:52,500 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:52,515 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:26:56,599 - 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-10-08 18:26:56,599 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:26:56,614 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:27:00,700 - 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 1024ms')
2025-10-08 18:27:00,701 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 failed!
2025-10-08 18:27:00,717 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is 192.168.1.1 and allocation pool is NOT set
2025-10-08 18:27:02,775 - 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=5.11 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.67 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 1.668/3.390/5.112/1.722 ms')
2025-10-08 18:27:02,775 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-03905860 passed
2025-10-08 18:27:02,850 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:02,850 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-03905860, IP 192.168.1.3, Port 22
2025-10-08 18:27:02,906 - 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-10-08 18:27:02,995 - DEBUG - VM ctest-vn1_vm1-03905860 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:27:07,996 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:07,997 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-03905860, IP 192.168.1.3, Port 22
2025-10-08 18:27:08,054 - 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-10-08 18:27:08,133 - DEBUG - VM ctest-vn1_vm1-03905860 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:27:13,134 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:13,134 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-03905860, IP 192.168.1.3, Port 22
2025-10-08 18:27:13,200 - 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-10-08 18:27:13,292 - DEBUG - VM ctest-vn1_vm1-03905860 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:27:18,293 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:18,293 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-03905860, IP 192.168.1.3, Port 22
2025-10-08 18:27:18,350 - 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-10-08 18:27:18,424 - DEBUG - VM ctest-vn1_vm1-03905860 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:27:23,425 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:23,425 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-03905860, IP 192.168.1.3, Port 22
2025-10-08 18:27:23,593 - DEBUG - VM ctest-vn1_vm1-03905860 is ready for SSH connections
2025-10-08 18:27:23,593 - INFO - Waiting for VM ctest-vn1_vm2-75868216 to be up..
2025-10-08 18:27:23,693 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:27:23,693 - INFO - VM name : ctest-vn1_vm2-75868216
2025-10-08 18:27:23,785 - DEBUG - VM ctest-vn1_vm2-75868216 ID is 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:27:23,786 - DEBUG - VM ctest-vn1_vm2-75868216 launched on Node an-jenkins-deploy-platform-ansible-os-4239-2
2025-10-08 18:27:23,877 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:27:23,890 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/a476a1bd-321a-4174-8306-d93aec3ac191
2025-10-08 18:27:25,069 - 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=5.08 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=2.24 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 2.242/3.661/5.081/1.419 ms')
2025-10-08 18:27:25,070 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm2-75868216 passed
2025-10-08 18:27:25,148 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:25,149 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-75868216, IP 192.168.1.4, Port 22
2025-10-08 18:27:25,319 - DEBUG - VM ctest-vn1_vm2-75868216 is ready for SSH connections
2025-10-08 18:27:25,319 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:25,320 - 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.33, gateway password: c0ntrail123
2025-10-08 18:27:25,320 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4
2025-10-08 18:27:43,446 - DEBUG - PING 192.168.1.4 (192.168.1.4) 56(84) bytes of data.
64 bytes from 192.168.1.4: icmp_req=1 ttl=64 time=10.0 ms
64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=2.04 ms
64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.23 ms
--- 192.168.1.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.234/4.443/10.051/3.979 ms
2025-10-08 18:27:43,446 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-03905860 passed
2025-10-08 18:27:43,447 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:27:43,447 - 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.19, gateway password: c0ntrail123
2025-10-08 18:27:43,447 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3
2025-10-08 18:28:24,648 - 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.70 ms
64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.28 ms
64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=1.95 ms
--- 192.168.1.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.283/3.649/7.705/2.881 ms
2025-10-08 18:28:24,648 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-75868216 passed
2025-10-08 18:28:24,654 - INFO - Active control node from the Agent 10.0.0.33 is 10.0.0.41
2025-10-08 18:28:24,654 - INFO - Stoping the Control service in 10.0.0.41
2025-10-08 18:28:25,053 - INFO - 10.0.0.41
2025-10-08 18:28:25,053 - INFO - control:inactive
2025-10-08 18:28:25,053 - INFO - Contrail services control are down on nodes 10.0.0.41
2025-10-08 18:28:30,060 - INFO - Active control node from the Agent 10.0.0.33 is 10.0.0.249
2025-10-08 18:28:30,060 - INFO - Starting the Control service in 10.0.0.41
2025-10-08 18:28:30,406 - INFO - 10.0.0.41
2025-10-08 18:28:30,410 - INFO - control:initializing
2025-10-08 18:28:30,410 - DEBUG - defaultdict(, {'10.0.0.41': {'control': {'status': 'initializing', 'description': None}}})
2025-10-08 18:28:30,410 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:28:35,513 - INFO - 10.0.0.41
2025-10-08 18:28:35,518 - INFO - control:active
2025-10-08 18:28:35,518 - INFO - Contrail services ['control'] are up on nodes 10.0.0.41
2025-10-08 18:28:40,658 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:28:40,658 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:28:40,658 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:28:40,667 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/dfbc9893-ba85-4d82-adc8-9b32a6f987fa
2025-10-08 18:28:40,685 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:28:40,696 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/dfbc9893-ba85-4d82-adc8-9b32a6f987fa
2025-10-08 18:28:40,707 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/0fb0bcc3-9559-4117-90da-71ef430e951d
2025-10-08 18:28:40,720 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:28:40,720 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:28:40,729 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/dfbc9893-ba85-4d82-adc8-9b32a6f987fa
2025-10-08 18:28:40,740 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/0fb0bcc3-9559-4117-90da-71ef430e951d
2025-10-08 18:28:40,748 - INFO - VM ctest-vn1_vm1-03905860 verfication in all API Servers passed
2025-10-08 18:28:40,765 - DEBUG - VM ctest-vn1_vm1-03905860 Tap interface: {'index': '3', 'name': 'tapdfbc9893-ba', 'uuid': 'dfbc9893-ba85-4d82-adc8-9b32a6f987fa', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'vm_uuid': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'vm_name': 'ctest-vn1_vm1-03905860', 'ip_addr': '192.168.1.3', 'mac_addr': '02:df:bc:98:93:ba', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '159', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '27', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-10-08 18:28:40,765 - DEBUG - Agent 10.0.0.33 vrf name: default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168
2025-10-08 18:28:40,773 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.14:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-10-08 18:28:40,852 - DEBUG - VM ctest-vn1_vm1-03905860 : Tap interface tapdfbc9893-ba is set to Active
2025-10-08 18:28:40,852 - DEBUG - Tap interface tapdfbc9893-ba detail : {'index': '3', 'name': 'tapdfbc9893-ba', 'uuid': 'dfbc9893-ba85-4d82-adc8-9b32a6f987fa', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', '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': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'vm_uuid': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'vm_name': 'ctest-vn1_vm1-03905860', 'ip_addr': '192.168.1.3', 'mac_addr': '02:df:bc:98:93:ba', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '159', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '27', 'allowed_address_pair_list': None, 'ip6_addr': '::', 'local_preference': '0', 'tx_vlan_id': '-1', 'rx_vlan_id': '-1', 'parent_interface': None, 'subnet': '--NA--', 'sub_type': 'Tap', 'vrf_assign_acl_uuid': '--NA--', 'vmi_type': 'Virtual Machine', 'transport': 'Ethernet', 'logical_interface_uuid': '00000000-0000-0000-0000-000000000000', 'flood_unknown_unicast': 'false', 'physical_device': None, 'physical_interface': None, 'fixed_ip4_list': None, 'fixed_ip6_list': None, 'fat_flow_list': None, 'metadata_ip_active': 'Active', 'service_health_check_ip': '0.0.0.0', 'alias_ip_list': None, 'drop_new_flows': 'false', 'bridge_domain_list': [], 'vmi_tag_list': None, 'policy_set_acl_list': None, 'slo_list': None, 'vhostuser_mode': '0', 'si_other_end_vmi': '00000000-0000-0000-0000-000000000000', 'cfg_igmp_enable': 'false', 'igmp_enabled': 'false', 'max_flows': '0', 'policy_set_fwaas_list': None, 'bond_interface_list': None, 'mac_ip_learning_enable': 'false', 'mac_ip_list': []}
2025-10-08 18:28:40,966 - DEBUG - Starting Layer 2 verification in Agent
2025-10-08 18:28:40,977 - DEBUG - Layer 2 path is seen for VM MAC 02:df:bc:98:93:ba in agent 10.0.0.33
2025-10-08 18:28:40,977 - DEBUG - Active layer 2 route in agent is present for VMI tapdfbc9893-ba
2025-10-08 18:28:40,977 - DEBUG - L2 label(29) matches bw route table and interface table
2025-10-08 18:28:40,983 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is found in Agent of node 10.0.0.33
2025-10-08 18:28:41,116 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is consistent in agent 10.0.0.33
2025-10-08 18:28:41,116 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.33
2025-10-08 18:28:41,116 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 verification for VM ctest-vn1_vm1-03905860 in Agent 10.0.0.33 passed
2025-10-08 18:28:41,229 - DEBUG - Starting all layer 2 verification in agent 10.0.0.33
2025-10-08 18:28:41,240 - DEBUG - Route for VM MAC 02:df:bc:98:93:ba is consistent in agent 10.0.0.33
2025-10-08 18:28:41,247 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is found in Agent of node 10.0.0.19
2025-10-08 18:28:41,375 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is consistent in agent 10.0.0.19
2025-10-08 18:28:41,376 - DEBUG - Route for VM IP ['192.168.1.3'] is consistent in agent 10.0.0.19
2025-10-08 18:28:41,376 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 verification for VM ctest-vn1_vm1-03905860 in Agent 10.0.0.19 passed
2025-10-08 18:28:41,492 - DEBUG - Starting all layer 2 verification in agent 10.0.0.19
2025-10-08 18:28:41,506 - DEBUG - Route for VM MAC 02:df:bc:98:93:ba is consistent in agent 10.0.0.19
2025-10-08 18:28:41,506 - INFO - VM ctest-vn1_vm1-03905860 verifications in Compute nodes passed
2025-10-08 18:28:41,743 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.33
2025-10-08 18:28:41,747 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-10-08 18:28:41,846 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.19
2025-10-08 18:28:41,851 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.14, 24; Got 10.20.0.14,24
2025-10-08 18:28:41,851 - DEBUG - Validated VM route 192.168.1.3 in vrouter of 10.0.0.19
2025-10-08 18:28:41,851 - INFO - Validated routes of VM ctest-vn1_vm1-03905860 in all vrouters
2025-10-08 18:28:42,369 - DEBUG - Starting all layer2 verification in 10.0.0.56 Control Node
2025-10-08 18:28:42,499 - DEBUG - Layer2 route found for VM MAC 02:df:bc:98:93:ba in Control-node 10.0.0.56
2025-10-08 18:28:42,499 - DEBUG - L2 Label for VM ctest-vn1_vm1-03905860 same between Control-node 10.0.0.56 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:42,499 - DEBUG - Starting all layer2 verification in 10.0.0.41 Control Node
2025-10-08 18:28:42,628 - DEBUG - Layer2 route found for VM MAC 02:df:bc:98:93:ba in Control-node 10.0.0.41
2025-10-08 18:28:42,628 - DEBUG - L2 Label for VM ctest-vn1_vm1-03905860 same between Control-node 10.0.0.41 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:42,628 - DEBUG - Starting all layer2 verification in 10.0.0.249 Control Node
2025-10-08 18:28:42,761 - DEBUG - Layer2 route found for VM MAC 02:df:bc:98:93:ba in Control-node 10.0.0.249
2025-10-08 18:28:42,761 - DEBUG - L2 Label for VM ctest-vn1_vm1-03905860 same between Control-node 10.0.0.249 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:42,761 - INFO - Verification in Control-nodes for VM ctest-vn1_vm1-03905860 passed
2025-10-08 18:28:42,761 - DEBUG - Verifying the vm in opserver
2025-10-08 18:28:42,761 - DEBUG - Verifying in collector 10.0.0.41 ...
2025-10-08 18:28:42,761 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat
2025-10-08 18:28:42,779 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa?flat
2025-10-08 18:28:42,860 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa?flat
2025-10-08 18:28:42,881 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat
2025-10-08 18:28:42,953 - DEBUG - Verifying vm in vn uve
2025-10-08 18:28:42,953 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa?flat
2025-10-08 18:28:43,014 - DEBUG - VM uve shows interface as {'vm_uuid': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'admin_state': True, 'is_health_check_active': True, 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'ip_address': '192.168.1.3', 'rx_vlan': 65535, 'fixed_ip4_list': ['192.168.1.3'], 'l2_active': True, 'vn_uuid': 'b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e', 'gateway': '192.168.1.1', 'vm_name': 'ctest-vn1_vm1-03905860', 'active': True, 'ip6_address': '::', 'mac_address': '02:df:bc:98:93:ba', 'vhostuser_mode': 0, 'ip4_active': True, 'ip6_active': False, 'port_mirror_enabled': False, 'label': 24, 'uuid': 'dfbc9893-ba85-4d82-adc8-9b32a6f987fa', '__T': 1759948111597430, 'tx_vlan': 65535}
2025-10-08 18:28:43,014 - DEBUG - VM uve shows ip address as ['192.168.1.3', '::']
2025-10-08 18:28:43,014 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:43,014 - INFO - Verifying through opserver in 10.0.0.56
2025-10-08 18:28:43,015 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat
2025-10-08 18:28:43,075 - DEBUG - expected vm list 1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:28:43,075 - DEBUG - Extracted vm list ['1ff39dea-74b6-43f6-a48a-5cd92323be04']
2025-10-08 18:28:43,075 - INFO - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is present in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:43,075 - DEBUG - Verifying vm in vrouter uve
2025-10-08 18:28:43,075 - DEBUG - Getting info from collector 10.0.0.41..
2025-10-08 18:28:43,075 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat
2025-10-08 18:28:43,133 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4239-1']
2025-10-08 18:28:43,133 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:43,181 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:28:43,209 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:28:43,209 - DEBUG - Validated that VM ctest-vn1_vm1-03905860 is in Vrouter an-jenkins-deploy-platform-ansible-os-4239-1 UVE
2025-10-08 18:28:43,209 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-10-08 18:28:43,217 - DEBUG - Expected tap interface of VM uuid 1ff39dea-74b6-43f6-a48a-5cd92323be04 is default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa
2025-10-08 18:28:43,217 - DEBUG - Expected VN of VM uuid 1ff39dea-74b6-43f6-a48a-5cd92323be04 is default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:43,217 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:43,263 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:28:43,292 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:28:43,292 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-71676797:dfbc9893-ba85-4d82-adc8-9b32a6f987fa of vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:28:43,292 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 of vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:28:43,292 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.56
2025-10-08 18:28:43,292 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:28:43,309 - DEBUG - VM link and name as {'name': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat'}
2025-10-08 18:28:43,309 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.249
2025-10-08 18:28:43,309 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:28:43,366 - DEBUG - VM link and name as {'name': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat'}
2025-10-08 18:28:43,366 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.41
2025-10-08 18:28:43,366 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:28:43,380 - DEBUG - VM link and name as {'name': '1ff39dea-74b6-43f6-a48a-5cd92323be04', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04?flat'}
2025-10-08 18:28:43,380 - INFO - VM ctest-vn1_vm1-03905860 validations in Opserver passed
2025-10-08 18:28:43,466 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:28:43,466 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:28:43,466 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:43,474 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/a476a1bd-321a-4174-8306-d93aec3ac191
2025-10-08 18:28:43,483 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:43,491 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/a476a1bd-321a-4174-8306-d93aec3ac191
2025-10-08 18:28:43,501 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/fedb61a0-f5c3-43f9-8277-cf07a7808f51
2025-10-08 18:28:43,511 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:28:43,512 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:43,520 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/a476a1bd-321a-4174-8306-d93aec3ac191
2025-10-08 18:28:43,530 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/fedb61a0-f5c3-43f9-8277-cf07a7808f51
2025-10-08 18:28:43,539 - INFO - VM ctest-vn1_vm2-75868216 verfication in all API Servers passed
2025-10-08 18:28:43,557 - DEBUG - VM ctest-vn1_vm2-75868216 Tap interface: {'index': '3', 'name': 'tapa476a1bd-32', 'uuid': 'a476a1bd-321a-4174-8306-d93aec3ac191', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'vm_uuid': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'vm_name': 'ctest-vn1_vm2-75868216', 'ip_addr': '192.168.1.4', 'mac_addr': '02:a4:76:a1:bd:32', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '129', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', '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-10-08 18:28:43,557 - DEBUG - Agent 10.0.0.19 vrf name: default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168
2025-10-08 18:28:43,562 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.25:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-10-08 18:28:43,646 - DEBUG - VM ctest-vn1_vm2-75868216 : Tap interface tapa476a1bd-32 is set to Active
2025-10-08 18:28:43,646 - DEBUG - Tap interface tapa476a1bd-32 detail : {'index': '3', 'name': 'tapa476a1bd-32', 'uuid': 'a476a1bd-321a-4174-8306-d93aec3ac191', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168:ctest-vn1-57208168', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '25', 'l2_label': '29', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'vm_uuid': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'vm_name': 'ctest-vn1_vm2-75868216', 'ip_addr': '192.168.1.4', 'mac_addr': '02:a4:76:a1:bd:32', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.3', 'service_vlan_list': None, 'os_ifindex': '129', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', '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-10-08 18:28:43,769 - DEBUG - Starting Layer 2 verification in Agent
2025-10-08 18:28:43,781 - DEBUG - Layer 2 path is seen for VM MAC 02:a4:76:a1:bd:32 in agent 10.0.0.19
2025-10-08 18:28:43,782 - DEBUG - Active layer 2 route in agent is present for VMI tapa476a1bd-32
2025-10-08 18:28:43,782 - DEBUG - L2 label(29) matches bw route table and interface table
2025-10-08 18:28:43,789 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is found in Agent of node 10.0.0.33
2025-10-08 18:28:43,932 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is consistent in agent 10.0.0.33
2025-10-08 18:28:43,932 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.33
2025-10-08 18:28:43,932 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 verification for VM ctest-vn1_vm2-75868216 in Agent 10.0.0.33 passed
2025-10-08 18:28:44,047 - DEBUG - Starting all layer 2 verification in agent 10.0.0.33
2025-10-08 18:28:44,058 - DEBUG - Route for VM MAC 02:a4:76:a1:bd:32 is consistent in agent 10.0.0.33
2025-10-08 18:28:44,063 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is found in Agent of node 10.0.0.19
2025-10-08 18:28:44,195 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 is consistent in agent 10.0.0.19
2025-10-08 18:28:44,196 - DEBUG - Route for VM IP ['192.168.1.4'] is consistent in agent 10.0.0.19
2025-10-08 18:28:44,196 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 verification for VM ctest-vn1_vm2-75868216 in Agent 10.0.0.19 passed
2025-10-08 18:28:44,312 - DEBUG - Starting all layer 2 verification in agent 10.0.0.19
2025-10-08 18:28:44,322 - DEBUG - Route for VM MAC 02:a4:76:a1:bd:32 is consistent in agent 10.0.0.19
2025-10-08 18:28:44,322 - INFO - VM ctest-vn1_vm2-75868216 verifications in Compute nodes passed
2025-10-08 18:28:44,546 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.33
2025-10-08 18:28:44,551 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: 10.20.0.25, 25; Got 10.20.0.25,25
2025-10-08 18:28:44,551 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.33
2025-10-08 18:28:44,652 - DEBUG - Validated VM route 192.168.1.4 in vrouter of 10.0.0.19
2025-10-08 18:28:44,657 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-10-08 18:28:44,657 - INFO - Validated routes of VM ctest-vn1_vm2-75868216 in all vrouters
2025-10-08 18:28:45,186 - DEBUG - Starting all layer2 verification in 10.0.0.56 Control Node
2025-10-08 18:28:45,316 - DEBUG - Layer2 route found for VM MAC 02:a4:76:a1:bd:32 in Control-node 10.0.0.56
2025-10-08 18:28:45,316 - DEBUG - L2 Label for VM ctest-vn1_vm2-75868216 same between Control-node 10.0.0.56 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:45,316 - DEBUG - Starting all layer2 verification in 10.0.0.41 Control Node
2025-10-08 18:28:45,443 - DEBUG - Layer2 route found for VM MAC 02:a4:76:a1:bd:32 in Control-node 10.0.0.41
2025-10-08 18:28:45,443 - DEBUG - L2 Label for VM ctest-vn1_vm2-75868216 same between Control-node 10.0.0.41 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:45,443 - DEBUG - Starting all layer2 verification in 10.0.0.249 Control Node
2025-10-08 18:28:45,570 - DEBUG - Layer2 route found for VM MAC 02:a4:76:a1:bd:32 in Control-node 10.0.0.249
2025-10-08 18:28:45,570 - DEBUG - L2 Label for VM ctest-vn1_vm2-75868216 same between Control-node 10.0.0.249 and Agent, Expected: 29, Seen: 29
2025-10-08 18:28:45,570 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-75868216 passed
2025-10-08 18:28:45,570 - DEBUG - Verifying the vm in opserver
2025-10-08 18:28:45,570 - DEBUG - Verifying in collector 10.0.0.41 ...
2025-10-08 18:28:45,571 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat
2025-10-08 18:28:45,588 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191?flat
2025-10-08 18:28:45,606 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191?flat
2025-10-08 18:28:45,625 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat
2025-10-08 18:28:45,642 - DEBUG - Verifying vm in vn uve
2025-10-08 18:28:45,642 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191?flat
2025-10-08 18:28:45,664 - DEBUG - VM uve shows interface as {'vm_uuid': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'admin_state': True, 'is_health_check_active': True, 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168', 'ip_address': '192.168.1.4', 'rx_vlan': 65535, 'fixed_ip4_list': ['192.168.1.4'], 'l2_active': True, 'vn_uuid': 'b63c7e37-b63d-43c3-8bc5-45c2e13f7c9e', 'gateway': '192.168.1.1', 'vm_name': 'ctest-vn1_vm2-75868216', 'active': True, 'ip6_address': '::', 'mac_address': '02:a4:76:a1:bd:32', 'vhostuser_mode': 0, 'ip4_active': True, 'ip6_active': False, 'port_mirror_enabled': False, 'label': 25, 'uuid': 'a476a1bd-321a-4174-8306-d93aec3ac191', '__T': 1759948000661938, 'tx_vlan': 65535}
2025-10-08 18:28:45,664 - DEBUG - VM uve shows ip address as ['192.168.1.4', '::']
2025-10-08 18:28:45,664 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:45,664 - INFO - Verifying through opserver in 10.0.0.56
2025-10-08 18:28:45,664 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat
2025-10-08 18:28:45,700 - DEBUG - expected vm list 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:45,700 - DEBUG - Extracted vm list ['5ffd9a77-7c79-49d6-a6df-a8338e3f89c5']
2025-10-08 18:28:45,700 - INFO - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is present in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:45,700 - DEBUG - Verifying vm in vrouter uve
2025-10-08 18:28:45,700 - DEBUG - Getting info from collector 10.0.0.41..
2025-10-08 18:28:45,700 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat
2025-10-08 18:28:45,720 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4239-2']
2025-10-08 18:28:45,720 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:45,767 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:28:45,802 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:45,803 - DEBUG - Validated that VM ctest-vn1_vm2-75868216 is in Vrouter an-jenkins-deploy-platform-ansible-os-4239-2 UVE
2025-10-08 18:28:45,803 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-10-08 18:28:45,811 - DEBUG - Expected tap interface of VM uuid 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191
2025-10-08 18:28:45,811 - DEBUG - Expected VN of VM uuid 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:45,811 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:45,858 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:28:45,892 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:45,892 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-71676797:a476a1bd-321a-4174-8306-d93aec3ac191 of vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:45,892 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 of vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:45,892 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.56
2025-10-08 18:28:45,892 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:28:45,906 - DEBUG - VM link and name as {'name': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat'}
2025-10-08 18:28:45,906 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.249
2025-10-08 18:28:45,907 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:28:45,921 - DEBUG - VM link and name as {'name': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat'}
2025-10-08 18:28:45,921 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.41
2025-10-08 18:28:45,921 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:28:45,936 - DEBUG - VM link and name as {'name': '5ffd9a77-7c79-49d6-a6df-a8338e3f89c5', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5?flat'}
2025-10-08 18:28:45,936 - INFO - VM ctest-vn1_vm2-75868216 validations in Opserver passed
2025-10-08 18:28:45,936 - INFO - Checking the ping between the VM again
2025-10-08 18:28:45,936 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:28:45,937 - 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.33, gateway password: c0ntrail123
2025-10-08 18:28:45,937 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.4
2025-10-08 18:28:48,394 - 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=4.50 ms
64 bytes from 192.168.1.4: icmp_req=2 ttl=64 time=1.55 ms
64 bytes from 192.168.1.4: icmp_req=3 ttl=64 time=1.13 ms
--- 192.168.1.4 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.135/2.398/4.502/1.498 ms
2025-10-08 18:28:48,394 - INFO - Ping to IP 192.168.1.4 from VM ctest-vn1_vm1-03905860 passed
2025-10-08 18:28:48,394 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:28:48,394 - 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.19, gateway password: c0ntrail123
2025-10-08 18:28:48,394 - DEBUG - ping -s 56 -c 3 -W 1 192.168.1.3
2025-10-08 18:28:50,866 - 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=1.14 ms
64 bytes from 192.168.1.3: icmp_req=2 ttl=64 time=1.12 ms
64 bytes from 192.168.1.3: icmp_req=3 ttl=64 time=1.13 ms
--- 192.168.1.3 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.123/1.133/1.146/0.029 ms
2025-10-08 18:28:50,867 - INFO - Ping to IP 192.168.1.3 from VM ctest-vn1_vm2-75868216 passed
2025-10-08 18:28:50,867 - INFO - Deleting VM ctest-vn1_vm2-75868216
2025-10-08 18:28:50,941 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:28:50,941 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:50,952 - DEBUG - VM ID 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 of VM ctest-vn1_vm2-75868216 is still found in API Server
2025-10-08 18:28:52,952 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:28:52,953 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:52,962 - DEBUG - Response Code: 404
2025-10-08 18:28:52,962 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:52,969 - DEBUG - Response Code: 404
2025-10-08 18:28:52,969 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/5ffd9a77-7c79-49d6-a6df-a8338e3f89c5
2025-10-08 18:28:52,976 - DEBUG - Response Code: 404
2025-10-08 18:28:52,976 - INFO - VM ctest-vn1_vm2-75868216 is fully removed in API-Server
2025-10-08 18:28:53,132 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-10-08 18:28:53,270 - DEBUG - VM route 192.168.1.4 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 of compute 10.0.0.33
2025-10-08 18:28:53,274 - DEBUG - Validated that vrouter 10.0.0.33 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:53,274 - DEBUG - Validated that vrouter 10.0.0.19 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:53,274 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:28:53,274 - INFO - VM ctest-vn1_vm2-75868216 is removed in Compute, and routes are removed in all compute nodes
2025-10-08 18:28:53,528 - INFO - Routes for VM ctest-vn1_vm2-75868216 is removed in all control-nodes
2025-10-08 18:28:53,528 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:53,574 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:28:53,605 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:53,605 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:28:53,606 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:28:53,606 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:28:56,607 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:56,650 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:28:56,682 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:56,682 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:28:56,682 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:28:56,683 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:28:59,683 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:28:59,726 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:28:59,757 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:28:59,757 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:28:59,757 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:28:59,757 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:02,758 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:02,804 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:29:02,839 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:29:02,839 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:02,839 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:29:02,839 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:05,839 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:05,885 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:29:05,916 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:29:05,916 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:05,917 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:29:05,917 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:08,917 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:08,960 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:29:08,988 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:29:08,988 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:08,988 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:29:08,988 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:11,988 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:12,034 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:29:12,063 - DEBUG - VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:29:12,063 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:12,063 - DEBUG - interface for vm 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 deleted from vrouter uve ...
2025-10-08 18:29:12,063 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:12,063 - DEBUG - Validated that VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is removed in Vrouter UVE
2025-10-08 18:29:12,063 - DEBUG - Verifying through opserver in 10.0.0.56
2025-10-08 18:29:12,063 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat
2025-10-08 18:29:12,085 - DEBUG - 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 BM not in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 uve
2025-10-08 18:29:12,085 - DEBUG - Validated that VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is not present in the VN UVE
2025-10-08 18:29:12,085 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.56
2025-10-08 18:29:12,085 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:29:12,097 - INFO - 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 vm uve deleted from opserver
2025-10-08 18:29:12,097 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.249
2025-10-08 18:29:12,097 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:29:12,110 - INFO - 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 vm uve deleted from opserver
2025-10-08 18:29:12,110 - DEBUG - Verifying the 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 virtual network link through opserver 10.0.0.41
2025-10-08 18:29:12,110 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:29:12,123 - INFO - 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 vm uve deleted from opserver
2025-10-08 18:29:12,123 - INFO - Validated that VM 5ffd9a77-7c79-49d6-a6df-a8338e3f89c5 is removed from Opserver
2025-10-08 18:29:12,123 - INFO - Deleting VM ctest-vn1_vm1-03905860
2025-10-08 18:29:12,184 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:29:12,184 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:29:12,193 - DEBUG - VM ID 1ff39dea-74b6-43f6-a48a-5cd92323be04 of VM ctest-vn1_vm1-03905860 is still found in API Server
2025-10-08 18:29:14,194 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:29:14,194 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:29:14,201 - DEBUG - Response Code: 404
2025-10-08 18:29:14,201 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:29:14,207 - DEBUG - Response Code: 404
2025-10-08 18:29:14,207 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/1ff39dea-74b6-43f6-a48a-5cd92323be04
2025-10-08 18:29:14,213 - DEBUG - Response Code: 404
2025-10-08 18:29:14,214 - INFO - VM ctest-vn1_vm1-03905860 is fully removed in API-Server
2025-10-08 18:29:14,364 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-10-08 18:29:14,434 - DEBUG - Validated that vrouter 10.0.0.33 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:29:14,444 - DEBUG - Validated that vrouter 10.0.0.19 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:29:14,444 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168
2025-10-08 18:29:14,444 - INFO - VM ctest-vn1_vm1-03905860 is removed in Compute, and routes are removed in all compute nodes
2025-10-08 18:29:14,689 - INFO - Routes for VM ctest-vn1_vm1-03905860 is removed in all control-nodes
2025-10-08 18:29:14,689 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:14,735 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:14,763 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:14,763 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:14,763 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:14,763 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:17,764 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:17,810 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:17,840 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:17,840 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:17,840 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:17,840 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:20,841 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:20,885 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:20,915 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:20,915 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:20,915 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:20,915 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:23,916 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:23,969 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:24,002 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:24,002 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:24,002 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:24,002 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:27,003 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:27,045 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:27,083 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:27,083 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:27,083 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:27,083 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:30,084 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:30,126 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:30,154 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:30,154 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:30,154 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:30,154 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:33,155 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:29:33,199 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:29:33,229 - DEBUG - VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:29:33,229 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:29:33,229 - DEBUG - interface for vm 1ff39dea-74b6-43f6-a48a-5cd92323be04 deleted from vrouter uve ...
2025-10-08 18:29:33,229 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:29:33,229 - DEBUG - Validated that VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is removed in Vrouter UVE
2025-10-08 18:29:33,229 - DEBUG - Verifying through opserver in 10.0.0.56
2025-10-08 18:29:33,229 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168?flat
2025-10-08 18:29:33,245 - DEBUG - 1ff39dea-74b6-43f6-a48a-5cd92323be04 BM not in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-57208168 uve
2025-10-08 18:29:33,245 - DEBUG - Validated that VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is not present in the VN UVE
2025-10-08 18:29:33,245 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.56
2025-10-08 18:29:33,245 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:29:33,256 - INFO - 1ff39dea-74b6-43f6-a48a-5cd92323be04 vm uve deleted from opserver
2025-10-08 18:29:33,256 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.249
2025-10-08 18:29:33,256 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:29:33,269 - INFO - 1ff39dea-74b6-43f6-a48a-5cd92323be04 vm uve deleted from opserver
2025-10-08 18:29:33,269 - DEBUG - Verifying the 1ff39dea-74b6-43f6-a48a-5cd92323be04 virtual network link through opserver 10.0.0.41
2025-10-08 18:29:33,269 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:29:33,283 - INFO - 1ff39dea-74b6-43f6-a48a-5cd92323be04 vm uve deleted from opserver
2025-10-08 18:29:33,283 - INFO - Validated that VM 1ff39dea-74b6-43f6-a48a-5cd92323be04 is removed from Opserver
2025-10-08 18:29:33,284 - INFO - Deleting VN ctest-vn1-57208168
2025-10-08 18:29:33,475 - DEBUG - Response for deleting network ()
2025-10-08 18:29:33,475 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/b9b663e9-47be-491c-9cd8-58f459604fba
2025-10-08 18:29:33,483 - DEBUG - Response Code: 404
2025-10-08 18:29:33,483 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:29:33,488 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:29:33,545 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:29:33,642 - INFO - Validated that VN ctest-vn1-57208168 is not found in API Server
2025-10-08 18:29:33,652 - DEBUG - VN ctest-vn1-57208168 is not present in Agent 10.0.0.33
2025-10-08 18:29:33,663 - DEBUG - VN ctest-vn1-57208168 is not present in Agent 10.0.0.19
2025-10-08 18:29:33,663 - INFO - Validated that VN ctest-vn1-57208168 is not in any agent
2025-10-08 18:29:33,696 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-57208168 info
2025-10-08 18:29:34,949 - DEBUG - Skipping xmpp flap check
2025-10-08 18:29:34,949 - INFO - END TEST : test_control_node_switchover : PASSED[0:03:14]
2025-10-08 18:29:34,949 - INFO - --------------------------------------------------------------------------------
2025-10-08 18:29:34,951 - INFO - ================================================================================
2025-10-08 18:29:34,951 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns
2025-10-08 18:29:34,951 - 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-10-08 18:29:36,241 - DEBUG - Skipping xmpp flap check
2025-10-08 18:29:36,241 - INFO - Initial checks done. Running the testcase now
2025-10-08 18:29:36,241 - INFO -
2025-10-08 18:29:36,249 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864, 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-71676797:ctest-vn2-83605714, 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-10-08 18:29:36,556 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714, 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-71676797:ctest-vn1-16745864, 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-10-08 18:29:37,109 - INFO - Created VN ctest-vn1-16745864, UUID :156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,421 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:29:37,428 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:29:37,439 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:29:37,535 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,545 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,554 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:29:37,565 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:29:37,572 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/5ec4a451-3058-42ba-a573-970fd1d818f7
2025-10-08 18:29:37,579 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:29:37,579 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,587 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:29:37,605 - INFO - Verified VN network id 13 for VN 156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,605 - INFO - Verifications in API Server for VN ctest-vn1-16745864 passed
2025-10-08 18:29:37,605 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,615 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:29:37,621 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:29:37,628 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/5ec4a451-3058-42ba-a573-970fd1d818f7
2025-10-08 18:29:37,638 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:37', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.380198'}
2025-10-08 18:29:37,642 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:29:37,648 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:37', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.390278'}
2025-10-08 18:29:37,655 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:29:37,661 - DEBUG - Control-node 10.0.0.41 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:37', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.410722'}
2025-10-08 18:29:37,667 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:29:37,667 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-16745864 passed
2025-10-08 18:29:37,667 - DEBUG - ====Verifying policy data for ctest-vn1-16745864 in API_Server ======
2025-10-08 18:29:37,667 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:29:37,673 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:29:37,684 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:29:37,784 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:29:37,806 - DEBUG - =>VN ctest-vn1-16745864 has no policy to be verified
2025-10-08 18:29:37,806 - DEBUG - Verifying the vn in opserver
2025-10-08 18:29:37,806 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.56
2025-10-08 18:29:37,806 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-08 18:29:37,825 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:29:37,825 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.249
2025-10-08 18:29:37,825 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-10-08 18:29:37,875 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:29:37,875 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.41
2025-10-08 18:29:37,875 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-networks
2025-10-08 18:29:37,889 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:29:37,889 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is found in opserver
2025-10-08 18:29:37,907 - DEBUG - Do not have enough data to verify VN in agent
2025-10-08 18:29:37,917 - DEBUG - VRF ids for VN ctest-vn1-16745864: {}
2025-10-08 18:29:38,584 - INFO - Created VN ctest-vn2-83605714, UUID :0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:38,896 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:29:38,901 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:29:38,911 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:29:39,005 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,021 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,035 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:29:39,048 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:29:39,057 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/31796cb6-5b15-47f4-b4cc-6484f9c3194f
2025-10-08 18:29:39,065 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-08 18:29:39,065 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,076 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:29:39,095 - INFO - Verified VN network id 14 for VN 0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,095 - INFO - Verifications in API Server for VN ctest-vn2-83605714 passed
2025-10-08 18:29:39,095 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,106 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:29:39,115 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:29:39,125 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/31796cb6-5b15-47f4-b4cc-6484f9c3194f
2025-10-08 18:29:39,139 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '927102841124112735', 'uuid-lslong': '13505633006656393831'}, 'enable': 'true', 'created': '2025-10-08T18:29:38', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.412845'}
2025-10-08 18:29:39,144 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-08 18:29:39,149 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '927102841124112735', 'uuid-lslong': '13505633006656393831'}, 'enable': 'true', 'created': '2025-10-08T18:29:38', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.424214'}
2025-10-08 18:29:39,154 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-08 18:29:39,159 - DEBUG - Control-node 10.0.0.41 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '927102841124112735', 'uuid-lslong': '13505633006656393831'}, 'enable': 'true', 'created': '2025-10-08T18:29:38', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.433798'}
2025-10-08 18:29:39,165 - DEBUG - Route Targets: ['target:64512:8000005']
2025-10-08 18:29:39,165 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-83605714 passed
2025-10-08 18:29:39,165 - DEBUG - ====Verifying policy data for ctest-vn2-83605714 in API_Server ======
2025-10-08 18:29:39,165 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:29:39,170 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:29:39,180 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:29:39,275 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/0cddbb1f-3b75-495f-bb6d-a5a9e48b9267
2025-10-08 18:29:39,289 - DEBUG - =>VN ctest-vn2-83605714 has no policy to be verified
2025-10-08 18:29:39,289 - DEBUG - Verifying the vn in opserver
2025-10-08 18:29:39,289 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 virtual network link through opserver 10.0.0.56
2025-10-08 18:29:39,289 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-08 18:29:39,301 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714?flat'}
2025-10-08 18:29:39,301 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 virtual network link through opserver 10.0.0.249
2025-10-08 18:29:39,301 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-10-08 18:29:39,316 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714?flat'}
2025-10-08 18:29:39,316 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 virtual network link through opserver 10.0.0.41
2025-10-08 18:29:39,316 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-networks
2025-10-08 18:29:39,329 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714?flat'}
2025-10-08 18:29:39,329 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is found in opserver
2025-10-08 18:29:39,350 - DEBUG - Do not have enough data to verify VN in agent
2025-10-08 18:29:39,359 - DEBUG - VRF ids for VN ctest-vn2-83605714: {}
2025-10-08 18:29:40,835 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-1)
2025-10-08 18:29:42,170 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-2)
2025-10-08 18:29:42,170 - INFO - Waiting for VM ctest-vn1_vm1-82660701 to be up..
2025-10-08 18:29:42,263 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-08 18:29:47,342 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:29:47,342 - INFO - VM name : ctest-vn1_vm1-82660701
2025-10-08 18:29:47,424 - DEBUG - VM ctest-vn1_vm1-82660701 ID is 2ab84eb9-38a7-4ab0-aada-8428cee5debb
2025-10-08 18:29:47,425 - DEBUG - VM ctest-vn1_vm1-82660701 launched on Node an-jenkins-deploy-platform-ansible-os-4239-1
2025-10-08 18:29:47,507 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/2ab84eb9-38a7-4ab0-aada-8428cee5debb
2025-10-08 18:29:47,519 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/cc8df7e6-a44b-464c-b5bb-d804ea8cc6ad
2025-10-08 18:29:50,717 - 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 1035ms')
2025-10-08 18:29:50,717 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:29:50,731 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:29:54,808 - 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-10-08 18:29:54,808 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:29:54,824 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:29:58,904 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-10-08 18:29:58,904 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:29:58,921 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:30:03,002 - 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-10-08 18:30:03,002 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:30:03,026 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:30:07,095 - 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-10-08 18:30:07,096 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:30:07,115 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:30:11,196 - 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-10-08 18:30:11,197 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:30:11,218 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:30:15,289 - 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 1004ms')
2025-10-08 18:30:15,290 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 failed!
2025-10-08 18:30:15,309 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:30:17,376 - 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=6.60 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.59 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.585/4.091/6.597/2.506 ms')
2025-10-08 18:30:17,376 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-82660701 passed
2025-10-08 18:30:17,450 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:17,451 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-82660701, IP 192.168.1.252, Port 22
2025-10-08 18:30:17,521 - 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-10-08 18:30:17,611 - DEBUG - VM ctest-vn1_vm1-82660701 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:30:22,612 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:22,612 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-82660701, IP 192.168.1.252, Port 22
2025-10-08 18:30:22,683 - 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-10-08 18:30:22,763 - DEBUG - VM ctest-vn1_vm1-82660701 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:30:27,764 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:27,764 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-82660701, IP 192.168.1.252, Port 22
2025-10-08 18:30:27,827 - 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-10-08 18:30:27,910 - DEBUG - VM ctest-vn1_vm1-82660701 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:30:32,911 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:32,911 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-82660701, IP 192.168.1.252, Port 22
2025-10-08 18:30:32,984 - 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-10-08 18:30:33,065 - DEBUG - VM ctest-vn1_vm1-82660701 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:30:38,066 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:38,066 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-82660701, IP 192.168.1.252, Port 22
2025-10-08 18:30:38,239 - DEBUG - VM ctest-vn1_vm1-82660701 is ready for SSH connections
2025-10-08 18:30:38,239 - INFO - Waiting for VM ctest-vn2_vm1-63535374 to be up..
2025-10-08 18:30:38,335 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:30:38,335 - INFO - VM name : ctest-vn2_vm1-63535374
2025-10-08 18:30:38,413 - DEBUG - VM ctest-vn2_vm1-63535374 ID is f5e90085-b2c5-4361-ae42-ca48e369c962
2025-10-08 18:30:38,413 - DEBUG - VM ctest-vn2_vm1-63535374 launched on Node an-jenkins-deploy-platform-ansible-os-4239-2
2025-10-08 18:30:38,523 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/f5e90085-b2c5-4361-ae42-ca48e369c962
2025-10-08 18:30:38,533 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/e6392a88-82b8-403b-860e-4877c9f54d0a
2025-10-08 18:30:39,721 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=3.69 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.30 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 1.299/2.493/3.687/1.194 ms')
2025-10-08 18:30:39,721 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn2_vm1-63535374 passed
2025-10-08 18:30:39,798 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:39,798 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-63535374, IP 192.168.2.252, Port 22
2025-10-08 18:30:39,882 - 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-10-08 18:30:39,967 - DEBUG - VM ctest-vn2_vm1-63535374 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:30:44,967 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:44,967 - DEBUG - Waiting to SSH to VM ctest-vn2_vm1-63535374, IP 192.168.2.252, Port 22
2025-10-08 18:30:45,153 - DEBUG - VM ctest-vn2_vm1-63535374 is ready for SSH connections
2025-10-08 18:30:45,153 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:30:45,153 - 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.33, gateway password: c0ntrail123
2025-10-08 18:30:45,153 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.252
2025-10-08 18:31:30,963 - 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=9.12 ms
64 bytes from 192.168.2.252: icmp_req=2 ttl=63 time=1.57 ms
64 bytes from 192.168.2.252: icmp_req=3 ttl=63 time=1.22 ms
--- 192.168.2.252 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2004ms
rtt min/avg/max/mdev = 1.222/3.976/9.129/3.646 ms
2025-10-08 18:31:30,963 - INFO - Ping to IP 192.168.2.252 from VM ctest-vn1_vm1-82660701 passed
2025-10-08 18:31:34,368 - INFO - 10.0.0.33
2025-10-08 18:31:34,372 - INFO - agent:initializing
2025-10-08 18:31:34,372 - DEBUG - defaultdict(, {'10.0.0.33': {'agent': {'status': 'initializing', 'description': None}}})
2025-10-08 18:31:34,373 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:31:39,465 - INFO - 10.0.0.33
2025-10-08 18:31:39,470 - INFO - agent:active
2025-10-08 18:31:39,471 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.33
2025-10-08 18:31:42,841 - INFO - 10.0.0.19
2025-10-08 18:31:42,846 - INFO - agent:initializing
2025-10-08 18:31:42,846 - DEBUG - defaultdict(, {'10.0.0.19': {'agent': {'status': 'initializing', 'description': None}}})
2025-10-08 18:31:42,846 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:31:47,937 - INFO - 10.0.0.19
2025-10-08 18:31:47,945 - INFO - agent:active
2025-10-08 18:31:47,945 - INFO - Contrail services ['agent'] are up on nodes 10.0.0.19
2025-10-08 18:31:48,545 - INFO - 10.0.0.56
2025-10-08 18:31:48,550 - INFO - control:initializing
2025-10-08 18:31:48,551 - DEBUG - defaultdict(, {'10.0.0.56': {'control': {'status': 'initializing', 'description': None}}})
2025-10-08 18:31:48,551 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:31:53,649 - INFO - 10.0.0.56
2025-10-08 18:31:53,653 - INFO - control:active
2025-10-08 18:31:53,653 - INFO - Contrail services ['control'] are up on nodes 10.0.0.56
2025-10-08 18:31:54,056 - INFO - 10.0.0.249
2025-10-08 18:31:54,060 - INFO - control:initializing
2025-10-08 18:31:54,060 - DEBUG - defaultdict(, {'10.0.0.249': {'control': {'status': 'initializing', 'description': None}}})
2025-10-08 18:31:54,060 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:31:59,171 - INFO - 10.0.0.249
2025-10-08 18:31:59,178 - INFO - control:active
2025-10-08 18:31:59,178 - INFO - Contrail services ['control'] are up on nodes 10.0.0.249
2025-10-08 18:31:59,615 - INFO - 10.0.0.41
2025-10-08 18:31:59,620 - INFO - control:initializing
2025-10-08 18:31:59,620 - DEBUG - defaultdict(, {'10.0.0.41': {'control': {'status': 'initializing', 'description': None}}})
2025-10-08 18:31:59,620 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:32:04,710 - INFO - 10.0.0.41
2025-10-08 18:32:04,717 - INFO - control:active
2025-10-08 18:32:04,717 - INFO - Contrail services ['control'] are up on nodes 10.0.0.41
2025-10-08 18:32:05,759 - INFO - 10.0.0.56
2025-10-08 18:32:05,762 - INFO - api-server:initializing
2025-10-08 18:32:05,762 - DEBUG - defaultdict(, {'10.0.0.56': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:05,762 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:32:10,880 - INFO - 10.0.0.56
2025-10-08 18:32:10,883 - INFO - api-server:initializing
2025-10-08 18:32:10,883 - DEBUG - defaultdict(, {'10.0.0.56': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:10,883 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-10-08 18:32:15,987 - INFO - 10.0.0.56
2025-10-08 18:32:15,992 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-10-08 18:32:15,992 - DEBUG - defaultdict(, {'10.0.0.56': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-10-08 18:32:15,992 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-10-08 18:32:21,080 - INFO - 10.0.0.56
2025-10-08 18:32:21,084 - INFO - api-server:active
2025-10-08 18:32:21,084 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.56
2025-10-08 18:32:21,740 - INFO - 10.0.0.249
2025-10-08 18:32:21,744 - INFO - api-server:initializing
2025-10-08 18:32:21,744 - DEBUG - defaultdict(, {'10.0.0.249': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:21,744 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:32:26,845 - INFO - 10.0.0.249
2025-10-08 18:32:26,850 - INFO - api-server:initializing
2025-10-08 18:32:26,850 - DEBUG - defaultdict(, {'10.0.0.249': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:26,850 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-10-08 18:32:31,939 - INFO - 10.0.0.249
2025-10-08 18:32:31,944 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-10-08 18:32:31,945 - DEBUG - defaultdict(, {'10.0.0.249': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-10-08 18:32:31,945 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-10-08 18:32:37,036 - INFO - 10.0.0.249
2025-10-08 18:32:37,041 - INFO - api-server:active
2025-10-08 18:32:37,042 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.249
2025-10-08 18:32:37,778 - INFO - 10.0.0.41
2025-10-08 18:32:37,781 - INFO - api-server:initializing
2025-10-08 18:32:37,782 - DEBUG - defaultdict(, {'10.0.0.41': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:37,782 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 0
2025-10-08 18:32:42,898 - INFO - 10.0.0.41
2025-10-08 18:32:42,903 - INFO - api-server:initializing
2025-10-08 18:32:42,903 - DEBUG - defaultdict(, {'10.0.0.41': {'api-server': {'status': 'initializing', 'description': None}}})
2025-10-08 18:32:42,903 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 1
2025-10-08 18:32:48,005 - INFO - 10.0.0.41
2025-10-08 18:32:48,011 - INFO - api-server:initializing (Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down)
2025-10-08 18:32:48,011 - DEBUG - defaultdict(, {'10.0.0.41': {'api-server': {'status': 'initializing', 'description': 'Collector:Collector[none to Idle on EvStart], Generic Connection:Keystone[] connection down'}}})
2025-10-08 18:32:48,011 - DEBUG - Not all services up. Sleeping for 5 seconds. iteration: 2
2025-10-08 18:32:53,101 - INFO - 10.0.0.41
2025-10-08 18:32:53,108 - INFO - api-server:active
2025-10-08 18:32:53,108 - INFO - Contrail services ['api-server'] are up on nodes 10.0.0.41
2025-10-08 18:32:53,216 - INFO - 10.0.0.56
2025-10-08 18:32:53,216 - INFO - config
2025-10-08 18:32:53,222 - INFO - config-nodemgr:active
2025-10-08 18:32:53,226 - INFO - api-server:active
2025-10-08 18:32:53,229 - INFO - schema:backup
2025-10-08 18:32:53,232 - INFO - svc-monitor:backup
2025-10-08 18:32:53,235 - INFO - device-manager:backup
2025-10-08 18:32:53,235 - INFO - config-database
2025-10-08 18:32:53,235 - INFO - config-cassandra:active
2025-10-08 18:32:53,235 - INFO - config-zookeeper:active
2025-10-08 18:32:53,235 - INFO - config-rabbitmq:active
2025-10-08 18:32:53,235 - INFO - control
2025-10-08 18:32:53,240 - INFO - control-nodemgr:active
2025-10-08 18:32:53,245 - INFO - control:active
2025-10-08 18:32:53,246 - INFO - named:active
2025-10-08 18:32:53,250 - INFO - dns:active
2025-10-08 18:32:53,250 - INFO - analytics
2025-10-08 18:32:53,254 - INFO - analytics-nodemgr:active
2025-10-08 18:32:53,260 - INFO - analytics-api:active
2025-10-08 18:32:53,265 - INFO - collector:active
2025-10-08 18:32:53,265 - INFO - analytics-database
2025-10-08 18:32:53,265 - INFO - analytics-cassandra:active
2025-10-08 18:32:53,270 - INFO - analyticsdb-nodemgr:active
2025-10-08 18:32:53,275 - INFO - query-engine:active
2025-10-08 18:32:53,275 - INFO - webui
2025-10-08 18:32:53,275 - INFO - webui:active
2025-10-08 18:32:53,275 - INFO - webui-middleware:active
2025-10-08 18:32:53,275 - INFO - redis:active
2025-10-08 18:32:53,275 - INFO - analytics_snmp
2025-10-08 18:32:53,279 - INFO - snmp-collector:active
2025-10-08 18:32:53,279 - INFO - snmp-topology:active
2025-10-08 18:32:53,279 - INFO - analytics_alarm
2025-10-08 18:32:53,279 - INFO - alarmgen:active
2025-10-08 18:32:53,378 - INFO - 10.0.0.249
2025-10-08 18:32:53,378 - INFO - config
2025-10-08 18:32:53,384 - INFO - config-nodemgr:active
2025-10-08 18:32:53,389 - INFO - api-server:active
2025-10-08 18:32:53,395 - INFO - schema:active
2025-10-08 18:32:53,400 - INFO - svc-monitor:active
2025-10-08 18:32:53,405 - INFO - device-manager:active
2025-10-08 18:32:53,405 - INFO - config-database
2025-10-08 18:32:53,405 - INFO - config-cassandra:active
2025-10-08 18:32:53,405 - INFO - config-zookeeper:active
2025-10-08 18:32:53,405 - INFO - config-rabbitmq:active
2025-10-08 18:32:53,405 - INFO - control
2025-10-08 18:32:53,410 - INFO - control-nodemgr:active
2025-10-08 18:32:53,416 - INFO - control:active
2025-10-08 18:32:53,416 - INFO - named:active
2025-10-08 18:32:53,423 - INFO - dns:active
2025-10-08 18:32:53,423 - INFO - analytics
2025-10-08 18:32:53,427 - INFO - analytics-nodemgr:active
2025-10-08 18:32:53,431 - INFO - analytics-api:active
2025-10-08 18:32:53,436 - INFO - collector:active
2025-10-08 18:32:53,436 - INFO - analytics-database
2025-10-08 18:32:53,436 - INFO - analytics-cassandra:active
2025-10-08 18:32:53,441 - INFO - analyticsdb-nodemgr:active
2025-10-08 18:32:53,445 - INFO - query-engine:active
2025-10-08 18:32:53,445 - INFO - webui
2025-10-08 18:32:53,445 - INFO - webui:active
2025-10-08 18:32:53,445 - INFO - webui-middleware:active
2025-10-08 18:32:53,446 - INFO - redis:active
2025-10-08 18:32:53,446 - INFO - analytics_snmp
2025-10-08 18:32:53,449 - INFO - snmp-collector:active
2025-10-08 18:32:53,449 - INFO - snmp-topology:active
2025-10-08 18:32:53,449 - INFO - analytics_alarm
2025-10-08 18:32:53,449 - INFO - alarmgen:active
2025-10-08 18:32:53,537 - INFO - 10.0.0.41
2025-10-08 18:32:53,537 - INFO - config
2025-10-08 18:32:53,544 - INFO - config-nodemgr:active
2025-10-08 18:32:53,548 - INFO - api-server:active
2025-10-08 18:32:53,553 - INFO - schema:backup
2025-10-08 18:32:53,556 - INFO - svc-monitor:backup
2025-10-08 18:32:53,560 - INFO - device-manager:backup
2025-10-08 18:32:53,560 - INFO - config-database
2025-10-08 18:32:53,560 - INFO - config-cassandra:active
2025-10-08 18:32:53,560 - INFO - config-zookeeper:active
2025-10-08 18:32:53,560 - INFO - config-rabbitmq:active
2025-10-08 18:32:53,560 - INFO - control
2025-10-08 18:32:53,564 - INFO - control-nodemgr:active
2025-10-08 18:32:53,569 - INFO - control:active
2025-10-08 18:32:53,569 - INFO - named:active
2025-10-08 18:32:53,574 - INFO - dns:active
2025-10-08 18:32:53,575 - INFO - analytics
2025-10-08 18:32:53,580 - INFO - analytics-nodemgr:active
2025-10-08 18:32:53,585 - INFO - analytics-api:active
2025-10-08 18:32:53,590 - INFO - collector:active
2025-10-08 18:32:53,590 - INFO - analytics-database
2025-10-08 18:32:53,590 - INFO - analytics-cassandra:active
2025-10-08 18:32:53,595 - INFO - analyticsdb-nodemgr:active
2025-10-08 18:32:53,600 - INFO - query-engine:active
2025-10-08 18:32:53,600 - INFO - webui
2025-10-08 18:32:53,600 - INFO - webui:active
2025-10-08 18:32:53,600 - INFO - webui-middleware:active
2025-10-08 18:32:53,600 - INFO - redis:active
2025-10-08 18:32:53,600 - INFO - analytics_snmp
2025-10-08 18:32:53,604 - INFO - snmp-collector:active
2025-10-08 18:32:53,604 - INFO - snmp-topology:active
2025-10-08 18:32:53,604 - INFO - analytics_alarm
2025-10-08 18:32:53,604 - INFO - alarmgen:active
2025-10-08 18:32:53,693 - INFO - 10.0.0.33
2025-10-08 18:32:53,693 - INFO - vrouter
2025-10-08 18:32:53,700 - INFO - vrouter-nodemgr:active
2025-10-08 18:32:53,705 - INFO - agent:active
2025-10-08 18:32:53,796 - INFO - 10.0.0.19
2025-10-08 18:32:53,796 - INFO - vrouter
2025-10-08 18:32:53,812 - INFO - vrouter-nodemgr:active
2025-10-08 18:32:53,818 - INFO - agent:active
2025-10-08 18:32:53,818 - INFO - All the contrail services are up on all nodes
2025-10-08 18:32:53,819 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:32:54,269 - WARNING - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.192:5269'] servers NOT UP
2025-10-08 18:32:54,269 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.19:5269'] servers UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1 connected to xmpp 10.20.0.19
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.254:5269'] servers UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1 connected to xmpp 10.20.0.254
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.192:53'] servers UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1 connected to dns 10.20.0.192
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.19:53'] servers UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1 connected to dns 10.20.0.19
2025-10-08 18:32:54,270 - WARNING - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.20.0.254:53'] servers NOT UP
2025-10-08 18:32:54,270 - WARNING - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.0.0.56:8086'] servers NOT UP
2025-10-08 18:32:54,270 - WARNING - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.0.0.249:8086'] servers NOT UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1:contrail-vrouter-agent module connection to ['10.0.0.41:8086'] servers UP
2025-10-08 18:32:54,270 - INFO - an-jenkins-deploy-platform-ansible-os-4239-1 connected to collector 10.0.0.41
2025-10-08 18:32:54,271 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:32:54,677 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-1:contrail-control module connection to 10.0.0.56:9041 servers UP
2025-10-08 18:32:54,678 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-1:contrail-control module connection to 10.0.0.56:5673 servers UP
2025-10-08 18:32:54,678 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-1:contrail-control module connection to ['10.0.0.56:8086'] servers UP
2025-10-08 18:32:54,678 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:32:55,045 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-2:contrail-control module connection to 10.0.0.56:9041 servers UP
2025-10-08 18:32:55,045 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-2:contrail-control module connection to 10.0.0.56:5673 servers UP
2025-10-08 18:32:55,045 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-2:contrail-control module connection to ['10.0.0.56:8086'] servers UP
2025-10-08 18:32:55,045 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/control-node/cn-jenkins-deploy-platform-ansible-os-4239-3?flat
2025-10-08 18:32:55,062 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-3:contrail-control module connection to 10.0.0.56:9041 servers UP
2025-10-08 18:32:55,062 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-3:contrail-control module connection to 10.0.0.56:5673 servers UP
2025-10-08 18:32:55,062 - INFO - cn-jenkins-deploy-platform-ansible-os-4239-3:contrail-control module connection to ['10.0.0.56:8086'] servers UP
2025-10-08 18:32:55,063 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4239-1.?flat
2025-10-08 18:32:55,083 - DEBUG - contrail-api is running
2025-10-08 18:32:55,083 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4239-2.?flat
2025-10-08 18:32:55,104 - DEBUG - contrail-api is running
2025-10-08 18:32:55,104 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/config-node/cn-jenkins-deploy-platform-ansible-os-4239-3.?flat
2025-10-08 18:32:55,126 - DEBUG - contrail-api is running
2025-10-08 18:32:55,424 - INFO - Created VN ctest-vn3-87146623, UUID :7aeb17f3-7b00-4c9a-81bd-3b4b8fbab511
2025-10-08 18:32:55,858 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:32:55,887 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:32:55,903 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:32:56,021 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,042 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,056 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:32:56,063 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:32:56,073 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/5ec4a451-3058-42ba-a573-970fd1d818f7
2025-10-08 18:32:56,085 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:32:56,085 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,097 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:32:56,115 - INFO - Verified VN network id 13 for VN 156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,115 - INFO - Verifications in API Server for VN ctest-vn1-16745864 passed
2025-10-08 18:32:56,115 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,125 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:32:56,134 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:32:56,142 - DEBUG - Requesting: http://10.0.0.56:8082/route-target/5ec4a451-3058-42ba-a573-970fd1d818f7
2025-10-08 18:32:56,155 - DEBUG - Control-node 10.0.0.56 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:07.123523'}
2025-10-08 18:32:56,162 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:32:56,167 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '0', 'advertised': '0', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:01:01.769410'}
2025-10-08 18:32:56,173 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:32:56,179 - DEBUG - Control-node 10.0.0.41 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-71676797', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1544441404404089090', 'uuid-lslong': '12275305513841747855'}, 'enable': 'true', 'created': '2025-10-08T18:29:37', 'last-modified': '2025-10-08T18:29:38', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:56.138312'}
2025-10-08 18:32:56,185 - DEBUG - Route Targets: ['target:64512:8000004']
2025-10-08 18:32:56,185 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-16745864 passed
2025-10-08 18:32:56,185 - DEBUG - ====Verifying policy data for ctest-vn1-16745864 in API_Server ======
2025-10-08 18:32:56,185 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:32:56,190 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:32:56,200 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:32:56,298 - DEBUG - Requesting: http://10.0.0.56:8082/virtual-network/156ef546-45e9-4102-aa5a-a553d5ee678f
2025-10-08 18:32:56,313 - DEBUG - ==>Verifying data for policy with id: e29478ba-7ae6-418e-b3a5-c4b229be6a3e, fqn: ['default-domain', 'ctest-TestBasicVMVN0-71676797', 'policy1']
2025-10-08 18:32:56,313 - INFO - VN ctest-vn1-16745864 Policy verification: verify_vn_policy_in_api_server, status: True
2025-10-08 18:32:56,313 - DEBUG - Verifying the vn in opserver
2025-10-08 18:32:56,314 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.56
2025-10-08 18:32:56,314 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-networks
2025-10-08 18:32:56,327 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:32:56,327 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.249
2025-10-08 18:32:56,327 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-10-08 18:32:56,387 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:32:56,387 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 virtual network link through opserver 10.0.0.41
2025-10-08 18:32:56,387 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-networks
2025-10-08 18:32:56,444 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat'}
2025-10-08 18:32:56,444 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is found in opserver
2025-10-08 18:32:56,457 - DEBUG - VRF ids for VN ctest-vn1-16745864: {'10.0.0.33': '2'}
2025-10-08 18:32:57,696 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-1)
2025-10-08 18:32:57,741 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-08 18:33:02,820 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:33:02,820 - INFO - VM name : ctest-vn1_vm2-60857096
2025-10-08 18:33:02,907 - DEBUG - VM ctest-vn1_vm2-60857096 ID is ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:02,990 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:33:02,990 - DEBUG - VM ctest-vn1_vm2-60857096 launched on Node an-jenkins-deploy-platform-ansible-os-4239-1
2025-10-08 18:33:03,063 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:03,099 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:03,108 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/c9157bf6-5abd-4d52-80b9-5309ce424d70
2025-10-08 18:33:03,119 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:03,126 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/c9157bf6-5abd-4d52-80b9-5309ce424d70
2025-10-08 18:33:03,138 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/76ac52d2-efd8-489d-8960-ab921b9e936e
2025-10-08 18:33:03,149 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:33:03,149 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:03,157 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/c9157bf6-5abd-4d52-80b9-5309ce424d70
2025-10-08 18:33:03,167 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/76ac52d2-efd8-489d-8960-ab921b9e936e
2025-10-08 18:33:03,176 - INFO - VM ctest-vn1_vm2-60857096 verfication in all API Servers passed
2025-10-08 18:33:03,197 - DEBUG - VM ctest-vn1_vm2-60857096 Tap interface: {'index': '4', 'name': 'tapc9157bf6-5a', 'uuid': 'c9157bf6-5abd-4d52-80b9-5309ce424d70', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864:ctest-vn1-16745864', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '30', 'l2_label': '34', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'vm_uuid': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'vm_name': 'ctest-vn1_vm2-60857096', 'ip_addr': '192.168.1.251', 'mac_addr': '02:c9:15:7b:f6:5a', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '163', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '35', '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-10-08 18:33:03,197 - DEBUG - Agent 10.0.0.33 vrf name: default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864:ctest-vn1-16745864
2025-10-08 18:33:03,203 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864:ctest-vn1-16745864', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'table_label': '-1', 'vxlan_id': '13', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.14:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-10-08 18:33:03,297 - DEBUG - VM ctest-vn1_vm2-60857096 : Tap interface tapc9157bf6-5a is set to Active
2025-10-08 18:33:03,297 - DEBUG - Tap interface tapc9157bf6-5a detail : {'index': '4', 'name': 'tapc9157bf6-5a', 'uuid': 'c9157bf6-5abd-4d52-80b9-5309ce424d70', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864:ctest-vn1-16745864', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '30', 'l2_label': '34', 'vxlan_id': '13', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864', 'vm_uuid': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'vm_name': 'ctest-vn1_vm2-60857096', 'ip_addr': '192.168.1.251', 'mac_addr': '02:c9:15:7b:f6:5a', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '163', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '35', '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-10-08 18:33:03,415 - DEBUG - Starting Layer 2 verification in Agent
2025-10-08 18:33:03,428 - DEBUG - Layer 2 path is seen for VM MAC 02:c9:15:7b:f6:5a in agent 10.0.0.33
2025-10-08 18:33:03,428 - DEBUG - Active layer 2 route in agent is present for VMI tapc9157bf6-5a
2025-10-08 18:33:03,428 - DEBUG - L2 label(34) matches bw route table and interface table
2025-10-08 18:33:03,435 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is found in Agent of node 10.0.0.33
2025-10-08 18:33:03,581 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is consistent in agent 10.0.0.33
2025-10-08 18:33:03,581 - DEBUG - Route for VM IP ['192.168.1.251'] is consistent in agent 10.0.0.33
2025-10-08 18:33:03,581 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 verification for VM ctest-vn1_vm2-60857096 in Agent 10.0.0.33 passed
2025-10-08 18:33:03,698 - DEBUG - Starting all layer 2 verification in agent 10.0.0.33
2025-10-08 18:33:03,711 - DEBUG - Route for VM MAC 02:c9:15:7b:f6:5a is consistent in agent 10.0.0.33
2025-10-08 18:33:06,896 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms')
2025-10-08 18:33:06,896 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:06,912 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:10,997 - 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 1026ms')
2025-10-08 18:33:10,997 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:11,012 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:15,097 - 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-10-08 18:33:15,097 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:15,119 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:19,193 - 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 1011ms')
2025-10-08 18:33:19,193 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:19,210 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:23,284 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-10-08 18:33:23,284 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:23,297 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:27,383 - 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-10-08 18:33:27,384 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:27,399 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:31,477 - 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-10-08 18:33:31,477 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 failed!
2025-10-08 18:33:31,496 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 is 192.168.1.254 and allocation pool is NOT set
2025-10-08 18:33:35,574 - 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=7.68 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1015ms\r\nrtt min/avg/max/mdev = 7.679/7.679/7.679/0.000 ms')
2025-10-08 18:33:35,574 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 passed
2025-10-08 18:33:35,574 - INFO - VM ctest-vn1_vm2-60857096 verifications in Compute nodes passed
2025-10-08 18:33:35,799 - DEBUG - Validated VM route 192.168.1.251 in vrouter of 10.0.0.33
2025-10-08 18:33:35,808 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-10-08 18:33:35,808 - INFO - Validated routes of VM ctest-vn1_vm2-60857096 in all vrouters
2025-10-08 18:33:36,237 - DEBUG - Starting all layer2 verification in 10.0.0.56 Control Node
2025-10-08 18:33:36,372 - DEBUG - Layer2 route found for VM MAC 02:c9:15:7b:f6:5a in Control-node 10.0.0.56
2025-10-08 18:33:36,373 - DEBUG - L2 Label for VM ctest-vn1_vm2-60857096 same between Control-node 10.0.0.56 and Agent, Expected: 34, Seen: 34
2025-10-08 18:33:36,373 - DEBUG - Starting all layer2 verification in 10.0.0.41 Control Node
2025-10-08 18:33:36,505 - DEBUG - Layer2 route found for VM MAC 02:c9:15:7b:f6:5a in Control-node 10.0.0.41
2025-10-08 18:33:36,505 - DEBUG - L2 Label for VM ctest-vn1_vm2-60857096 same between Control-node 10.0.0.41 and Agent, Expected: 34, Seen: 34
2025-10-08 18:33:36,506 - DEBUG - Starting all layer2 verification in 10.0.0.249 Control Node
2025-10-08 18:33:36,641 - DEBUG - Layer2 route found for VM MAC 02:c9:15:7b:f6:5a in Control-node 10.0.0.249
2025-10-08 18:33:36,641 - DEBUG - L2 Label for VM ctest-vn1_vm2-60857096 same between Control-node 10.0.0.249 and Agent, Expected: 34, Seen: 34
2025-10-08 18:33:36,641 - INFO - Verification in Control-nodes for VM ctest-vn1_vm2-60857096 passed
2025-10-08 18:33:36,641 - DEBUG - Verifying the vm in opserver
2025-10-08 18:33:36,641 - DEBUG - Verifying in collector 10.0.0.41 ...
2025-10-08 18:33:36,641 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat
2025-10-08 18:33:36,715 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70?flat
2025-10-08 18:33:36,737 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70?flat
2025-10-08 18:33:36,756 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat
2025-10-08 18:33:36,773 - DEBUG - Verifying vm in vn uve
2025-10-08 18:33:36,773 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70?flat
2025-10-08 18:33:36,793 - DEBUG - VM uve shows interface as {'__T': 1759948384924359, 'ip_address': '192.168.1.251', 'is_health_check_active': True, 'vn_uuid': '156ef546-45e9-4102-aa5a-a553d5ee678f', 'ip6_address': '::', 'rx_vlan': 65535, 'ip6_active': False, 'ip4_active': True, 'vm_uuid': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'vm_name': 'ctest-vn1_vm2-60857096', 'port_mirror_enabled': False, 'l2_active': True, 'label': 30, 'uuid': 'c9157bf6-5abd-4d52-80b9-5309ce424d70', 'tx_vlan': 65535, 'vhostuser_mode': 0, 'active': True, 'fixed_ip4_list': ['192.168.1.251'], 'mac_address': '02:c9:15:7b:f6:5a', 'gateway': '192.168.1.254', 'admin_state': True, 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864'}
2025-10-08 18:33:36,793 - DEBUG - VM uve shows ip address as ['192.168.1.251', '::']
2025-10-08 18:33:36,793 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:33:36,793 - INFO - Verifying through opserver in 10.0.0.56
2025-10-08 18:33:36,793 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat
2025-10-08 18:33:36,816 - DEBUG - expected vm list ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:33:36,816 - DEBUG - Extracted vm list ['ced8e1bc-19b9-49fe-b626-1e9fc3f95340']
2025-10-08 18:33:36,816 - INFO - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is present in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:33:36,816 - DEBUG - Verifying vm in vrouter uve
2025-10-08 18:33:36,816 - DEBUG - Getting info from collector 10.0.0.41..
2025-10-08 18:33:36,816 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat
2025-10-08 18:33:36,886 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4239-1']
2025-10-08 18:33:36,886 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:33:36,941 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:33:36,968 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:33:36,968 - DEBUG - Validated that VM ctest-vn1_vm2-60857096 is in Vrouter an-jenkins-deploy-platform-ansible-os-4239-1 UVE
2025-10-08 18:33:36,968 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-10-08 18:33:36,983 - DEBUG - Expected tap interface of VM uuid ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70
2025-10-08 18:33:36,983 - DEBUG - Expected VN of VM uuid ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:33:36,983 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:33:37,034 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:33:37,071 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:33:37,071 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-71676797:c9157bf6-5abd-4d52-80b9-5309ce424d70 of vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:33:37,071 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 of vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:33:37,071 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.56
2025-10-08 18:33:37,071 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:33:37,087 - DEBUG - VM link and name as {'name': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat'}
2025-10-08 18:33:37,087 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.249
2025-10-08 18:33:37,087 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:33:37,156 - DEBUG - VM link and name as {'name': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat'}
2025-10-08 18:33:37,156 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.41
2025-10-08 18:33:37,156 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:33:37,171 - DEBUG - VM link and name as {'name': 'ced8e1bc-19b9-49fe-b626-1e9fc3f95340', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340?flat'}
2025-10-08 18:33:37,171 - INFO - VM ctest-vn1_vm2-60857096 validations in Opserver passed
2025-10-08 18:33:38,409 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4239-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4239-2)
2025-10-08 18:33:38,469 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-10-08 18:33:43,597 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:33:43,597 - INFO - VM name : ctest-vn2_vm2-18719282
2025-10-08 18:33:43,701 - DEBUG - VM ctest-vn2_vm2-18719282 ID is 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:33:43,797 - DEBUG - VM is in ACTIVE state now
2025-10-08 18:33:43,797 - DEBUG - VM ctest-vn2_vm2-18719282 launched on Node an-jenkins-deploy-platform-ansible-os-4239-2
2025-10-08 18:33:43,879 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:33:43,893 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:33:43,905 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/ed4f7108-8ebd-4894-a956-d5a749ad280f
2025-10-08 18:33:43,918 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:33:43,929 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/ed4f7108-8ebd-4894-a956-d5a749ad280f
2025-10-08 18:33:43,947 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/84b024c4-31b5-4a72-86e3-10863e54cb27
2025-10-08 18:33:43,965 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:33:43,966 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:33:43,978 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/ed4f7108-8ebd-4894-a956-d5a749ad280f
2025-10-08 18:33:43,993 - DEBUG - Requesting: http://10.0.0.41:8082/instance-ip/84b024c4-31b5-4a72-86e3-10863e54cb27
2025-10-08 18:33:44,001 - INFO - VM ctest-vn2_vm2-18719282 verfication in all API Servers passed
2025-10-08 18:33:44,020 - DEBUG - VM ctest-vn2_vm2-18719282 Tap interface: {'index': '4', 'name': 'taped4f7108-8e', 'uuid': 'ed4f7108-8ebd-4894-a956-d5a749ad280f', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714:ctest-vn2-83605714', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '30', 'l2_label': '34', 'vxlan_id': '14', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'vm_uuid': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'vm_name': 'ctest-vn2_vm2-18719282', 'ip_addr': '192.168.2.251', 'mac_addr': '02:ed:4f:71:08:8e', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '133', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '35', '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-10-08 18:33:44,020 - DEBUG - Agent 10.0.0.19 vrf name: default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714:ctest-vn2-83605714
2025-10-08 18:33:44,026 - DEBUG - Agent VRF Object : {'vrf_list': [{'name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714:ctest-vn2-83605714', 'ucindex': '2', 'mcindex': '2', 'l2index': '2', 'source': 'Config; ', 'uc6index': '2', 'vn': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'table_label': '-1', 'vxlan_id': '14', 'evpnindex': '2', 'brindex': '2', 'mplsindex': '0', 'RD': '10.20.0.25:2', 'mac_aging_time': '0', 'layer2_control_word': 'false', 'forwarding_vrf': None, 'hbf_rintf': '-1', 'hbf_lintf': '-1'}]}
2025-10-08 18:33:44,116 - DEBUG - VM ctest-vn2_vm2-18719282 : Tap interface taped4f7108-8e is set to Active
2025-10-08 18:33:44,116 - DEBUG - Tap interface taped4f7108-8e detail : {'index': '4', 'name': 'taped4f7108-8e', 'uuid': 'ed4f7108-8ebd-4894-a956-d5a749ad280f', 'vrf_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714:ctest-vn2-83605714', 'active': 'Active', 'ipv4_active': 'Active', 'l2_active': 'L2 Active', 'ip6_active': 'Ipv6 Inactive < no-ipv6-addr >', 'health_check_active': 'Active', 'dhcp_service': 'Enable', 'dhcp_service_v6': 'Disable', 'dns_service': 'Enable', 'type': 'vport', 'label': '30', 'l2_label': '34', 'vxlan_id': '14', 'vn_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714', 'vm_uuid': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'vm_name': 'ctest-vn2_vm2-18719282', 'ip_addr': '192.168.2.251', 'mac_addr': '02:ed:4f:71:08:8e', 'policy': 'Enable', 'fip_list': [], 'mdata_ip_addr': '169.254.0.4', 'service_vlan_list': None, 'os_ifindex': '133', 'fabric_port': 'NotFabricPort', 'alloc_linklocal_ip': 'LL-Enable', 'analyzer_name': None, 'config_name': 'default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f', 'sg_uuid_list': ['3998b414-1d3a-45db-8a12-b80295d29d11'], 'static_route_list': None, 'vm_project_uuid': 'c77634c8-53f2-4f8b-9224-f7deebbf77db', 'admin_state': 'Enabled', 'flow_key_idx': '35', '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-10-08 18:33:44,234 - DEBUG - Starting Layer 2 verification in Agent
2025-10-08 18:33:44,250 - DEBUG - Layer 2 path is seen for VM MAC 02:ed:4f:71:08:8e in agent 10.0.0.19
2025-10-08 18:33:44,250 - DEBUG - Active layer 2 route in agent is present for VMI taped4f7108-8e
2025-10-08 18:33:44,250 - DEBUG - L2 label(34) matches bw route table and interface table
2025-10-08 18:33:44,266 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is found in Agent of node 10.0.0.19
2025-10-08 18:33:44,374 - DEBUG - VRF IDs of VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is consistent in agent 10.0.0.19
2025-10-08 18:33:44,374 - DEBUG - Route for VM IP ['192.168.2.251'] is consistent in agent 10.0.0.19
2025-10-08 18:33:44,374 - DEBUG - VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 verification for VM ctest-vn2_vm2-18719282 in Agent 10.0.0.19 passed
2025-10-08 18:33:44,492 - DEBUG - Starting all layer 2 verification in agent 10.0.0.19
2025-10-08 18:33:44,509 - DEBUG - Route for VM MAC 02:ed:4f:71:08:8e is consistent in agent 10.0.0.19
2025-10-08 18:33:47,712 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2025-10-08 18:33:47,713 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:33:47,728 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:33:51,817 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1026ms')
2025-10-08 18:33:51,817 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:33:51,835 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:33:55,909 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms')
2025-10-08 18:33:55,909 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:33:55,925 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:00,007 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-10-08 18:34:00,007 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:34:00,023 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:04,099 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-10-08 18:34:04,099 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:34:04,116 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:08,194 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms')
2025-10-08 18:34:08,194 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:34:08,212 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:12,295 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2025-10-08 18:34:12,295 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:34:12,308 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:16,392 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2025-10-08 18:34:16,392 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 failed!
2025-10-08 18:34:16,405 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 is 192.168.2.254 and allocation pool is NOT set
2025-10-08 18:34:18,477 - 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=15.4 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=2.62 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 = 2.615/9.011/15.407/6.396 ms')
2025-10-08 18:34:18,477 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 passed
2025-10-08 18:34:18,478 - INFO - VM ctest-vn2_vm2-18719282 verifications in Compute nodes passed
2025-10-08 18:34:18,702 - DEBUG - Validated VM route 192.168.2.251 in vrouter of 10.0.0.19
2025-10-08 18:34:18,707 - DEBUG - Remote Nh validation passed. Expected Tunnel, label: None, 0; Got None,0
2025-10-08 18:34:18,707 - INFO - Validated routes of VM ctest-vn2_vm2-18719282 in all vrouters
2025-10-08 18:34:19,152 - DEBUG - Starting all layer2 verification in 10.0.0.56 Control Node
2025-10-08 18:34:19,277 - DEBUG - Layer2 route found for VM MAC 02:ed:4f:71:08:8e in Control-node 10.0.0.56
2025-10-08 18:34:19,277 - DEBUG - L2 Label for VM ctest-vn2_vm2-18719282 same between Control-node 10.0.0.56 and Agent, Expected: 34, Seen: 34
2025-10-08 18:34:19,277 - DEBUG - Starting all layer2 verification in 10.0.0.41 Control Node
2025-10-08 18:34:19,403 - DEBUG - Layer2 route found for VM MAC 02:ed:4f:71:08:8e in Control-node 10.0.0.41
2025-10-08 18:34:19,403 - DEBUG - L2 Label for VM ctest-vn2_vm2-18719282 same between Control-node 10.0.0.41 and Agent, Expected: 34, Seen: 34
2025-10-08 18:34:19,403 - DEBUG - Starting all layer2 verification in 10.0.0.249 Control Node
2025-10-08 18:34:19,530 - DEBUG - Layer2 route found for VM MAC 02:ed:4f:71:08:8e in Control-node 10.0.0.249
2025-10-08 18:34:19,530 - DEBUG - L2 Label for VM ctest-vn2_vm2-18719282 same between Control-node 10.0.0.249 and Agent, Expected: 34, Seen: 34
2025-10-08 18:34:19,531 - INFO - Verification in Control-nodes for VM ctest-vn2_vm2-18719282 passed
2025-10-08 18:34:19,531 - DEBUG - Verifying the vm in opserver
2025-10-08 18:34:19,531 - DEBUG - Verifying in collector 10.0.0.41 ...
2025-10-08 18:34:19,531 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat
2025-10-08 18:34:19,546 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f?flat
2025-10-08 18:34:19,564 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f?flat
2025-10-08 18:34:19,580 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat
2025-10-08 18:34:19,597 - DEBUG - Verifying vm in vn uve
2025-10-08 18:34:19,597 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machine-interface/default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f?flat
2025-10-08 18:34:19,615 - DEBUG - VM uve shows interface as {'__T': 1759948423453376, 'ip_address': '192.168.2.251', 'is_health_check_active': True, 'vn_uuid': '0cddbb1f-3b75-495f-bb6d-a5a9e48b9267', 'ip6_address': '::', 'rx_vlan': 65535, 'ip6_active': False, 'ip4_active': True, 'vm_uuid': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'vm_name': 'ctest-vn2_vm2-18719282', 'port_mirror_enabled': False, 'l2_active': True, 'label': 30, 'uuid': 'ed4f7108-8ebd-4894-a956-d5a749ad280f', 'tx_vlan': 65535, 'vhostuser_mode': 0, 'active': True, 'fixed_ip4_list': ['192.168.2.251'], 'mac_address': '02:ed:4f:71:08:8e', 'gateway': '192.168.2.254', 'admin_state': True, 'virtual_network': 'default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714'}
2025-10-08 18:34:19,615 - DEBUG - VM uve shows ip address as ['192.168.2.251', '::']
2025-10-08 18:34:19,615 - DEBUG - VM uve shows virtual network as default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:34:19,615 - INFO - Verifying through opserver in 10.0.0.56
2025-10-08 18:34:19,616 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714?flat
2025-10-08 18:34:19,635 - DEBUG - expected vm list 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:34:19,635 - DEBUG - Extracted vm list ['6b8bdfb0-af87-437e-b4af-6a5a0dd3f579']
2025-10-08 18:34:19,635 - INFO - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is present in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:34:19,635 - DEBUG - Verifying vm in vrouter uve
2025-10-08 18:34:19,635 - DEBUG - Getting info from collector 10.0.0.41..
2025-10-08 18:34:19,635 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat
2025-10-08 18:34:19,649 - DEBUG - VM uve shows vrouter as ['an-jenkins-deploy-platform-ansible-os-4239-2']
2025-10-08 18:34:19,649 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:34:19,690 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:34:19,717 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:34:19,717 - DEBUG - Validated that VM ctest-vn2_vm2-18719282 is in Vrouter an-jenkins-deploy-platform-ansible-os-4239-2 UVE
2025-10-08 18:34:19,717 - DEBUG - Verifying vm tap interface/vn in vrouter uve
2025-10-08 18:34:19,727 - DEBUG - Expected tap interface of VM uuid 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f
2025-10-08 18:34:19,727 - DEBUG - Expected VN of VM uuid 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:34:19,727 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:34:19,769 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:34:19,801 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:34:19,801 - INFO - tap interface default-domain:ctest-TestBasicVMVN0-71676797:ed4f7108-8ebd-4894-a956-d5a749ad280f of vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:34:19,801 - DEBUG - Connected network default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 of vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:34:19,801 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.56
2025-10-08 18:34:19,801 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:34:19,817 - DEBUG - VM link and name as {'name': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'href': 'http://10.0.0.56:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat'}
2025-10-08 18:34:19,817 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.249
2025-10-08 18:34:19,817 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:34:19,829 - DEBUG - VM link and name as {'name': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat'}
2025-10-08 18:34:19,829 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.41
2025-10-08 18:34:19,829 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:34:19,842 - DEBUG - VM link and name as {'name': '6b8bdfb0-af87-437e-b4af-6a5a0dd3f579', 'href': 'http://10.0.0.41:8081/analytics/uves/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579?flat'}
2025-10-08 18:34:19,842 - INFO - VM ctest-vn2_vm2-18719282 validations in Opserver passed
2025-10-08 18:34:19,842 - INFO - Waiting for VM ctest-vn1_vm2-60857096 to be up..
2025-10-08 18:34:19,842 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:19,842 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:34:19,850 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/c9157bf6-5abd-4d52-80b9-5309ce424d70
2025-10-08 18:34:21,000 - 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.05 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.409 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.409/1.731/3.053/1.322 ms')
2025-10-08 18:34:21,001 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1_vm2-60857096 passed
2025-10-08 18:34:21,073 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:21,073 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-60857096, IP 192.168.1.251, Port 22
2025-10-08 18:34:21,235 - DEBUG - VM ctest-vn1_vm2-60857096 is ready for SSH connections
2025-10-08 18:34:21,235 - INFO - Waiting for VM ctest-vn2_vm2-18719282 to be up..
2025-10-08 18:34:21,235 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:21,235 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:34:21,245 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine-interface/ed4f7108-8ebd-4894-a956-d5a749ad280f
2025-10-08 18:34:22,416 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=2.29 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.460 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.460/1.375/2.290/0.915 ms')
2025-10-08 18:34:22,416 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn2_vm2-18719282 passed
2025-10-08 18:34:22,484 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:22,485 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-18719282, IP 192.168.2.251, Port 22
2025-10-08 18:34:22,551 - 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-10-08 18:34:22,632 - DEBUG - VM ctest-vn2_vm2-18719282 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:34:27,633 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:27,633 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-18719282, IP 192.168.2.251, Port 22
2025-10-08 18:34:27,699 - 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-10-08 18:34:27,783 - DEBUG - VM ctest-vn2_vm2-18719282 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:34:32,783 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:32,783 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-18719282, IP 192.168.2.251, Port 22
2025-10-08 18:34:32,851 - 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-10-08 18:34:32,931 - DEBUG - VM ctest-vn2_vm2-18719282 is NOT ready for SSH connections, VM status: ACTIVE
2025-10-08 18:34:37,931 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:37,931 - DEBUG - Waiting to SSH to VM ctest-vn2_vm2-18719282, IP 192.168.2.251, Port 22
2025-10-08 18:34:38,109 - DEBUG - VM ctest-vn2_vm2-18719282 is ready for SSH connections
2025-10-08 18:34:38,109 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-10-08 18:34:38,109 - 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.33, gateway password: c0ntrail123
2025-10-08 18:34:38,109 - DEBUG - ping -s 56 -c 3 -W 1 192.168.2.251
2025-10-08 18:35:16,056 - DEBUG - PING 192.168.2.251 (192.168.2.251) 56(84) bytes of data.
64 bytes from 192.168.2.251: icmp_req=1 ttl=63 time=10.2 ms
64 bytes from 192.168.2.251: icmp_req=2 ttl=63 time=1.22 ms
64 bytes from 192.168.2.251: icmp_req=3 ttl=63 time=1.19 ms
--- 192.168.2.251 ping statistics ---
3 packets transmitted, 3 received, 0% packet loss, time 2003ms
rtt min/avg/max/mdev = 1.195/4.218/10.237/4.256 ms
2025-10-08 18:35:16,056 - INFO - Ping to IP 192.168.2.251 from VM ctest-vn1_vm2-60857096 passed
2025-10-08 18:35:16,056 - INFO - Deleting VM ctest-vn2_vm2-18719282
2025-10-08 18:35:16,122 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:35:16,123 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:35:16,132 - DEBUG - VM ID 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 of VM ctest-vn2_vm2-18719282 is still found in API Server
2025-10-08 18:35:18,133 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:35:18,133 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:35:18,140 - DEBUG - Response Code: 404
2025-10-08 18:35:18,140 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:35:18,146 - DEBUG - Response Code: 404
2025-10-08 18:35:18,146 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/6b8bdfb0-af87-437e-b4af-6a5a0dd3f579
2025-10-08 18:35:18,151 - DEBUG - Response Code: 404
2025-10-08 18:35:18,151 - INFO - VM ctest-vn2_vm2-18719282 is fully removed in API-Server
2025-10-08 18:35:18,303 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-10-08 18:35:18,336 - DEBUG - Validated that vrouter 10.0.0.33 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:35:18,469 - DEBUG - VM route 192.168.2.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 of compute 10.0.0.19
2025-10-08 18:35:18,474 - DEBUG - Validated that vrouter 10.0.0.19 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:35:18,474 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714
2025-10-08 18:35:18,474 - INFO - VM ctest-vn2_vm2-18719282 is removed in Compute, and routes are removed in all compute nodes
2025-10-08 18:35:18,711 - INFO - Routes for VM ctest-vn2_vm2-18719282 is removed in all control-nodes
2025-10-08 18:35:18,711 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:18,760 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:18,793 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:18,794 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:18,794 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:18,794 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:21,794 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:21,837 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:21,866 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:21,866 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:21,866 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:21,866 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:24,867 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:24,912 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:24,942 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:24,942 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:24,942 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:24,942 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:27,942 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:27,988 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:28,017 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:28,017 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:28,017 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:28,017 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:31,017 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:31,060 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:31,091 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:31,091 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:31,091 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:31,091 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:34,092 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:34,134 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:34,161 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:34,161 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:34,161 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:34,161 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:37,162 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:37,213 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:37,248 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:37,248 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:37,248 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:37,248 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:40,249 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:40,301 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:40,330 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:40,330 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:40,330 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:40,330 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:43,331 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:43,377 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:43,405 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:43,405 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:43,405 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:43,405 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:46,406 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-2:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:46,461 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-2?flat
2025-10-08 18:35:46,488 - DEBUG - VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4239-2 uve
2025-10-08 18:35:46,488 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:46,488 - DEBUG - interface for vm 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 deleted from vrouter uve ...
2025-10-08 18:35:46,488 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:46,488 - DEBUG - Validated that VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is removed in Vrouter UVE
2025-10-08 18:35:46,488 - DEBUG - Verifying through opserver in 10.0.0.56
2025-10-08 18:35:46,489 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714?flat
2025-10-08 18:35:46,511 - DEBUG - 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 BM not in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn2-83605714 uve
2025-10-08 18:35:46,511 - DEBUG - Validated that VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is not present in the VN UVE
2025-10-08 18:35:46,511 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.56
2025-10-08 18:35:46,511 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:35:46,521 - INFO - 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 vm uve deleted from opserver
2025-10-08 18:35:46,521 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.249
2025-10-08 18:35:46,522 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:35:46,573 - INFO - 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 vm uve deleted from opserver
2025-10-08 18:35:46,573 - DEBUG - Verifying the 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 virtual network link through opserver 10.0.0.41
2025-10-08 18:35:46,573 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:35:46,585 - INFO - 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 vm uve deleted from opserver
2025-10-08 18:35:46,585 - INFO - Validated that VM 6b8bdfb0-af87-437e-b4af-6a5a0dd3f579 is removed from Opserver
2025-10-08 18:35:46,585 - INFO - Deleting VM ctest-vn1_vm2-60857096
2025-10-08 18:35:46,644 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:35:46,644 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:35:46,653 - DEBUG - VM ID ced8e1bc-19b9-49fe-b626-1e9fc3f95340 of VM ctest-vn1_vm2-60857096 is still found in API Server
2025-10-08 18:35:48,653 - DEBUG - Verifying in api server 10.0.0.41
2025-10-08 18:35:48,654 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:35:48,661 - DEBUG - Response Code: 404
2025-10-08 18:35:48,661 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:35:48,669 - DEBUG - Response Code: 404
2025-10-08 18:35:48,669 - DEBUG - Requesting: http://10.0.0.41:8082/virtual-machine/ced8e1bc-19b9-49fe-b626-1e9fc3f95340
2025-10-08 18:35:48,676 - DEBUG - Response Code: 404
2025-10-08 18:35:48,676 - INFO - VM ctest-vn1_vm2-60857096 is fully removed in API-Server
2025-10-08 18:35:48,832 - DEBUG - Skipping VM-deletion-check in nova db since mysql_token is not found
2025-10-08 18:35:48,985 - DEBUG - VM route 192.168.1.251 has been marked for discard in VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 of compute 10.0.0.33
2025-10-08 18:35:48,990 - DEBUG - Validated that vrouter 10.0.0.33 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:35:48,990 - DEBUG - Validated that vrouter 10.0.0.19 does not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:35:48,990 - INFO - Validated that all vrouters do not have VMs route for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:35:48,990 - INFO - VM ctest-vn1_vm2-60857096 is removed in Compute, and routes are removed in all compute nodes
2025-10-08 18:35:49,205 - INFO - Routes for VM ctest-vn1_vm2-60857096 is removed in all control-nodes
2025-10-08 18:35:49,206 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:49,255 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:35:49,280 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:35:49,280 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:49,280 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:35:49,280 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:52,281 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:52,331 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:35:52,361 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:35:52,361 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:52,361 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:35:52,361 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:55,363 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:55,408 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:35:55,441 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:35:55,441 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:55,441 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:35:55,441 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:35:58,442 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:35:58,485 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:35:58,514 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:35:58,514 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:35:58,514 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:35:58,514 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:36:01,515 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:36:01,560 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:36:01,588 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:36:01,588 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:36:01,588 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:36:01,588 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:36:04,589 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:36:04,677 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:36:04,707 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is still present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:36:04,707 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:36:04,707 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:36:04,707 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:36:07,708 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/generator/an-jenkins-deploy-platform-ansible-os-4239-1:Compute:contrail-vrouter-agent:0?flat
2025-10-08 18:36:07,756 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/vrouter/an-jenkins-deploy-platform-ansible-os-4239-1?flat
2025-10-08 18:36:07,784 - DEBUG - VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is not present in vrouter an-jenkins-deploy-platform-ansible-os-4239-1 uve
2025-10-08 18:36:07,784 - DEBUG - Verifying if the vm interface deleted from vroter uve...
2025-10-08 18:36:07,784 - DEBUG - interface for vm ced8e1bc-19b9-49fe-b626-1e9fc3f95340 deleted from vrouter uve ...
2025-10-08 18:36:07,784 - DEBUG - Deleted interface not in error interface list ...
2025-10-08 18:36:07,784 - DEBUG - Validated that VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is removed in Vrouter UVE
2025-10-08 18:36:07,784 - DEBUG - Verifying through opserver in 10.0.0.56
2025-10-08 18:36:07,784 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864?flat
2025-10-08 18:36:07,806 - DEBUG - ced8e1bc-19b9-49fe-b626-1e9fc3f95340 BM not in default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864 uve
2025-10-08 18:36:07,806 - DEBUG - Validated that VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is not present in the VN UVE
2025-10-08 18:36:07,806 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.56
2025-10-08 18:36:07,806 - DEBUG - Requesting: http://10.0.0.56:8081/analytics/uves/virtual-machines
2025-10-08 18:36:07,819 - INFO - ced8e1bc-19b9-49fe-b626-1e9fc3f95340 vm uve deleted from opserver
2025-10-08 18:36:07,819 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.249
2025-10-08 18:36:07,819 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-machines
2025-10-08 18:36:07,833 - INFO - ced8e1bc-19b9-49fe-b626-1e9fc3f95340 vm uve deleted from opserver
2025-10-08 18:36:07,833 - DEBUG - Verifying the ced8e1bc-19b9-49fe-b626-1e9fc3f95340 virtual network link through opserver 10.0.0.41
2025-10-08 18:36:07,833 - DEBUG - Requesting: http://10.0.0.41:8081/analytics/uves/virtual-machines
2025-10-08 18:36:07,846 - INFO - ced8e1bc-19b9-49fe-b626-1e9fc3f95340 vm uve deleted from opserver
2025-10-08 18:36:07,846 - INFO - Validated that VM ced8e1bc-19b9-49fe-b626-1e9fc3f95340 is removed from Opserver
2025-10-08 18:36:07,846 - INFO - Deleting VN ctest-vn3-87146623
2025-10-08 18:36:07,964 - INFO - Deleting VM ctest-vn2_vm1-63535374
2025-10-08 18:36:08,044 - INFO - Deleting VM ctest-vn1_vm1-82660701
2025-10-08 18:36:08,312 - INFO - Deleting VN ctest-vn2-83605714
2025-10-08 18:36:08,385 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.41:8082/virtual-machine-interface/e6392a88-82b8-403b-860e-4877c9f54d0a'] while deleting VN ctest-vn2-83605714..Will retry
2025-10-08 18:36:10,511 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/6dff4db2-8a01-4f13-83dd-be3f84363ed6
2025-10-08 18:36:10,520 - DEBUG - Response Code: 404
2025-10-08 18:36:10,520 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:36:10,528 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:36:10,544 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:36:10,651 - INFO - Validated that VN ctest-vn2-83605714 is not found in API Server
2025-10-08 18:36:10,665 - DEBUG - VN ctest-vn2-83605714 is not present in Agent 10.0.0.33
2025-10-08 18:36:10,675 - DEBUG - VN ctest-vn2-83605714 is not present in Agent 10.0.0.19
2025-10-08 18:36:10,675 - INFO - Validated that VN ctest-vn2-83605714 is not in any agent
2025-10-08 18:36:10,703 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-83605714 info
2025-10-08 18:36:10,849 - INFO - Deleting VN ctest-vn1-16745864
2025-10-08 18:36:10,969 - DEBUG - Requesting: http://10.0.0.56:8082/routing-instance/3aea74e9-a5cf-466d-8376-8ba857fec919
2025-10-08 18:36:10,977 - DEBUG - Response Code: 404
2025-10-08 18:36:10,977 - DEBUG - Requesting: http://10.0.0.56:8082/domains
2025-10-08 18:36:10,983 - DEBUG - Requesting: http://10.0.0.56:8082/domain/1d11f468-2e8f-4a79-a987-f452a249cd6b
2025-10-08 18:36:10,999 - DEBUG - Requesting: http://10.0.0.56:8082/project/c77634c8-53f2-4f8b-9224-f7deebbf77db
2025-10-08 18:36:11,083 - INFO - Validated that VN ctest-vn1-16745864 is not found in API Server
2025-10-08 18:36:11,093 - DEBUG - VN ctest-vn1-16745864 is not present in Agent 10.0.0.33
2025-10-08 18:36:11,104 - DEBUG - VN ctest-vn1-16745864 is not present in Agent 10.0.0.19
2025-10-08 18:36:11,104 - INFO - Validated that VN ctest-vn1-16745864 is not in any agent
2025-10-08 18:36:11,109 - DEBUG - VRF 2 is not seen in agent 10.0.0.33
2025-10-08 18:36:11,113 - DEBUG - Vrouter 10.0.0.33 does not have vrf 2 for VN ctest-vn1-16745864
2025-10-08 18:36:11,113 - INFO - Validated that all vrouters do not have the route table for VN default-domain:ctest-TestBasicVMVN0-71676797:ctest-vn1-16745864
2025-10-08 18:36:11,135 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-16745864 info
2025-10-08 18:36:11,168 - INFO - Deleted policy policy2
2025-10-08 18:36:11,203 - INFO - Deleted policy policy1
2025-10-08 18:36:12,461 - DEBUG - Skipping xmpp flap check
2025-10-08 18:36:12,461 - INFO - END TEST : test_process_restart_in_policy_between_vns : PASSED[0:06:38]
2025-10-08 18:36:12,461 - INFO - --------------------------------------------------------------------------------
2025-10-08 18:36:12,463 - INFO - ================================================================================
2025-10-08 18:36:12,463 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling
2025-10-08 18:36:12,463 - 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-10-08 18:36:13,722 - DEBUG - Skipping xmpp flap check
2025-10-08 18:36:13,722 - INFO - Initial checks done. Running the testcase now
2025-10-08 18:36:13,722 - INFO -
2025-10-08 18:36:14,106 - INFO - Agent interface name: ens6
2025-10-08 18:36:14,187 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U host 0.0.0.0 -w /tmp/ens6_ctest-random-60697929.pcap
2025-10-08 18:36:19,572 - INFO - Pinging broacast address 0.0.0.0 from compute 10.20.0.14
2025-10-08 18:36:33,878 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2025-10-08 18:36:36,019 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:36,034 - DEBUG - STDOUT: 2
2025-10-08 18:36:36,035 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:36,035 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:38,036 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:38,053 - DEBUG - STDOUT: 2
2025-10-08 18:36:38,053 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:38,053 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:40,054 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:40,073 - DEBUG - STDOUT: 2
2025-10-08 18:36:40,074 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:40,074 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:42,074 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:42,090 - DEBUG - STDOUT: 2
2025-10-08 18:36:42,090 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:42,090 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:44,091 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:44,106 - DEBUG - STDOUT: 2
2025-10-08 18:36:44,106 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:44,106 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:46,107 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:46,123 - DEBUG - STDOUT: 2
2025-10-08 18:36:46,123 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:46,123 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:48,123 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-60697929.pcap | grep -c length
2025-10-08 18:36:48,138 - DEBUG - STDOUT: 2
2025-10-08 18:36:48,138 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-60697929.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-10-08 18:36:48,138 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-60697929.pcap but expected 10
2025-10-08 18:36:49,401 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Wed Oct 8 18:36:48 2025
A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
78 log.info('Initial checks done. Running the testcase now')
79 log.info('')
80 result = function(self, *args, **kwargs)
81 if self.inputs.upgrade:
82 pid = os.getpid()
result = None
function =
self =
args = ()
kwargs = {}
/contrail-test/serial_scripts/vm_regression/test_vm_serial.py in test_underlay_broadcast_traffic_handling(self=)
948
949 # Analyze pcap
950 assert verify_tcpdump_count(self, session, pcap, exp_count=packet_count), "There should only be %s\
951 packet from source %s on compute %s" %(packet_count, broadcast_address, compute_ip)
952 self.logger.info(
global verify_tcpdump_count = .deco_retry..f_retry>
self =
session =
pcap = '/tmp/ens6_ctest-random-60697929.pcap'
exp_count undefined
packet_count = 10
broadcast_address = '0.0.0.0'
compute_ip = '10.0.0.19'
AssertionError: There should only be 10 packet from source 0.0.0.0 on compute 10.0.0.19
__cause__ = None
__class__ =
__context__ = None
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = 'Assertion failed.'
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
args = ('There should only be 10 ... packet from source 0.0.0.0 on compute 10.0.0.19',)
with_traceback =
The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/serial_scripts/vm_regression/test_vm_serial.py", line 950, in test_underlay_broadcast_traffic_handling
assert verify_tcpdump_count(self, session, pcap, exp_count=packet_count), "There should only be %s\
AssertionError: There should only be 10 packet from source 0.0.0.0 on compute 10.0.0.19
2025-10-08 18:36:49,401 - DEBUG - Skipping xmpp flap check
2025-10-08 18:36:49,401 - INFO -
2025-10-08 18:36:49,403 - INFO - END TEST : test_underlay_broadcast_traffic_handling : FAILED[0:00:37]
2025-10-08 18:36:49,403 - INFO - --------------------------------------------------------------------------------
2025-10-08 18:36:50,197 - INFO - Deleted project: ctest-TestBasicVMVN0-71676797, ID : c77634c8-53f2-4f8b-9224-f7deebbf77db