2025-09-11 03:27:55,116 - INFO - Domain Default found not creating
2025-09-11 03:27:55,278 - INFO - Project ctest-TestBasicVMVN0-49175314 not found, creating it
2025-09-11 03:27:55,805 - INFO - Created Project:ctest-TestBasicVMVN0-49175314, ID : 44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:27:57,361 - INFO - ================================================================================
2025-09-11 03:27:57,361 - INFO - STARTING TEST : test_control_node_switchover
2025-09-11 03:27:57,361 - 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-09-11 03:27:58,608 - DEBUG - Skipping xmpp flap check
2025-09-11 03:27:58,608 - INFO - Initial checks done. Running the testcase now
2025-09-11 03:27:58,608 - INFO -
2025-09-11 03:27:59,272 - DEBUG - Response for create_network : {'network': {'id': '456e0ce6-2b4d-4a1d-a811-502c8c479850', 'name': 'ctest-vn1-35963032', 'tenant_id': '44c75927370a40c78f40bb5ccf53216c', 'project_id': '44c75927370a40c78f40bb5ccf53216c', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN0-49175314', 'ctest-vn1-35963032'], 'port_security_enabled': True, 'description': ''}}
2025-09-11 03:27:59,787 - DEBUG - Response for create_subnet : {'subnet': {'id': '3a8cd06c-7de0-4f73-9b19-07c84f648622', 'name': '', 'tenant_id': '44c75927370a40c78f40bb5ccf53216c', 'network_id': '456e0ce6-2b4d-4a1d-a811-502c8c479850', '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': '44c75927370a40c78f40bb5ccf53216c'}}
2025-09-11 03:27:59,821 - INFO - Created VN ctest-vn1-35963032
2025-09-11 03:27:59,835 - DEBUG - VN ctest-vn1-35963032 UUID is 456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:27:59,930 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:28:00,236 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:28:00,295 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:28:00,317 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:28:00,431 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,457 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,474 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:28:00,484 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:28:00,494 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/9bad3719-2cdc-44ff-8544-479c0a7e81d9
2025-09-11 03:28:00,514 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:28:00,514 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,526 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:28:00,548 - INFO - Verified VN network id 17 for VN 456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,549 - INFO - Verifications in API Server for VN ctest-vn1-35963032 passed
2025-09-11 03:28:00,550 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,562 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:28:00,572 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:28:00,582 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/9bad3719-2cdc-44ff-8544-479c0a7e81d9
2025-09-11 03:28:00,603 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5002950418763696669', 'uuid-lslong': '12110549025238259792'}, 'enable': 'true', 'created': '2025-09-11T03:27:59', 'last-modified': '2025-09-11T03:27:59', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.871500'}
2025-09-11 03:28:00,613 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:28:00,618 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5002950418763696669', 'uuid-lslong': '12110549025238259792'}, 'enable': 'true', 'created': '2025-09-11T03:27:59', 'last-modified': '2025-09-11T03:27:59', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.887165'}
2025-09-11 03:28:00,624 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:28:00,631 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5002950418763696669', 'uuid-lslong': '12110549025238259792'}, 'enable': 'true', 'created': '2025-09-11T03:27:59', 'last-modified': '2025-09-11T03:27:59', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.900428'}
2025-09-11 03:28:00,638 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:28:00,638 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-35963032 passed
2025-09-11 03:28:00,638 - DEBUG - ====Verifying policy data for ctest-vn1-35963032 in API_Server ======
2025-09-11 03:28:00,638 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:28:00,645 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:28:00,661 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:28:00,762 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/456e0ce6-2b4d-4a1d-a811-502c8c479850
2025-09-11 03:28:00,775 - DEBUG - =>VN ctest-vn1-35963032 has no policy to be verified
2025-09-11 03:28:00,775 - DEBUG - Verifying the vn in opserver
2025-09-11 03:28:00,775 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 virtual network link through opserver 10.0.0.249
2025-09-11 03:28:00,775 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,085 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,161 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032?flat'}
2025-09-11 03:28:01,161 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 virtual network link through opserver 10.0.0.22
2025-09-11 03:28:01,161 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,490 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,566 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032?flat'}
2025-09-11 03:28:01,566 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 virtual network link through opserver 10.0.0.49
2025-09-11 03:28:01,566 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,872 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-09-11 03:28:01,934 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032?flat'}
2025-09-11 03:28:01,934 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is found in opserver
2025-09-11 03:28:01,956 - DEBUG - Do not have enough data to verify VN in agent
2025-09-11 03:28:01,966 - DEBUG - VRF ids for VN ctest-vn1-35963032: {}
2025-09-11 03:28:02,213 - DEBUG - Services list from nova: [, , , ]
2025-09-11 03:28:03,533 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4079-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4079-1)
2025-09-11 03:28:05,423 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4079-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4079-2)
2025-09-11 03:28:05,423 - INFO - Waiting for VM ctest-vn1_vm1-22298201 to be up..
2025-09-11 03:28:05,510 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-11 03:28:10,601 - DEBUG - VM is in ACTIVE state now
2025-09-11 03:28:10,601 - INFO - VM name : ctest-vn1_vm1-22298201
2025-09-11 03:28:10,688 - DEBUG - VM ctest-vn1_vm1-22298201 ID is 8d6f8cd7-e905-4ca4-9feb-de9e3baf0217
2025-09-11 03:28:10,716 - DEBUG - VM ctest-vn1_vm1-22298201 launched on Node an-jenkins-deploy-platform-ansible-os-4079-1
2025-09-11 03:28:10,799 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/8d6f8cd7-e905-4ca4-9feb-de9e3baf0217
2025-09-11 03:28:11,109 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/8d6f8cd7-e905-4ca4-9feb-de9e3baf0217
2025-09-11 03:28:11,159 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/e2bc2112-a19d-470f-9080-5fc18beb1b9c
2025-09-11 03:28:14,345 - 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 1026ms')
2025-09-11 03:28:14,345 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:14,361 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:18,442 - 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')
2025-09-11 03:28:18,442 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:18,457 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:22,549 - 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 1026ms')
2025-09-11 03:28:22,549 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:22,564 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:26,634 - 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 1007ms')
2025-09-11 03:28:26,634 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:26,647 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:30,734 - 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')
2025-09-11 03:28:30,735 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:30,748 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:34,833 - 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 1019ms')
2025-09-11 03:28:34,833 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:34,849 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:38,927 - 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')
2025-09-11 03:28:38,927 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:38,944 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:43,018 - 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 1015ms')
2025-09-11 03:28:43,018 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 failed!
2025-09-11 03:28:43,033 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-35963032 is 192.168.1.1 and allocation pool is NOT set
2025-09-11 03:28:45,105 - 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=7.89 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=6.83 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 = 6.830/7.362/7.894/0.532 ms')
2025-09-11 03:28:45,105 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-22298201 passed
2025-09-11 03:28:45,176 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:28:45,176 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-22298201, IP 192.168.1.3, Port 22
2025-09-11 03:28:45,240 - 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': ''}
2025-09-11 03:28:45,317 - DEBUG - VM ctest-vn1_vm1-22298201 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:28:50,318 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:28:50,318 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-22298201, IP 192.168.1.3, Port 22
2025-09-11 03:28:50,385 - 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': ''}
2025-09-11 03:28:50,500 - DEBUG - VM ctest-vn1_vm1-22298201 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:28:55,500 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:28:55,500 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-22298201, IP 192.168.1.3, Port 22
2025-09-11 03:28:55,570 - 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': ''}
2025-09-11 03:28:55,684 - DEBUG - VM ctest-vn1_vm1-22298201 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:29:00,685 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:29:00,685 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-22298201, IP 192.168.1.3, Port 22
2025-09-11 03:29:00,743 - 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': ''}
2025-09-11 03:29:00,831 - DEBUG - VM ctest-vn1_vm1-22298201 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:29:05,832 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:29:05,832 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-22298201, IP 192.168.1.3, Port 22
2025-09-11 03:29:06,001 - DEBUG - VM ctest-vn1_vm1-22298201 is ready for SSH connections
2025-09-11 03:29:06,001 - INFO - Waiting for VM ctest-vn1_vm2-13963437 to be up..
2025-09-11 03:29:06,061 - DEBUG - VM is in ERROR state now
2025-09-11 03:29:06,061 - ERROR - VM in error state.
2025-09-11 03:29:06,061 - ERROR - VM is not in ACTIVE state
2025-09-11 03:29:06,144 - ERROR - Fatal Nova Exception while getting VM detail
2025-09-11 03:29:06,144 - DEBUG - None
2025-09-11 03:29:06,147 - INFO - Skip interface_detach for VM ctest-vn1_vm2-13963437 in state ERROR
2025-09-11 03:29:06,148 - INFO - Deleting VM ctest-vn1_vm2-13963437
2025-09-11 03:29:06,148 - ERROR - VM ctest-vn1_vm2-13963437 has failed to come up
2025-09-11 03:29:06,148 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-09-11T03:28:05Z', 'message': 'No valid host was found. ', 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 1581, in schedule_and_build_instances\n instance_uuids, return_alternates=True)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 942, in _schedule_instances\n return_alternates=return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/client/query.py", line 42, in select_destinations\n instance_uuids, return_objects, return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/rpcapi.py", line 160, in select_destinations\n return cctxt.call(ctxt, \'select_destinations\', **msg_args)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/client.py", line 192, in call\n retry=self.retry, transport_options=self.transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/transport.py", line 128, in _send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 691, in send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 681, in _send\n raise result\nnova.exception_Remote.NoValidHost_Remote: No valid host was found. \nTraceback (most recent call last):\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 241, in inner\n return func(*args, **kwargs)\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/manager.py", line 209, in select_destinations\n raise exception.NoValidHost(reason="")\n\nnova.exception.NoValidHost: No valid host was found. \n\n'}
2025-09-11 03:29:06,148 - INFO - Deleting VM ctest-vn1_vm1-22298201
2025-09-11 03:29:06,221 - INFO - Deleting VN ctest-vn1-35963032
2025-09-11 03:29:06,261 - DEBUG - VN 456e0ce6-2b4d-4a1d-a811-502c8c479850 still in use: Unable to complete operation on network 456e0ce6-2b4d-4a1d-a811-502c8c479850. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-7d8ca5e3-c628-4b9f-a946-2d793e61d0ff']
2025-09-11 03:29:06,262 - WARNING - Deleting VN ctest-vn1-35963032 failed..Will retry
2025-09-11 03:29:08,409 - DEBUG - Response for deleting network ()
2025-09-11 03:29:08,409 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/c7872479-88e8-45fa-95bc-55f7c68ee36f
2025-09-11 03:29:08,417 - DEBUG - Response Code: 404
2025-09-11 03:29:08,417 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:29:08,428 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:29:08,450 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:29:08,561 - INFO - Validated that VN ctest-vn1-35963032 is not found in API Server
2025-09-11 03:29:08,573 - DEBUG - VN ctest-vn1-35963032 is not present in Agent 10.0.0.254
2025-09-11 03:29:08,590 - DEBUG - VN ctest-vn1-35963032 is not present in Agent 10.0.0.19
2025-09-11 03:29:08,590 - INFO - Validated that VN ctest-vn1-35963032 is not in any agent
2025-09-11 03:29:08,625 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-35963032 info
2025-09-11 03:29:09,911 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Thu Sep 11 03:29:06 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_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
2025-09-11 03:29:09,912 - DEBUG - Skipping xmpp flap check
2025-09-11 03:29:09,912 - INFO -
2025-09-11 03:29:09,912 - INFO - END TEST : test_control_node_switchover : FAILED[0:01:12]
2025-09-11 03:29:09,912 - INFO - --------------------------------------------------------------------------------
2025-09-11 03:29:09,916 - INFO - ================================================================================
2025-09-11 03:29:09,917 - INFO - STARTING TEST : test_process_restart_in_policy_between_vns
2025-09-11 03:29:09,917 - 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-09-11 03:29:11,187 - DEBUG - Skipping xmpp flap check
2025-09-11 03:29:11,187 - INFO - Initial checks done. Running the testcase now
2025-09-11 03:29:11,187 - INFO -
2025-09-11 03:29:11,193 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645, 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-49175314:ctest-vn2-70341741, 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-09-11 03:29:11,471 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741, 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-49175314:ctest-vn1-39841645, 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-09-11 03:29:12,011 - INFO - Created VN ctest-vn1-39841645, UUID :0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,322 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:29:12,331 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:29:12,345 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:29:12,457 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,474 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,491 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:29:12,502 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:29:12,513 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/9c325ccd-7fcf-4d13-91b2-684f02f83722
2025-09-11 03:29:12,529 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:29:12,529 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,541 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:29:12,560 - INFO - Verified VN network id 17 for VN 0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,560 - INFO - Verifications in API Server for VN ctest-vn1-39841645 passed
2025-09-11 03:29:12,560 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,571 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:29:12,579 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:29:12,587 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/9c325ccd-7fcf-4d13-91b2-684f02f83722
2025-09-11 03:29:12,603 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1074447748590029986', 'uuid-lslong': '12354593507045645965'}, 'enable': 'true', 'created': '2025-09-11T03:29:11', 'last-modified': '2025-09-11T03:29:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.457677'}
2025-09-11 03:29:12,610 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:29:12,616 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1074447748590029986', 'uuid-lslong': '12354593507045645965'}, 'enable': 'true', 'created': '2025-09-11T03:29:11', 'last-modified': '2025-09-11T03:29:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.471196'}
2025-09-11 03:29:12,622 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:29:12,629 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1074447748590029986', 'uuid-lslong': '12354593507045645965'}, 'enable': 'true', 'created': '2025-09-11T03:29:11', 'last-modified': '2025-09-11T03:29:12', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.482228'}
2025-09-11 03:29:12,635 - DEBUG - Route Targets: ['target:64512:8000007']
2025-09-11 03:29:12,635 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-39841645 passed
2025-09-11 03:29:12,635 - DEBUG - ====Verifying policy data for ctest-vn1-39841645 in API_Server ======
2025-09-11 03:29:12,635 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:29:12,643 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:29:12,656 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:29:12,753 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/0ee93488-e06d-4ca2-ab74-555653cd9e8d
2025-09-11 03:29:12,769 - DEBUG - =>VN ctest-vn1-39841645 has no policy to be verified
2025-09-11 03:29:12,769 - DEBUG - Verifying the vn in opserver
2025-09-11 03:29:12,769 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 virtual network link through opserver 10.0.0.249
2025-09-11 03:29:12,769 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-09-11 03:29:12,838 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645?flat'}
2025-09-11 03:29:12,838 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 virtual network link through opserver 10.0.0.22
2025-09-11 03:29:12,838 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-09-11 03:29:12,897 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645?flat'}
2025-09-11 03:29:12,897 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 virtual network link through opserver 10.0.0.49
2025-09-11 03:29:12,897 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-09-11 03:29:12,956 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645?flat'}
2025-09-11 03:29:12,956 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is found in opserver
2025-09-11 03:29:12,977 - DEBUG - Do not have enough data to verify VN in agent
2025-09-11 03:29:12,988 - DEBUG - VRF ids for VN ctest-vn1-39841645: {}
2025-09-11 03:29:13,643 - INFO - Created VN ctest-vn2-70341741, UUID :c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:13,962 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:29:13,969 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:29:13,983 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:29:14,069 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,084 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,095 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:29:14,105 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:29:14,113 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/39021dd6-2c14-470c-b53d-6533ba6a93c6
2025-09-11 03:29:14,122 - DEBUG - Route Targets: ['target:64512:8000008']
2025-09-11 03:29:14,122 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,131 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:29:14,147 - INFO - Verified VN network id 18 for VN c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,147 - INFO - Verifications in API Server for VN ctest-vn2-70341741 passed
2025-09-11 03:29:14,147 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,157 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:29:14,165 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:29:14,172 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/39021dd6-2c14-470c-b53d-6533ba6a93c6
2025-09-11 03:29:14,184 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14071619022006079106', 'uuid-lslong': '12072883782162046893'}, 'enable': 'true', 'created': '2025-09-11T03:29:13', 'last-modified': '2025-09-11T03:29:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.395299'}
2025-09-11 03:29:14,190 - DEBUG - Route Targets: ['target:64512:8000008']
2025-09-11 03:29:14,196 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14071619022006079106', 'uuid-lslong': '12072883782162046893'}, 'enable': 'true', 'created': '2025-09-11T03:29:13', 'last-modified': '2025-09-11T03:29:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.406272'}
2025-09-11 03:29:14,202 - DEBUG - Route Targets: ['target:64512:8000008']
2025-09-11 03:29:14,208 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN0-49175314', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '14071619022006079106', 'uuid-lslong': '12072883782162046893'}, 'enable': 'true', 'created': '2025-09-11T03:29:13', 'last-modified': '2025-09-11T03:29:13', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.421372'}
2025-09-11 03:29:14,216 - DEBUG - Route Targets: ['target:64512:8000008']
2025-09-11 03:29:14,217 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn2-70341741 passed
2025-09-11 03:29:14,217 - DEBUG - ====Verifying policy data for ctest-vn2-70341741 in API_Server ======
2025-09-11 03:29:14,217 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:29:14,225 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:29:14,239 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:29:14,330 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/c3486ef2-254d-4e82-a78b-7fd5c257dfad
2025-09-11 03:29:14,344 - DEBUG - =>VN ctest-vn2-70341741 has no policy to be verified
2025-09-11 03:29:14,345 - DEBUG - Verifying the vn in opserver
2025-09-11 03:29:14,345 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741 virtual network link through opserver 10.0.0.249
2025-09-11 03:29:14,345 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks
2025-09-11 03:29:14,359 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741?flat'}
2025-09-11 03:29:14,359 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741 virtual network link through opserver 10.0.0.22
2025-09-11 03:29:14,359 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks
2025-09-11 03:29:14,372 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741?flat'}
2025-09-11 03:29:14,372 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741 virtual network link through opserver 10.0.0.49
2025-09-11 03:29:14,373 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks
2025-09-11 03:29:14,434 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741?flat'}
2025-09-11 03:29:14,434 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn2-70341741 is found in opserver
2025-09-11 03:29:14,458 - DEBUG - Do not have enough data to verify VN in agent
2025-09-11 03:29:14,470 - DEBUG - VRF ids for VN ctest-vn2-70341741: {}
2025-09-11 03:29:16,541 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4079-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4079-1)
2025-09-11 03:29:18,410 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-4079-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-4079-2)
2025-09-11 03:29:18,411 - INFO - Waiting for VM ctest-vn1_vm1-20207782 to be up..
2025-09-11 03:29:18,514 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-09-11 03:29:23,601 - DEBUG - VM is in ACTIVE state now
2025-09-11 03:29:23,601 - INFO - VM name : ctest-vn1_vm1-20207782
2025-09-11 03:29:23,704 - DEBUG - VM ctest-vn1_vm1-20207782 ID is 08575f9b-cc9c-47bf-a0a6-a80e9c256826
2025-09-11 03:29:23,704 - DEBUG - VM ctest-vn1_vm1-20207782 launched on Node an-jenkins-deploy-platform-ansible-os-4079-1
2025-09-11 03:29:23,809 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/08575f9b-cc9c-47bf-a0a6-a80e9c256826
2025-09-11 03:29:23,820 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/c1bdb185-9c06-46bd-8f8d-3ae4aeb58d7f
2025-09-11 03:29:26,984 - 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 1005ms')
2025-09-11 03:29:26,984 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:26,998 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:31,086 - 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 1031ms')
2025-09-11 03:29:31,086 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:31,100 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:35,187 - 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')
2025-09-11 03:29:35,187 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:35,204 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:39,272 - 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')
2025-09-11 03:29:39,272 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:39,288 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:43,381 - 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 1024ms')
2025-09-11 03:29:43,381 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:43,396 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:47,465 - 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')
2025-09-11 03:29:47,465 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:47,482 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:51,565 - 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')
2025-09-11 03:29:51,565 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:51,579 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:55,656 - 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 1024ms')
2025-09-11 03:29:55,657 - DEBUG - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 failed!
2025-09-11 03:29:55,670 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN0-49175314:ctest-vn1-39841645 is 192.168.1.254 and allocation pool is NOT set
2025-09-11 03:29:57,734 - 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=9.28 ms\r\n64 bytes from 169.254.0.7: icmp_seq=2 ttl=63 time=1.23 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.226/5.252/9.279/4.026 ms')
2025-09-11 03:29:57,734 - INFO - Ping to Metadata IP 169.254.0.7 of VM ctest-vn1_vm1-20207782 passed
2025-09-11 03:29:57,804 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:29:57,804 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20207782, IP 192.168.1.252, Port 22
2025-09-11 03:29:57,872 - 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': ''}
2025-09-11 03:29:57,952 - DEBUG - VM ctest-vn1_vm1-20207782 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:30:02,953 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:30:02,953 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20207782, IP 192.168.1.252, Port 22
2025-09-11 03:30:03,022 - 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': ''}
2025-09-11 03:30:03,128 - DEBUG - VM ctest-vn1_vm1-20207782 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:30:08,129 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:30:08,129 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20207782, IP 192.168.1.252, Port 22
2025-09-11 03:30:08,198 - 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': ''}
2025-09-11 03:30:08,282 - DEBUG - VM ctest-vn1_vm1-20207782 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:30:13,282 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:30:13,282 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20207782, IP 192.168.1.252, Port 22
2025-09-11 03:30:13,349 - 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': ''}
2025-09-11 03:30:13,436 - DEBUG - VM ctest-vn1_vm1-20207782 is NOT ready for SSH connections, VM status: ACTIVE
2025-09-11 03:30:18,436 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-09-11 03:30:18,436 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-20207782, IP 192.168.1.252, Port 22
2025-09-11 03:30:18,610 - DEBUG - VM ctest-vn1_vm1-20207782 is ready for SSH connections
2025-09-11 03:30:18,610 - INFO - Waiting for VM ctest-vn2_vm1-41553835 to be up..
2025-09-11 03:30:18,685 - DEBUG - VM is in ERROR state now
2025-09-11 03:30:18,685 - ERROR - VM in error state.
2025-09-11 03:30:18,685 - ERROR - VM is not in ACTIVE state
2025-09-11 03:30:18,788 - ERROR - Fatal Nova Exception while getting VM detail
2025-09-11 03:30:18,788 - DEBUG - None
2025-09-11 03:30:18,790 - INFO - Skip interface_detach for VM ctest-vn2_vm1-41553835 in state ERROR
2025-09-11 03:30:18,790 - INFO - Deleting VM ctest-vn2_vm1-41553835
2025-09-11 03:30:18,790 - ERROR - VM ctest-vn2_vm1-41553835 has failed to come up
2025-09-11 03:30:18,790 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-09-11T03:29:18Z', 'message': 'No valid host was found. ', 'details': 'Traceback (most recent call last):\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 1581, in schedule_and_build_instances\n instance_uuids, return_alternates=True)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/conductor/manager.py", line 942, in _schedule_instances\n return_alternates=return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/client/query.py", line 42, in select_destinations\n instance_uuids, return_objects, return_alternates)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/rpcapi.py", line 160, in select_destinations\n return cctxt.call(ctxt, \'select_destinations\', **msg_args)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/client.py", line 192, in call\n retry=self.retry, transport_options=self.transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/transport.py", line 128, in _send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 691, in send\n transport_options=transport_options)\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 681, in _send\n raise result\nnova.exception_Remote.NoValidHost_Remote: No valid host was found. \nTraceback (most recent call last):\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/oslo_messaging/rpc/server.py", line 241, in inner\n return func(*args, **kwargs)\n\n File "/var/lib/kolla/venv/lib/python3.6/site-packages/nova/scheduler/manager.py", line 209, in select_destinations\n raise exception.NoValidHost(reason="")\n\nnova.exception.NoValidHost: No valid host was found. \n\n'}
2025-09-11 03:30:18,790 - INFO - Deleting VM ctest-vn1_vm1-20207782
2025-09-11 03:30:19,050 - INFO - Deleting VN ctest-vn2-70341741
2025-09-11 03:30:19,163 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/7808d105-5d5d-49f5-b8e4-2308dbb90ce5
2025-09-11 03:30:19,168 - DEBUG - Response Code: 404
2025-09-11 03:30:19,168 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:30:19,174 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:30:19,187 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:30:19,282 - INFO - Validated that VN ctest-vn2-70341741 is not found in API Server
2025-09-11 03:30:19,303 - DEBUG - VN ctest-vn2-70341741 is not present in Agent 10.0.0.254
2025-09-11 03:30:19,314 - DEBUG - VN ctest-vn2-70341741 is not present in Agent 10.0.0.19
2025-09-11 03:30:19,314 - INFO - Validated that VN ctest-vn2-70341741 is not in any agent
2025-09-11 03:30:19,364 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn2-70341741 info
2025-09-11 03:30:19,540 - INFO - Deleting VN ctest-vn1-39841645
2025-09-11 03:30:19,607 - DEBUG - RefsExistError Delete when resource still referred: ['http://10.0.0.49:8082/virtual-machine-interface/c1bdb185-9c06-46bd-8f8d-3ae4aeb58d7f'] while deleting VN ctest-vn1-39841645..Will retry
2025-09-11 03:30:21,733 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/db4baeb6-d057-44a7-aac2-ee2badbed121
2025-09-11 03:30:21,750 - DEBUG - Response Code: 404
2025-09-11 03:30:21,751 - DEBUG - Requesting: http://10.0.0.249:8082/domains
2025-09-11 03:30:21,763 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07
2025-09-11 03:30:21,783 - DEBUG - Requesting: http://10.0.0.249:8082/project/44c75927-370a-40c7-8f40-bb5ccf53216c
2025-09-11 03:30:21,873 - INFO - Validated that VN ctest-vn1-39841645 is not found in API Server
2025-09-11 03:30:21,886 - DEBUG - VN ctest-vn1-39841645 is not present in Agent 10.0.0.254
2025-09-11 03:30:21,896 - DEBUG - VN ctest-vn1-39841645 is not present in Agent 10.0.0.19
2025-09-11 03:30:21,897 - INFO - Validated that VN ctest-vn1-39841645 is not in any agent
2025-09-11 03:30:21,934 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-39841645 info
2025-09-11 03:30:21,973 - INFO - Deleted policy policy2
2025-09-11 03:30:22,012 - INFO - Deleted policy policy1
2025-09-11 03:30:23,281 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Thu Sep 11 03:30:18 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_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
2025-09-11 03:30:23,282 - DEBUG - Skipping xmpp flap check
2025-09-11 03:30:23,282 - INFO -
2025-09-11 03:30:23,282 - INFO - END TEST : test_process_restart_in_policy_between_vns : FAILED[0:01:14]
2025-09-11 03:30:23,282 - INFO - --------------------------------------------------------------------------------
2025-09-11 03:30:23,285 - INFO - ================================================================================
2025-09-11 03:30:23,285 - INFO - STARTING TEST : test_underlay_broadcast_traffic_handling
2025-09-11 03:30:23,285 - 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-09-11 03:30:24,559 - DEBUG - Skipping xmpp flap check
2025-09-11 03:30:24,559 - INFO - Initial checks done. Running the testcase now
2025-09-11 03:30:24,559 - INFO -
2025-09-11 03:30:24,964 - INFO - Agent interface name: ens6
2025-09-11 03:30:25,048 - DEBUG - Executing command: sudo tcpdump -nni ens6 -U host 0.0.0.0 -w /tmp/ens6_ctest-random-14286543.pcap
2025-09-11 03:30:30,469 - INFO - Pinging broacast address 0.0.0.0 from compute 10.20.0.18
2025-09-11 03:30:44,777 - DEBUG - Executing command: sudo kill $(ps -ef|grep tcpdump | grep pcap| awk '{print $2}')
2025-09-11 03:30:46,917 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:46,932 - DEBUG - STDOUT: 2
2025-09-11 03:30:46,933 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:46,933 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:48,933 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:48,948 - DEBUG - STDOUT: 2
2025-09-11 03:30:48,948 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:48,948 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:50,948 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:50,964 - DEBUG - STDOUT: 2
2025-09-11 03:30:50,964 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:50,964 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:52,965 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:52,980 - DEBUG - STDOUT: 2
2025-09-11 03:30:52,980 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:52,980 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:54,981 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:54,996 - DEBUG - STDOUT: 2
2025-09-11 03:30:54,996 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:54,996 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:56,997 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:57,015 - DEBUG - STDOUT: 2
2025-09-11 03:30:57,015 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:57,015 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:30:59,016 - DEBUG - Executing command: sudo tcpdump -nnr /tmp/ens6_ctest-random-14286543.pcap | grep -c length
2025-09-11 03:30:59,031 - DEBUG - STDOUT: 2
2025-09-11 03:30:59,031 - DEBUG - STDERR: reading from file /tmp/ens6_ctest-random-14286543.pcap, link-type EN10MB (Ethernet), snapshot length 262144
2025-09-11 03:30:59,031 - WARNING - 2 packets are found in tcpdump output file /tmp/ens6_ctest-random-14286543.pcap but expected 10
2025-09-11 03:31:00,308 - ERROR - AssertionError
Python 3.9.21: /usr/bin/python3
Thu Sep 11 03:30:59 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-14286543.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-09-11 03:31:00,309 - DEBUG - Skipping xmpp flap check
2025-09-11 03:31:00,309 - INFO -
2025-09-11 03:31:00,309 - INFO - END TEST : test_underlay_broadcast_traffic_handling : FAILED[0:00:37]
2025-09-11 03:31:00,309 - INFO - --------------------------------------------------------------------------------
2025-09-11 03:31:01,026 - INFO - Deleted project: ctest-TestBasicVMVN0-49175314, ID : 44c75927-370a-40c7-8f40-bb5ccf53216c