2026-10-05 05:34:52,493 - INFO - Domain Default found not creating
2026-10-05 05:34:52,707 - INFO - Project ctest-TestBasicVMVN0-57626945 not found, creating it
2026-10-05 05:34:53,318 - INFO - Created Project:ctest-TestBasicVMVN0-57626945, ID : af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:34:55,584 - INFO - ================================================================================
2026-10-05 05:34:55,584 - INFO - STARTING TEST : test_control_node_switchover
2026-10-05 05:34:55,584 - INFO - TEST DESCRIPTION : Stop the control node and check peering with agent fallback to other control node.
1. Pick one VN from respource pool which has 2 VM's in it
2. Verify ping between VM's
3. Find active control node in cluster by agent inspect
4. Stop control service on active control node
5. Verify agents are connected to new active control-node using xmpp connections
6. Bring back control service on previous active node
7. Verify ping between VM's again after bringing up control serveice
Pass criteria: Step 2,5 and 7 should pass
2026-10-05 05:34:56,919 - DEBUG - Skipping xmpp flap check
2026-10-05 05:34:56,919 - INFO - Initial checks done. Running the testcase now
2026-10-05 05:34:56,919 - INFO -
2026-10-05 05:34:57,749 - DEBUG - Response for create_network : {'network': {'id': 'fd52df56-1a92-4686-96dc-51e952720a2c', 'name': 'ctest-vn1-90425407', 'tenant_id': 'af34b70ede2e4bb1bbd521145f94920a', 'project_id': 'af34b70ede2e4bb1bbd521145f94920a', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-57626945', 'ctest-vn1-90425407'], 'port_security_enabled': True, 'description': ''}}
2026-10-05 05:34:58,059 - DEBUG - Response for create_subnet : {'subnet': {'id': '2c1ef1d4-58a5-4e5e-86f9-abe5d5b27e4e', 'name': '', 'tenant_id': 'af34b70ede2e4bb1bbd521145f94920a', 'network_id': 'fd52df56-1a92-4686-96dc-51e952720a2c', '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': 'af34b70ede2e4bb1bbd521145f94920a'}}
2026-10-05 05:34:58,085 - INFO - Created VN ctest-vn1-90425407
2026-10-05 05:34:58,101 - DEBUG - VN ctest-vn1-90425407 UUID is fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,183 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:34:58,573 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:34:58,607 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:34:58,630 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:34:58,741 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,756 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,768 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:34:58,781 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:34:58,790 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/f5b983b2-ff16-40bc-ab16-387c3c49601b
2026-10-05 05:34:58,799 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:34:58,799 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,812 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:34:58,832 - INFO - Verified VN network id 22 for VN fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,832 - INFO - Verifications in API Server for VN ctest-vn1-90425407 passed
2026-10-05 05:34:58,832 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:58,845 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:34:58,854 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:34:58,864 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/f5b983b2-ff16-40bc-ab16-387c3c49601b
2026-10-05 05:34:58,881 - DEBUG - Control-node 10.0.0.177 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '18253897800592017030', 'uuid-lslong': '10870653663117969964'}, 'enable': 'true', 'created': '2026-10-05T05:34:57', 'last-modified': '2026-10-05T05:34:57', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.868148'}
2026-10-05 05:34:58,890 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:34:58,898 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '18253897800592017030', 'uuid-lslong': '10870653663117969964'}, 'enable': 'true', 'created': '2026-10-05T05:34:57', 'last-modified': '2026-10-05T05:34:57', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.901099'}
2026-10-05 05:34:58,906 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:34:58,913 - DEBUG - Control-node 10.0.0.190 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '18253897800592017030', 'uuid-lslong': '10870653663117969964'}, 'enable': 'true', 'created': '2026-10-05T05:34:57', 'last-modified': '2026-10-05T05:34:57', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.917938'}
2026-10-05 05:34:58,923 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:34:58,923 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-90425407 passed
2026-10-05 05:34:58,923 - DEBUG - ====Verifying policy data for ctest-vn1-90425407 in API_Server ======
2026-10-05 05:34:58,924 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:34:58,932 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:34:58,948 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:34:59,048 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/fd52df56-1a92-4686-96dc-51e952720a2c
2026-10-05 05:34:59,060 - DEBUG - =>VN ctest-vn1-90425407 has no policy to be verified
2026-10-05 05:34:59,060 - DEBUG - Verifying the vn in opserver
2026-10-05 05:34:59,060 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 virtual network link through opserver 10.0.0.177
2026-10-05 05:34:59,061 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks
2026-10-05 05:34:59,439 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks
2026-10-05 05:34:59,512 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'href': 'http://10.0.0.177:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407?flat'}
2026-10-05 05:34:59,512 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 virtual network link through opserver 10.0.0.38
2026-10-05 05:34:59,512 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2026-10-05 05:34:59,892 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2026-10-05 05:34:59,966 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407?flat'}
2026-10-05 05:34:59,966 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 virtual network link through opserver 10.0.0.190
2026-10-05 05:34:59,967 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks
2026-10-05 05:35:00,361 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks
2026-10-05 05:35:00,430 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407', 'href': 'http://10.0.0.190:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407?flat'}
2026-10-05 05:35:00,430 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is found in opserver
2026-10-05 05:35:00,457 - DEBUG - Do not have enough data to verify VN in agent
2026-10-05 05:35:00,470 - DEBUG - VRF ids for VN ctest-vn1-90425407: {}
2026-10-05 05:35:00,679 - DEBUG - Services list from nova: [, , , ]
2026-10-05 05:35:01,302 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6343-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6343-1)
2026-10-05 05:35:02,243 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6343-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6343-2)
2026-10-05 05:35:02,243 - INFO - Waiting for VM ctest-vn1_vm1-20825746 to be up..
2026-10-05 05:35:02,309 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:07,428 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:12,531 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:17,638 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:22,747 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:27,853 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:35:32,958 - DEBUG - VM is in ACTIVE state now
2026-10-05 05:35:32,958 - INFO - VM name : ctest-vn1_vm1-20825746
2026-10-05 05:35:33,055 - DEBUG - VM ctest-vn1_vm1-20825746 ID is f79b7029-2809-45c4-acab-4e9779ab860f
2026-10-05 05:35:33,088 - DEBUG - VM ctest-vn1_vm1-20825746 launched on Node an-jenkins-deploy-platform-ansible-os-6343-1
2026-10-05 05:35:33,182 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/f79b7029-2809-45c4-acab-4e9779ab860f
2026-10-05 05:35:33,563 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/f79b7029-2809-45c4-acab-4e9779ab860f
2026-10-05 05:35:33,609 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine-interface/860f7e11-1863-4681-a5ab-efc45a6cf3d0
2026-10-05 05:35:36,798 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms')
2026-10-05 05:35:36,798 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:36,818 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:35:40,901 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1010ms')
2026-10-05 05:35:40,901 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:40,920 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:35:44,994 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms')
2026-10-05 05:35:44,994 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:45,014 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:35:49,096 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms')
2026-10-05 05:35:49,097 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:49,115 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:35:53,179 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1003ms')
2026-10-05 05:35:53,179 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:53,197 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:35:57,280 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1022ms')
2026-10-05 05:35:57,281 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:35:57,298 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:36:01,376 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms')
2026-10-05 05:36:01,377 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 failed!
2026-10-05 05:36:01,397 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-90425407 is 192.168.1.1 and allocation pool is NOT set
2026-10-05 05:36:03,469 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n64 bytes from 169.254.0.7: icmp_seq=1 ttl=63 time=11.6 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=1.80 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 1.799/6.702/11.606/4.903 ms')
2026-10-05 05:36:03,469 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20825746 passed
2026-10-05 05:36:03,545 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:36:03,545 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20825746, IP 192.168.1.3, Port 22
2026-10-05 05:36:03,613 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:36:03,715 - DEBUG - VM ctest-vn1_vm1-20825746 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:36:08,716 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:36:08,717 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20825746, IP 192.168.1.3, Port 22
2026-10-05 05:36:08,784 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:36:08,878 - DEBUG - VM ctest-vn1_vm1-20825746 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:36:13,879 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:36:13,879 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20825746, IP 192.168.1.3, Port 22
2026-10-05 05:36:13,948 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:36:14,052 - DEBUG - VM ctest-vn1_vm1-20825746 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:36:19,052 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:36:19,053 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20825746, IP 192.168.1.3, Port 22
2026-10-05 05:36:19,224 - DEBUG - VM ctest-vn1_vm1-20825746 is ready for SSH connections
2026-10-05 05:36:19,224 - INFO - Waiting for VM ctest-vn1_vm2-76720314 to be up..
2026-10-05 05:36:19,286 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:24,346 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:29,408 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:34,474 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:39,540 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:44,601 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:49,656 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:54,727 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:36:59,792 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:04,854 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:09,916 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:14,977 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:20,036 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:25,105 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:30,166 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:35,227 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:40,284 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:45,347 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:50,406 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:37:55,471 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:00,535 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:05,609 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:10,710 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:15,772 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:20,837 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:25,906 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:30,966 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:36,023 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:41,091 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:46,230 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:51,289 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:38:51,289 - ERROR - VM is not in ACTIVE state
2026-10-05 05:38:51,379 - ERROR - Fatal Nova Exception while getting VM detail
2026-10-05 05:38:51,379 - DEBUG - None
2026-10-05 05:38:51,382 - INFO - Skip interface_detach for VM ctest-vn1_vm2-76720314 in state BUILD
2026-10-05 05:38:51,382 - INFO - Deleting VM ctest-vn1_vm2-76720314
2026-10-05 05:38:51,383 - ERROR - VM ctest-vn1_vm2-76720314 has failed to come up
2026-10-05 05:38:51,383 - ERROR - Nova failed to get host of the VM
2026-10-05 05:38:51,383 - ERROR - VM ctest-vn1_vm2-76720314 has failed to come up
2026-10-05 05:38:51,383 - ERROR - Nova failed to get host of the VM
2026-10-05 05:38:51,568 - INFO - Deleting VM ctest-vn1_vm1-20825746
2026-10-05 05:38:51,658 - INFO - Deleting VN ctest-vn1-90425407
2026-10-05 05:38:51,704 - DEBUG - VN fd52df56-1a92-4686-96dc-51e952720a2c still in use: Unable to complete operation on network fd52df56-1a92-4686-96dc-51e952720a2c. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-daaa2f33-50f5-47fa-94c5-7313c687509d']
2026-10-05 05:38:51,705 - WARNING - Deleting VN ctest-vn1-90425407 failed..Will retry
2026-10-05 05:38:53,778 - DEBUG - VN fd52df56-1a92-4686-96dc-51e952720a2c still in use: Unable to complete operation on network fd52df56-1a92-4686-96dc-51e952720a2c. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-4edea226-9dc0-45c4-a452-2ff42d345a91']
2026-10-05 05:38:53,779 - WARNING - Deleting VN ctest-vn1-90425407 failed..Will retry
2026-10-05 05:38:56,043 - DEBUG - Response for deleting network ()
2026-10-05 05:38:56,043 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8354b507-65be-49e6-bc58-834eee0a0012
2026-10-05 05:38:56,051 - DEBUG - Response Code: 404
2026-10-05 05:38:56,052 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:38:56,065 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:38:56,127 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:38:56,244 - INFO - Validated that VN ctest-vn1-90425407 is not found in API Server
2026-10-05 05:38:56,259 - DEBUG - VN ctest-vn1-90425407 is not present in Agent 10.0.0.50
2026-10-05 05:38:56,274 - DEBUG - VN ctest-vn1-90425407 is not present in Agent 10.0.0.191
2026-10-05 05:38:56,274 - INFO - Validated that VN ctest-vn1-90425407 is not in any agent
2026-10-05 05:38:56,318 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-90425407 info
2026-10-05 05:38:57,621 - ERROR - AssertionError
Python 3.9.25: /usr/bin/python3
Mon Oct 5 05:38:51 2026
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_control_node_switchover(self=)
636 vm2_fixture = self.create_vm(vn1_fixture, vn1_vm2_name)
637 assert vm1_fixture.wait_till_vm_is_up()
638 assert vm2_fixture.wait_till_vm_is_up()
639 assert vm1_fixture.ping_to_ip(vm2_fixture.vm_ip)
640 assert vm2_fixture.ping_to_ip(vm1_fixture.vm_ip)
vm2_fixture =
vm2_fixture.wait_till_vm_is_up = >
AssertionError:
__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 = ()
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 638, in test_control_node_switchover
assert vm2_fixture.wait_till_vm_is_up()
AssertionError
2026-10-05 05:38:57,621 - DEBUG - Skipping xmpp flap check
2026-10-05 05:38:57,622 - INFO -
2026-10-05 05:38:57,622 - INFO - END TEST : test_control_node_switchover : FAILED[0:04:02]
2026-10-05 05:38:57,622 - INFO - --------------------------------------------------------------------------------
2026-10-05 05:38:57,625 - INFO - ================================================================================
2026-10-05 05:38:57,625 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns
2026-10-05 05:38:57,625 - INFO - TEST DESCRIPTION : Test to validate that with policy having rule to check icmp fwding between VMs on different VNs , ping between VMs should pass
with process restarts
1. Pick 2 VN's from resource pool which has one VM each
2. Create policy with icmp allow rule between those VN's and bind it networks
3. Ping from one VM to another VM
4. Restart process 'vrouter' and 'control' on setup
5. Ping again between VM's after process restart
Pass criteria: Step 2,3,4 and 5 should pass
2026-10-05 05:38:58,933 - DEBUG - Skipping xmpp flap check
2026-10-05 05:38:58,933 - INFO - Initial checks done. Running the testcase now
2026-10-05 05:38:58,933 - INFO -
2026-10-05 05:38:58,941 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572, 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-57626945:ctest-vn2-20220263, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None]
2026-10-05 05:38:59,270 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263, 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-57626945:ctest-vn1-35396572, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = pass, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None]
2026-10-05 05:38:59,878 - INFO - Created VN ctest-vn1-35396572, UUID :50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,266 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:39:00,275 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:39:00,291 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:39:00,402 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,419 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,434 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:39:00,444 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:39:00,454 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/68e90eca-5e4d-42df-a480-1c33dd587997
2026-10-05 05:39:00,466 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:39:00,466 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,480 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:39:00,504 - INFO - Verified VN network id 22 for VN 50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,505 - INFO - Verifications in API Server for VN ctest-vn1-35396572 passed
2026-10-05 05:39:00,505 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,519 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:39:00,530 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:39:00,544 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/68e90eca-5e4d-42df-a480-1c33dd587997
2026-10-05 05:39:00,564 - DEBUG - Control-node 10.0.0.177 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5831854291807388324', 'uuid-lslong': '10055190786866038974'}, 'enable': 'true', 'created': '2026-10-05T05:38:59', 'last-modified': '2026-10-05T05:39:00', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.497677'}
2026-10-05 05:39:00,572 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:39:00,579 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5831854291807388324', 'uuid-lslong': '10055190786866038974'}, 'enable': 'true', 'created': '2026-10-05T05:38:59', 'last-modified': '2026-10-05T05:39:00', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.527379'}
2026-10-05 05:39:00,589 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:39:00,598 - DEBUG - Control-node 10.0.0.190 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5831854291807388324', 'uuid-lslong': '10055190786866038974'}, 'enable': 'true', 'created': '2026-10-05T05:38:59', 'last-modified': '2026-10-05T05:39:00', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.532504'}
2026-10-05 05:39:00,608 - DEBUG - Route Targets: ['target:64512:8000013']
2026-10-05 05:39:00,609 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-35396572 passed
2026-10-05 05:39:00,609 - DEBUG - ====Verifying policy data for ctest-vn1-35396572 in API_Server ======
2026-10-05 05:39:00,609 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:39:00,618 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:39:00,635 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:39:00,748 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/50eee894-7504-42a4-8b8b-36bef7ee48be
2026-10-05 05:39:00,761 - DEBUG - =>VN ctest-vn1-35396572 has no policy to be verified
2026-10-05 05:39:00,761 - DEBUG - Verifying the vn in opserver
2026-10-05 05:39:00,762 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 virtual network link through opserver 10.0.0.177
2026-10-05 05:39:00,762 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks
2026-10-05 05:39:00,778 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'href': 'http://10.0.0.177:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572?flat'}
2026-10-05 05:39:00,778 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 virtual network link through opserver 10.0.0.38
2026-10-05 05:39:00,778 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2026-10-05 05:39:00,838 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572?flat'}
2026-10-05 05:39:00,838 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 virtual network link through opserver 10.0.0.190
2026-10-05 05:39:00,838 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks
2026-10-05 05:39:00,899 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572', 'href': 'http://10.0.0.190:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572?flat'}
2026-10-05 05:39:00,899 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is found in opserver
2026-10-05 05:39:00,924 - DEBUG - Do not have enough data to verify VN in agent
2026-10-05 05:39:00,937 - DEBUG - VRF ids for VN ctest-vn1-35396572: {}
2026-10-05 05:39:01,698 - INFO - Created VN ctest-vn2-20220263, UUID :b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,052 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:39:02,059 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:39:02,074 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:39:02,190 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,208 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,223 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:39:02,236 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:39:02,248 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/e3be0e94-19da-4c33-b284-b466f17a7684
2026-10-05 05:39:02,258 - DEBUG - Route Targets: ['target:64512:8000014']
2026-10-05 05:39:02,258 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,271 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:39:02,293 - INFO - Verified VN network id 23 for VN b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,293 - INFO - Verifications in API Server for VN ctest-vn2-20220263 passed
2026-10-05 05:39:02,293 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,306 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:39:02,316 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:39:02,327 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/e3be0e94-19da-4c33-b284-b466f17a7684
2026-10-05 05:39:02,346 - DEBUG - Control-node 10.0.0.177 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13040005453309035171', 'uuid-lslong': '10917003829901212608'}, 'enable': 'true', 'created': '2026-10-05T05:39:01', 'last-modified': '2026-10-05T05:39:01', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.484320'}
2026-10-05 05:39:02,353 - DEBUG - Route Targets: ['target:64512:8000014']
2026-10-05 05:39:02,360 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13040005453309035171', 'uuid-lslong': '10917003829901212608'}, 'enable': 'true', 'created': '2026-10-05T05:39:01', 'last-modified': '2026-10-05T05:39:01', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.496944'}
2026-10-05 05:39:02,368 - DEBUG - Route Targets: ['target:64512:8000014']
2026-10-05 05:39:02,376 - DEBUG - Control-node 10.0.0.190 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-57626945', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13040005453309035171', 'uuid-lslong': '10917003829901212608'}, 'enable': 'true', 'created': '2026-10-05T05:39:01', 'last-modified': '2026-10-05T05:39:01', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.516559'}
2026-10-05 05:39:02,383 - DEBUG - Route Targets: ['target:64512:8000014']
2026-10-05 05:39:02,383 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-20220263 passed
2026-10-05 05:39:02,384 - DEBUG - ====Verifying policy data for ctest-vn2-20220263 in API_Server ======
2026-10-05 05:39:02,384 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:39:02,391 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:39:02,406 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:39:02,505 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/b4f767de-f1a4-42a3-9780-fd247cd73bc0
2026-10-05 05:39:02,517 - DEBUG - =>VN ctest-vn2-20220263 has no policy to be verified
2026-10-05 05:39:02,517 - DEBUG - Verifying the vn in opserver
2026-10-05 05:39:02,517 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263 virtual network link through opserver 10.0.0.177
2026-10-05 05:39:02,517 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks
2026-10-05 05:39:02,591 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'href': 'http://10.0.0.177:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263?flat'}
2026-10-05 05:39:02,591 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263 virtual network link through opserver 10.0.0.38
2026-10-05 05:39:02,591 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks
2026-10-05 05:39:02,649 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263?flat'}
2026-10-05 05:39:02,649 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263 virtual network link through opserver 10.0.0.190
2026-10-05 05:39:02,649 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks
2026-10-05 05:39:02,710 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263', 'href': 'http://10.0.0.190:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263?flat'}
2026-10-05 05:39:02,710 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn2-20220263 is found in opserver
2026-10-05 05:39:02,741 - DEBUG - Do not have enough data to verify VN in agent
2026-10-05 05:39:02,753 - DEBUG - VRF ids for VN ctest-vn2-20220263: {}
2026-10-05 05:39:04,096 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6343-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6343-1)
2026-10-05 05:39:04,921 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-6343-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-6343-2)
2026-10-05 05:39:04,921 - INFO - Waiting for VM ctest-vn1_vm1-49223081 to be up..
2026-10-05 05:39:04,986 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:10,134 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:15,249 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:20,357 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:25,470 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:30,573 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:39:35,677 - DEBUG - VM is in ACTIVE state now
2026-10-05 05:39:35,677 - INFO - VM name : ctest-vn1_vm1-49223081
2026-10-05 05:39:35,783 - DEBUG - VM ctest-vn1_vm1-49223081 ID is ae22a705-9585-4c1b-9375-06156e251bdc
2026-10-05 05:39:35,783 - DEBUG - VM ctest-vn1_vm1-49223081 launched on Node an-jenkins-deploy-platform-ansible-os-6343-1
2026-10-05 05:39:35,891 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/ae22a705-9585-4c1b-9375-06156e251bdc
2026-10-05 05:39:35,904 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine-interface/b8d5a6e6-a08c-4314-9471-f0a94677682d
2026-10-05 05:39:39,103 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1021ms')
2026-10-05 05:39:39,104 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:39,121 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:39:43,203 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1011ms')
2026-10-05 05:39:43,203 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:43,220 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:39:47,296 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1012ms')
2026-10-05 05:39:47,296 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:47,313 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:39:51,391 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2026-10-05 05:39:51,391 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:51,408 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:39:55,485 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms')
2026-10-05 05:39:55,486 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:55,505 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:39:59,584 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1011ms')
2026-10-05 05:39:59,584 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:39:59,624 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:40:03,714 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms')
2026-10-05 05:40:03,714 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 failed!
2026-10-05 05:40:03,735 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-57626945:ctest-vn1-35396572 is 192.168.1.254 and allocation pool is NOT set
2026-10-05 05:40:05,807 - DEBUG - (True, 'PING 169.254.0.7 (169.254.0.7) 56(84) bytes of data.\r\n64 bytes from 169.254.0.7: icmp_seq=1 ttl=63 time=15.4 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=3.40 ms\r\n\r\n--- 169.254.0.7 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 3.397/9.376/15.356/5.979 ms')
2026-10-05 05:40:05,807 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-49223081 passed
2026-10-05 05:40:05,882 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:40:05,882 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-49223081, IP 192.168.1.252, Port 22
2026-10-05 05:40:05,952 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:40:06,129 - DEBUG - VM ctest-vn1_vm1-49223081 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:40:11,130 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:40:11,130 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-49223081, IP 192.168.1.252, Port 22
2026-10-05 05:40:11,211 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:40:11,360 - DEBUG - VM ctest-vn1_vm1-49223081 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:40:16,361 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:40:16,361 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-49223081, IP 192.168.1.252, Port 22
2026-10-05 05:40:16,428 - DEBUG - Error on ssh to ubuntu@169.254.0.7:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.7/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.7/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.7/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-05 05:40:16,531 - DEBUG - VM ctest-vn1_vm1-49223081 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-05 05:40:21,532 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-05 05:40:21,532 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-49223081, IP 192.168.1.252, Port 22
2026-10-05 05:40:21,712 - DEBUG - VM ctest-vn1_vm1-49223081 is ready for SSH connections
2026-10-05 05:40:21,712 - INFO - Waiting for VM ctest-vn2_vm1-30542495 to be up..
2026-10-05 05:40:21,771 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:26,842 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:31,923 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:36,985 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:42,044 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:47,111 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:52,170 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:40:57,255 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:02,314 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:07,390 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:12,481 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:17,543 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:22,603 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:27,672 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:32,734 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:37,797 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:42,859 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:47,921 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:52,985 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:41:58,056 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:03,122 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:08,188 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:13,255 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:18,319 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:23,378 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:28,448 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:33,510 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:38,570 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:43,625 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:48,694 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:53,757 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-05 05:42:53,758 - ERROR - VM is not in ACTIVE state
2026-10-05 05:42:53,852 - ERROR - Fatal Nova Exception while getting VM detail
2026-10-05 05:42:53,852 - DEBUG - None
2026-10-05 05:42:53,853 - INFO - Skip interface_detach for VM ctest-vn2_vm1-30542495 in state BUILD
2026-10-05 05:42:53,854 - INFO - Deleting VM ctest-vn2_vm1-30542495
2026-10-05 05:42:53,854 - ERROR - VM ctest-vn2_vm1-30542495 has failed to come up
2026-10-05 05:42:53,854 - ERROR - Nova failed to get host of the VM
2026-10-05 05:42:53,854 - ERROR - VM ctest-vn2_vm1-30542495 has failed to come up
2026-10-05 05:42:53,854 - ERROR - Nova failed to get host of the VM
2026-10-05 05:42:54,027 - INFO - Deleting VM ctest-vn1_vm1-49223081
2026-10-05 05:42:54,379 - INFO - Deleting VN ctest-vn2-20220263
2026-10-05 05:42:54,544 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/d2ee9c5f-186c-4dbf-ae86-0e15c4b75bd9
2026-10-05 05:42:54,581 - DEBUG - Response Code: 404
2026-10-05 05:42:54,582 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:42:54,593 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:42:54,608 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:42:54,758 - INFO - Validated that VN ctest-vn2-20220263 is not found in API Server
2026-10-05 05:42:54,777 - DEBUG - VN ctest-vn2-20220263 is not present in Agent 10.0.0.50
2026-10-05 05:42:54,791 - DEBUG - VN ctest-vn2-20220263 is not present in Agent 10.0.0.191
2026-10-05 05:42:54,791 - INFO - Validated that VN ctest-vn2-20220263 is not in any agent
2026-10-05 05:42:54,835 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-20220263 info
2026-10-05 05:42:55,030 - INFO - Deleting VN ctest-vn1-35396572
2026-10-05 05:42:55,090 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.190:8082/virtual-machine-interface/b8d5a6e6-a08c-4314-9471-f0a94677682d'] while deleting VN ctest-vn1-35396572..Will retry
2026-10-05 05:42:57,241 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0922f89b-54c8-46a0-a23a-af981938f063
2026-10-05 05:42:57,249 - DEBUG - Response Code: 404
2026-10-05 05:42:57,249 - DEBUG - Requesting: http://10.0.0.177:8082/domains
2026-10-05 05:42:57,259 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054
2026-10-05 05:42:57,284 - DEBUG - Requesting: http://10.0.0.177:8082/project/af34b70e-de2e-4bb1-bbd5-21145f94920a
2026-10-05 05:42:57,399 - INFO - Validated that VN ctest-vn1-35396572 is not found in API Server
2026-10-05 05:42:57,413 - DEBUG - VN ctest-vn1-35396572 is not present in Agent 10.0.0.50
2026-10-05 05:42:57,425 - DEBUG - VN ctest-vn1-35396572 is not present in Agent 10.0.0.191
2026-10-05 05:42:57,425 - INFO - Validated that VN ctest-vn1-35396572 is not in any agent
2026-10-05 05:42:57,485 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-35396572 info
2026-10-05 05:42:57,526 - INFO - Deleted policy policy2
2026-10-05 05:42:57,567 - INFO - Deleted policy policy1
2026-10-05 05:42:58,893 - ERROR - AssertionError
Python 3.9.25: /usr/bin/python3
Mon Oct 5 05:42:53 2026
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_process_restart_in_policy_between_vns(self=)
405 vm2_fixture = self.create_vm(vn2_fixture, vn2_vm1_name)
406 assert vm1_fixture.wait_till_vm_is_up()
407 assert vm2_fixture.wait_till_vm_is_up()
408 assert vm1_fixture.ping_with_certainty(vm2_fixture.vm_ip)
409
vm2_fixture =
vm2_fixture.wait_till_vm_is_up = >
AssertionError:
__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 = ()
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 407, in test_process_restart_in_policy_between_vns
assert vm2_fixture.wait_till_vm_is_up()
AssertionError
2026-10-05 05:42:58,893 - DEBUG - Skipping xmpp flap check
2026-10-05 05:42:58,894 - INFO -
2026-10-05 05:42:58,894 - INFO - END TEST : test_process_restart_in_policy_between_vns : FAILED[0:04:01]
2026-10-05 05:42:58,894 - INFO - --------------------------------------------------------------------------------
2026-10-05 05:42:58,898 - INFO - ================================================================================
2026-10-05 05:42:58,898 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling
2026-10-05 05:42:58,898 - INFO - TEST DESCRIPTION : Test the underlay brocast traffic handling by vrouter. (Bug-1545229).
1. Send broadcast traffic from one compute node.
2. Other compute in same subnet should receive that traffic.
3. Receiving compute should treat this traffic as underlay.
4. Compute should not replicate the packet and send the copy back.
Pass criteria: Step 3-4 should pass
Maintainer : chhandak@juniper.net
2026-10-05 05:43:00,228 - DEBUG - Skipping xmpp flap check
2026-10-05 05:43:00,228 - INFO - Initial checks done. Running the testcase now
2026-10-05 05:43:00,228 - INFO -
2026-10-05 05:43:00,667 - INFO - Agent interface name: enp5s0
2026-10-05 05:43:00,746 - DEBUG - Executing command: sudo tcpdump -nni enp5s0 -U host 10.20.0.255 -w /tmp/enp5s0_ctest-random-23565053.pcap
2026-10-05 05:43:06,204 - INFO - Pinging broacast address 10.20.0.255 from compute 10.20.0.193
2026-10-05 05:43:20,480 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-10-05 05:43:22,623 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/enp5s0_ctest-random-23565053.pcap | grep -c length
2026-10-05 05:43:22,641 - DEBUG - STDOUT: 10
2026-10-05 05:43:22,641 - DEBUG - STDERR: reading from file /tmp/enp5s0_ctest-random-23565053.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2026-10-05 05:43:22,641 - INFO - 10 packets are found in tcpdump output as expected
2026-10-05 05:43:22,641 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2026-10-05 05:43:24,687 - INFO - Packet count matched: Compute 10.0.0.191 has receive only 10 packet from source IP 10.20.0.255. No duplicate packet seen
2026-10-05 05:43:26,030 - DEBUG - Skipping xmpp flap check
2026-10-05 05:43:26,030 - INFO - END TEST : test_underlay_broadcast_traffic_handling : PASSED[0:00:28]
2026-10-05 05:43:26,030 - INFO - --------------------------------------------------------------------------------
2026-10-05 05:43:27,895 - INFO - Deleted project: ctest-TestBasicVMVN0-57626945, ID : af34b70e-de2e-4bb1-bbd5-21145f94920a