2026-10-05 04:19:16,071 - INFO - Domain Default found not creating 2026-10-05 04:19:16,256 - INFO - Project ctest-TestBasicVMVNx-94562591 not found, creating it 2026-10-05 04:19:16,863 - INFO - Created Project:ctest-TestBasicVMVNx-94562591, ID : 1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:19:18,731 - INFO - ================================================================================ 2026-10-05 04:19:18,731 - INFO - STARTING TEST : test_sctp_traffic_between_vm 2026-10-05 04:19:18,731 - INFO - TEST DESCRIPTION : Description: Test to validate SCTP flow setup between Test steps: 1. Run SCTP traffic between 2 VM across VN connected through FIP 2. Verify the Ingress and Egress flow. Pass criteria: SCTP egress and ingress flow setup properly. Maintainer : chhandak@juniper.net 2026-10-05 04:19:20,067 - DEBUG - Nothing to compare xmpp stats {'10.0.0.50': {'10.20.0.14': '0', '10.20.0.25': '0'}, '10.0.0.191': {'10.20.0.254': '0', '10.20.0.25': '0'}} with 2026-10-05 04:19:20,067 - INFO - Initial checks done. Running the testcase now 2026-10-05 04:19:20,067 - INFO - 2026-10-05 04:19:20,102 - DEBUG - Services list from nova: [, , , ] 2026-10-05 04:19:20,103 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-6343-1', 'an-jenkins-deploy-platform-ansible-os-6343-2']} 2026-10-05 04:19:20,941 - DEBUG - Response for create_network : {'network': {'id': '0e993743-83d0-4266-bdc5-e25cd696912a', 'name': 'ctest-fvn-77209518', 'tenant_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'project_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVNx-94562591', 'ctest-fvn-77209518'], 'port_security_enabled': True, 'description': ''}} 2026-10-05 04:19:21,308 - DEBUG - Response for create_subnet : {'subnet': {'id': '985285fc-0e3c-48ed-8ffc-d4e3a6c788d1', 'name': '', 'tenant_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'network_id': '0e993743-83d0-4266-bdc5-e25cd696912a', 'ip_version': 4, 'cidr': '93.138.36.128/26', 'allocation_pools': [{'start': '93.138.36.130', 'end': '93.138.36.190'}], 'gateway_ip': '93.138.36.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '93.138.36.130', 'tags': [], 'project_id': '1c47cd9d4d8c4da78310bb67c81c670d'}} 2026-10-05 04:19:21,333 - INFO - Created VN ctest-fvn-77209518 2026-10-05 04:19:21,352 - DEBUG - VN ctest-fvn-77209518 UUID is 0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:21,438 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:19:21,845 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:19:21,884 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:19:21,906 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:19:22,034 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,056 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,072 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:19:22,082 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:19:22,096 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/225bc2b4-dc9a-4dde-b38a-19ae2bfe4e88 2026-10-05 04:19:22,105 - DEBUG - Route Targets: ['target:64512:8000010'] 2026-10-05 04:19:22,105 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,117 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:19:22,138 - INFO - Verified VN network id 19 for VN 0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,138 - INFO - Verifications in API Server for VN ctest-fvn-77209518 passed 2026-10-05 04:19:22,138 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,153 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:19:22,166 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:19:22,180 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/225bc2b4-dc9a-4dde-b38a-19ae2bfe4e88 2026-10-05 04:19:22,200 - DEBUG - Control-node 10.0.0.177 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1051932751081521766', 'uuid-lslong': '13674584731945439530'}, 'enable': 'true', 'created': '2026-10-05T04:19:20', 'last-modified': '2026-10-05T04:19:21', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.995259'} 2026-10-05 04:19:22,209 - DEBUG - Route Targets: ['target:64512:8000010'] 2026-10-05 04:19:22,216 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1051932751081521766', 'uuid-lslong': '13674584731945439530'}, 'enable': 'true', 'created': '2026-10-05T04:19:20', 'last-modified': '2026-10-05T04:19:21', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.012462'} 2026-10-05 04:19:22,227 - DEBUG - Route Targets: ['target:64512:8000010'] 2026-10-05 04:19:22,234 - DEBUG - Control-node 10.0.0.190 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '1051932751081521766', 'uuid-lslong': '13674584731945439530'}, 'enable': 'true', 'created': '2026-10-05T04:19:20', 'last-modified': '2026-10-05T04:19:21', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:01.032196'} 2026-10-05 04:19:22,243 - DEBUG - Route Targets: ['target:64512:8000010'] 2026-10-05 04:19:22,243 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-fvn-77209518 passed 2026-10-05 04:19:22,244 - DEBUG - ====Verifying policy data for ctest-fvn-77209518 in API_Server ====== 2026-10-05 04:19:22,244 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:19:22,253 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:19:22,269 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:19:22,375 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:19:22,390 - DEBUG - =>VN ctest-fvn-77209518 has no policy to be verified 2026-10-05 04:19:22,390 - DEBUG - Verifying the vn in opserver 2026-10-05 04:19:22,390 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518 virtual network link through opserver 10.0.0.177 2026-10-05 04:19:22,390 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks 2026-10-05 04:19:22,828 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks 2026-10-05 04:19:22,909 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'href': 'http://10.0.0.177:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518?flat'} 2026-10-05 04:19:22,909 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518 virtual network link through opserver 10.0.0.38 2026-10-05 04:19:22,909 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks 2026-10-05 04:19:23,305 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks 2026-10-05 04:19:23,392 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518?flat'} 2026-10-05 04:19:23,392 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518 virtual network link through opserver 10.0.0.190 2026-10-05 04:19:23,392 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks 2026-10-05 04:19:23,785 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks 2026-10-05 04:19:23,856 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518', 'href': 'http://10.0.0.190:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518?flat'} 2026-10-05 04:19:23,856 - INFO - Validated that VN default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518 is found in opserver 2026-10-05 04:19:23,882 - DEBUG - Do not have enough data to verify VN in agent 2026-10-05 04:19:23,894 - DEBUG - VRF ids for VN ctest-fvn-77209518: {} 2026-10-05 04:19:24,239 - DEBUG - Response for create_network : {'network': {'id': '4f1a873c-bbce-41a4-accf-3520a0402309', 'name': 'ctest-vn1-81344656', 'tenant_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'project_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVNx-94562591', 'ctest-vn1-81344656'], 'port_security_enabled': True, 'description': ''}} 2026-10-05 04:19:24,530 - DEBUG - Response for create_subnet : {'subnet': {'id': 'aa7b7368-44b6-474e-ab95-f0c7e2d87cdf', 'name': '', 'tenant_id': '1c47cd9d4d8c4da78310bb67c81c670d', 'network_id': '4f1a873c-bbce-41a4-accf-3520a0402309', 'ip_version': 4, 'cidr': '80.200.88.192/26', 'allocation_pools': [{'start': '80.200.88.194', 'end': '80.200.88.254'}], 'gateway_ip': '80.200.88.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '80.200.88.194', 'tags': [], 'project_id': '1c47cd9d4d8c4da78310bb67c81c670d'}} 2026-10-05 04:19:24,565 - INFO - Created VN ctest-vn1-81344656 2026-10-05 04:19:24,580 - DEBUG - VN ctest-vn1-81344656 UUID is 4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,674 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:19:24,681 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:19:24,699 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:19:24,797 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,818 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,829 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:19:24,840 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:19:24,850 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/0c911bf0-5c45-4d38-acf0-f5d79a2d108c 2026-10-05 04:19:24,858 - DEBUG - Route Targets: ['target:64512:8000011'] 2026-10-05 04:19:24,858 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,868 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:19:24,889 - INFO - Verified VN network id 20 for VN 4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,889 - INFO - Verifications in API Server for VN ctest-vn1-81344656 passed 2026-10-05 04:19:24,889 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:24,908 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:19:24,921 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:19:24,931 - DEBUG - Requesting: http://10.0.0.177:8082/route-target/0c911bf0-5c45-4d38-acf0-f5d79a2d108c 2026-10-05 04:19:24,958 - DEBUG - Control-node 10.0.0.177 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5700016973309428132', 'uuid-lslong': '12452229908946494217'}, 'enable': 'true', 'created': '2026-10-05T04:19:24', 'last-modified': '2026-10-05T04:19:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.494865'} 2026-10-05 04:19:24,974 - DEBUG - Route Targets: ['target:64512:8000011'] 2026-10-05 04:19:24,983 - DEBUG - Control-node 10.0.0.38 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5700016973309428132', 'uuid-lslong': '12452229908946494217'}, 'enable': 'true', 'created': '2026-10-05T04:19:24', 'last-modified': '2026-10-05T04:19:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.525308'} 2026-10-05 04:19:24,992 - DEBUG - Route Targets: ['target:64512:8000011'] 2026-10-05 04:19:25,002 - DEBUG - Control-node 10.0.0.190 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-94562591', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5700016973309428132', 'uuid-lslong': '12452229908946494217'}, 'enable': 'true', 'created': '2026-10-05T04:19:24', 'last-modified': '2026-10-05T04:19:24', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.544058'} 2026-10-05 04:19:25,015 - DEBUG - Route Targets: ['target:64512:8000011'] 2026-10-05 04:19:25,015 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-81344656 passed 2026-10-05 04:19:25,016 - DEBUG - ====Verifying policy data for ctest-vn1-81344656 in API_Server ====== 2026-10-05 04:19:25,016 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:19:25,023 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:19:25,037 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:19:25,144 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/4f1a873c-bbce-41a4-accf-3520a0402309 2026-10-05 04:19:25,167 - DEBUG - =>VN ctest-vn1-81344656 has no policy to be verified 2026-10-05 04:19:25,167 - DEBUG - Verifying the vn in opserver 2026-10-05 04:19:25,167 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 virtual network link through opserver 10.0.0.177 2026-10-05 04:19:25,167 - DEBUG - Requesting: http://10.0.0.177:8081/analytics/uves/virtual-networks 2026-10-05 04:19:25,328 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'href': 'http://10.0.0.177:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656?flat'} 2026-10-05 04:19:25,328 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 virtual network link through opserver 10.0.0.38 2026-10-05 04:19:25,329 - DEBUG - Requesting: http://10.0.0.38:8081/analytics/uves/virtual-networks 2026-10-05 04:19:25,430 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'href': 'http://10.0.0.38:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656?flat'} 2026-10-05 04:19:25,430 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 virtual network link through opserver 10.0.0.190 2026-10-05 04:19:25,430 - DEBUG - Requesting: http://10.0.0.190:8081/analytics/uves/virtual-networks 2026-10-05 04:19:25,542 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656', 'href': 'http://10.0.0.190:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656?flat'} 2026-10-05 04:19:25,542 - INFO - Validated that VN default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is found in opserver 2026-10-05 04:19:25,569 - DEBUG - Do not have enough data to verify VN in agent 2026-10-05 04:19:25,582 - DEBUG - VRF ids for VN ctest-vn1-81344656: {} 2026-10-05 04:19:25,805 - DEBUG - Image by name ubuntu-sctp not found 2026-10-05 04:19:25,805 - DEBUG - Installing image ubuntu-sctp 2026-10-05 04:19:25,806 - DEBUG - Image info {'name': 'ubuntu-sctp.vmdk.gz', 'webserver': '', 'location': '/images/converts/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_small', 'params': '--container-format bare --disk-format vmdk --property vmware_disktype="sparse" --property vmware_adaptertype="ide" --property hw_scsi_model=virtio-scsi --property hw_disk_bus_model=virtio-scsi --property hw_disk_bus=virtio', 'name_docker': 'phusion-baseimage-enablesshd'} 2026-10-05 04:19:25,806 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-sctp.vmdk.gz 2026-10-05 04:19:25,806 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-sctp.vmdk.gz 2026-10-05 04:19:25,835 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: wget -nv http://nexus.opensdn.io/repository///images/converts//ubuntu-sctp.vmdk.gz -O /contrail-test/images/ubuntu-sctp.vmdk.gz 2026-10-05 04:19:27,816 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-sctp.vmdk.gz 2026-10-05 04:19:27,816 - DEBUG - Unzip image 2026-10-05 04:19:27,816 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-sctp.vmdk.gz 2026-10-05 04:19:36,460 - DEBUG - Try to create image in user context 2026-10-05 04:19:42,569 - DEBUG - Image has been created in user context 2026-10-05 04:19:42,569 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-sctp.vmdk 2026-10-05 04:19:42,706 - DEBUG - Downloaded image has been removed 2026-10-05 04:19:42,723 - DEBUG - Uploaded image status = active 2026-10-05 04:19:43,423 - 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 04:19:44,091 - 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 04:19:44,148 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:19:49,257 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:19:54,351 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:19:59,452 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:04,562 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:09,687 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:14,788 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:19,890 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:25,005 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:30,103 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:20:35,203 - DEBUG - VM is in ACTIVE state now 2026-10-05 04:20:35,204 - INFO - VM name : ctest-vn1_vm1_name-88234536 2026-10-05 04:20:35,297 - DEBUG - VM ctest-vn1_vm1_name-88234536 ID is 1985be13-a5f4-4c01-af80-4fa539a10fee 2026-10-05 04:20:35,298 - DEBUG - VM ctest-vn1_vm1_name-88234536 launched on Node an-jenkins-deploy-platform-ansible-os-6343-1 2026-10-05 04:20:35,394 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/1985be13-a5f4-4c01-af80-4fa539a10fee 2026-10-05 04:20:35,785 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine/1985be13-a5f4-4c01-af80-4fa539a10fee 2026-10-05 04:20:35,826 - DEBUG - Requesting: http://10.0.0.190:8082/virtual-machine-interface/151be128-94a2-4941-a715-c9cd8f7a22fe 2026-10-05 04:20:39,040 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1029ms') 2026-10-05 04:20:39,041 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:39,060 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:20:43,135 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms') 2026-10-05 04:20:43,136 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:43,153 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:20:47,235 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1013ms') 2026-10-05 04:20:47,235 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:47,254 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:20:51,331 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms') 2026-10-05 04:20:51,332 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:51,351 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:20:55,429 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms') 2026-10-05 04:20:55,429 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:55,448 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:20:59,519 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms') 2026-10-05 04:20:59,519 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:20:59,535 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:03,620 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2026-10-05 04:21:03,621 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:21:03,640 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:07,717 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1009ms') 2026-10-05 04:21:07,717 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:21:07,734 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:11,813 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms') 2026-10-05 04:21:11,813 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:21:11,831 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:15,909 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1008ms') 2026-10-05 04:21:15,909 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:21:15,927 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:20,001 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1007ms') 2026-10-05 04:21:20,001 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 failed! 2026-10-05 04:21:20,019 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-94562591:ctest-vn1-81344656 is 80.200.88.193 and allocation pool is NOT set 2026-10-05 04:21:22,086 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=7.46 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.870 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.870/4.164/7.459/3.294 ms') 2026-10-05 04:21:22,086 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-88234536 passed 2026-10-05 04:21:22,165 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:22,165 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:22,232 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:22,362 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:27,364 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:27,364 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:27,442 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:27,557 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:32,558 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:32,558 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:32,624 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:32,718 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:37,719 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:37,719 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:37,799 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:37,899 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:42,900 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:42,900 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:42,968 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:43,066 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:48,067 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:48,068 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:48,136 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:48,231 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:53,232 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:53,232 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:53,301 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:53,409 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:21:58,410 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:21:58,410 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:21:58,476 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2026-10-05 04:21:58,573 - DEBUG - VM ctest-vn1_vm1_name-88234536 is NOT ready for SSH connections, VM status: ACTIVE 2026-10-05 04:22:03,574 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2026-10-05 04:22:03,574 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-88234536, IP 80.200.88.195, Port 22 2026-10-05 04:22:03,748 - DEBUG - VM ctest-vn1_vm1_name-88234536 is ready for SSH connections 2026-10-05 04:22:03,806 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:08,872 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:13,931 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:18,992 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:24,052 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:29,119 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:34,176 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:39,232 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:44,294 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:49,350 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:54,411 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:22:59,474 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:04,534 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:09,604 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:14,663 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:19,719 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:24,789 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:29,851 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:34,912 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:39,989 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:45,048 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:50,106 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:23:55,167 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:00,232 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:05,290 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:10,362 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:15,420 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:20,531 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:25,618 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:30,702 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:35,758 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2026-10-05 04:24:35,759 - ERROR - VM is not in ACTIVE state 2026-10-05 04:24:35,970 - INFO - Creating Floating IP pool ctest-some-pool-13370227 in API Server 2026-10-05 04:24:36,164 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:24:36,191 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:24:36,243 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:24:36,377 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:24:36,391 - DEBUG - Requesting: http://10.0.0.177:8082/floating-ip-pool/21d6a5c1-62c7-41f5-8b86-08cea7830b1f 2026-10-05 04:24:36,402 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:24:36,412 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:24:36,427 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:24:36,532 - DEBUG - Requesting: http://10.0.0.177:8082/virtual-network/0e993743-83d0-4266-bdc5-e25cd696912a 2026-10-05 04:24:36,545 - DEBUG - FIP Pool ctest-some-pool-13370227 found in API Server 2026-10-05 04:24:36,545 - INFO - Verification for FIP pool ctest-some-pool-13370227 in API Server passed 2026-10-05 04:24:36,571 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-13370227 information 2026-10-05 04:24:36,579 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-13370227 information 2026-10-05 04:24:36,587 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-13370227 information 2026-10-05 04:24:36,587 - INFO - Verification for FIP pool ctest-some-pool-13370227 in Control-node passed 2026-10-05 04:24:36,803 - DEBUG - Created Floating IP : ('93.138.36.131', '186dfc35-3513-4422-80c4-4ae3c42304bf') 2026-10-05 04:24:36,803 - DEBUG - Associating FIP 93.138.36.131 to 1985be13-a5f4-4c01-af80-4fa539a10fee 2026-10-05 04:24:36,849 - DEBUG - Associating FIP ID 186dfc35-3513-4422-80c4-4ae3c42304bf with Port ID 151be128-94a2-4941-a715-c9cd8f7a22fe 2026-10-05 04:24:37,161 - INFO - Route for FIP 93.138.36.131 is fine on Control-node 10.0.0.38 2026-10-05 04:24:37,174 - INFO - Route for FIP 93.138.36.131 is fine on Control-node 10.0.0.190 2026-10-05 04:24:37,175 - INFO - FIP 93.138.36.131 verification for passed on all Control-nodes 2026-10-05 04:24:37,175 - INFO - FIP ID 186dfc35-3513-4422-80c4-4ae3c42304bf(93.138.36.131) validation in Control node passed 2026-10-05 04:24:37,199 - DEBUG - agent_label query returned:{'nh': {'type': 'interface', 'ref_count': '18', 'valid': 'true', 'policy': 'enabled', 'itf': 'tap151be128-94', 'mac': ['2:15:1b:e1:28:94'], 'mcast': 'disabled', 'nh_index': '31', 'vxlan_flag': 'false', 'intf_flags': '1', 'isid': '0', 'learning_enabled': 'false', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'crypt_all_traffic': 'false', 'crypt_path_available': 'false', 'crypt_interface': None}, 'label': '25', 'vxlan_id': '0', 'peer': '10.20.0.14', 'dest_vn_list': ['default-domain:ctest-TestBasicVMVNx-94562591:ctest-fvn-77209518'], 'unresolved': 'false', 'sg_list': ['8000007'], 'supported_tunnel_type': 'MPLSoGRE MPLSoUDP ', 'active_tunnel_type': 'MPLSoUDP', 'stale': 'false', 'path_preference_data': {'sequence': '0', 'preference': '200', 'ecmp': 'true'}, 'active_label': '25', 'ecmp_hashing_fields': 'l3-source-address,l3-destination-address,l4-protocol,l4-source-port,l4-destination-port,', 'communities': None, 'peer_sequence_number': '1', 'etree_leaf': 'false', 'layer2_control_word': 'false', 'tag_list': None, 'inactive': 'false', 'origin_vn': None} 2026-10-05 04:24:37,199 - DEBUG - Route for FIP IP 93.138.36.131 is present in agent 10.0.0.50 2026-10-05 04:24:37,199 - DEBUG - FIP 93.138.36.131 verification for VM ctest-vn1_vm1_name-88234536 in Agent 10.0.0.50 passed 2026-10-05 04:24:37,206 - INFO - FIP ID 186dfc35-3513-4422-80c4-4ae3c42304bf(93.138.36.131) validation in agents passed 2026-10-05 04:24:37,206 - DEBUG - Requesting: http://10.0.0.177:8082/floating-ip/186dfc35-3513-4422-80c4-4ae3c42304bf 2026-10-05 04:24:37,218 - DEBUG - FIP 186dfc35-3513-4422-80c4-4ae3c42304bf is present in API server 2026-10-05 04:24:37,218 - INFO - FIP ID 186dfc35-3513-4422-80c4-4ae3c42304bf(93.138.36.131) validation in API Server passed 2026-10-05 04:24:37,218 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:24:37,279 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:24:42,347 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:24:47,407 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:24:52,473 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:24:57,535 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:02,595 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:02,595 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:25:04,596 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:25:04,654 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:09,728 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:14,791 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:19,862 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:24,939 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:30,015 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:30,016 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:25:32,017 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:25:32,083 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:37,139 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:42,204 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:47,265 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:52,323 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:57,380 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:25:57,380 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:25:59,381 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:25:59,441 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:04,507 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:09,569 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:14,629 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:19,689 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:24,825 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:24,825 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:26:26,826 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:26:26,906 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:31,966 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:37,034 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:42,092 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:47,152 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:52,210 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:52,210 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:26:54,211 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:26:54,274 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:26:59,334 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:04,389 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:09,467 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:14,530 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:19,587 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:19,587 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:27:19,592 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:27:19,648 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:24,706 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:29,765 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:34,822 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:39,882 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:44,942 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:44,942 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:27:46,943 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:27:46,999 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:52,064 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:27:57,140 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:02,208 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:07,264 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:12,325 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:12,325 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:28:14,326 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:28:14,382 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:19,444 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:24,539 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:29,600 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:34,661 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:39,716 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:39,716 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:28:41,717 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:28:41,773 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:46,833 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:51,898 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:28:56,957 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:02,021 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:07,079 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:07,079 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:29:09,079 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:29:09,137 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:14,204 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:19,269 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:24,468 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:29,614 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:34,697 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:34,697 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:29:36,698 - INFO - VM name : ctest-fvn_vm1_name-05810886 2026-10-05 04:29:36,787 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:41,851 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:46,910 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:51,969 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:29:57,031 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:30:02,088 - DEBUG - VM ctest-fvn_vm1_name-05810886 : Status=BUILD, Addresses : {} 2026-10-05 04:30:02,088 - ERROR - VM c82f27e8-6d7f-44fe-8c05-7f7ca15aae52 is not launched yet 2026-10-05 04:30:02,089 - DEBUG - Disassociating port from FIP ID : 186dfc35-3513-4422-80c4-4ae3c42304bf 2026-10-05 04:30:02,172 - DEBUG - Deleting FIP ID 186dfc35-3513-4422-80c4-4ae3c42304bf 2026-10-05 04:30:02,288 - INFO - Deleting the FIP pool ctest-some-pool-13370227 2026-10-05 04:30:02,470 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-13370227 information 2026-10-05 04:30:02,477 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-13370227 information 2026-10-05 04:30:02,483 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-13370227 information 2026-10-05 04:30:02,484 - INFO - Skip interface_detach for VM ctest-fvn_vm1_name-05810886 in state BUILD 2026-10-05 04:30:02,484 - INFO - Deleting VM ctest-fvn_vm1_name-05810886 2026-10-05 04:30:02,484 - ERROR - VM ctest-fvn_vm1_name-05810886 has failed to come up 2026-10-05 04:30:02,484 - ERROR - Nova failed to get host of the VM 2026-10-05 04:30:02,484 - ERROR - VM ctest-fvn_vm1_name-05810886 has failed to come up 2026-10-05 04:30:02,484 - ERROR - Nova failed to get host of the VM 2026-10-05 04:30:02,711 - INFO - Deleting VM ctest-vn1_vm1_name-88234536 2026-10-05 04:30:02,818 - INFO - Deleting VN ctest-vn1-81344656 2026-10-05 04:30:02,869 - DEBUG - VN 4f1a873c-bbce-41a4-accf-3520a0402309 still in use: Unable to complete operation on network 4f1a873c-bbce-41a4-accf-3520a0402309. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-b256c6eb-04c7-49c4-a108-056d5da350ef'] 2026-10-05 04:30:02,869 - WARNING - Deleting VN ctest-vn1-81344656 failed..Will retry 2026-10-05 04:30:05,074 - DEBUG - Response for deleting network () 2026-10-05 04:30:05,074 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/0cc17a4d-dc7b-460c-8ea8-7a9c253a38f9 2026-10-05 04:30:05,110 - DEBUG - Response Code: 404 2026-10-05 04:30:05,110 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:30:05,118 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:30:05,181 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:30:05,295 - INFO - Validated that VN ctest-vn1-81344656 is not found in API Server 2026-10-05 04:30:05,316 - DEBUG - VN ctest-vn1-81344656 is not present in Agent 10.0.0.50 2026-10-05 04:30:05,333 - DEBUG - VN ctest-vn1-81344656 is not present in Agent 10.0.0.191 2026-10-05 04:30:05,333 - INFO - Validated that VN ctest-vn1-81344656 is not in any agent 2026-10-05 04:30:05,379 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-81344656 info 2026-10-05 04:30:05,379 - INFO - Deleting VN ctest-fvn-77209518 2026-10-05 04:30:05,628 - DEBUG - Response for deleting network () 2026-10-05 04:30:05,628 - DEBUG - Requesting: http://10.0.0.177:8082/routing-instance/8a32b8cf-1b9b-478a-8a6c-aaf963ce5473 2026-10-05 04:30:05,641 - DEBUG - Response Code: 404 2026-10-05 04:30:05,641 - DEBUG - Requesting: http://10.0.0.177:8082/domains 2026-10-05 04:30:05,656 - DEBUG - Requesting: http://10.0.0.177:8082/domain/6850e378-7089-4036-8f54-55c0ed1b9054 2026-10-05 04:30:05,680 - DEBUG - Requesting: http://10.0.0.177:8082/project/1c47cd9d-4d8c-4da7-8310-bb67c81c670d 2026-10-05 04:30:05,781 - INFO - Validated that VN ctest-fvn-77209518 is not found in API Server 2026-10-05 04:30:05,796 - DEBUG - VN ctest-fvn-77209518 is not present in Agent 10.0.0.50 2026-10-05 04:30:05,810 - DEBUG - VN ctest-fvn-77209518 is not present in Agent 10.0.0.191 2026-10-05 04:30:05,810 - INFO - Validated that VN ctest-fvn-77209518 is not in any agent 2026-10-05 04:30:05,852 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-fvn-77209518 info 2026-10-05 04:30:07,187 - ERROR - 
Traceback (most recent call last):
  File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
    result = function(self, *args, **kwargs)
  File "/contrail-test/scripts/vm_regression/test_vm.py", line 3030, in test_sctp_traffic_between_vm
    if not vn1_vm1_fixture.ping_with_certainty(fvn_vm1_fixture.vm_ip):
  File "/contrail-test/fixtures/vm_test.py", line 354, in vm_ip
    assert self.verify_vm_launched()
AssertionError
2026-10-05 04:30:07,202 - DEBUG - No XMPP flaps were noticed during the test 2026-10-05 04:30:07,202 - INFO -
2026-10-05 04:30:07,202 - INFO - END TEST : test_sctp_traffic_between_vm : FAILED[0:10:49]
2026-10-05 04:30:07,202 - INFO - -------------------------------------------------------------------------------- 2026-10-05 04:30:08,140 - INFO - Deleted project: ctest-TestBasicVMVNx-94562591, ID : 1c47cd9d-4d8c-4da7-8310-bb67c81c670d