2025-09-11 02:56:16,281 - INFO - Domain Default found not creating 2025-09-11 02:56:16,444 - INFO - Project ctest-TestBasicVMVNx-85137739 not found, creating it 2025-09-11 02:56:16,977 - INFO - Created Project:ctest-TestBasicVMVNx-85137739, ID : 2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:56:18,380 - INFO - ================================================================================ 2025-09-11 02:56:18,380 - INFO - STARTING TEST : test_sctp_traffic_between_vm 2025-09-11 02:56:18,380 - 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 2025-09-11 02:56:19,646 - DEBUG - Nothing to compare xmpp stats {'10.0.0.254': {'10.20.0.17': '0', '10.20.0.25': '0'}, '10.0.0.19': {'10.20.0.17': '0', '10.20.0.25': '0'}} with 2025-09-11 02:56:19,646 - INFO - Initial checks done. Running the testcase now 2025-09-11 02:56:19,646 - INFO - 2025-09-11 02:56:19,667 - DEBUG - Services list from nova: [, , , ] 2025-09-11 02:56:19,667 - DEBUG - Hosts: {'nova': ['an-jenkins-deploy-platform-ansible-os-4079-1', 'an-jenkins-deploy-platform-ansible-os-4079-2']} 2025-09-11 02:56:20,332 - DEBUG - Response for create_network : {'network': {'id': 'bc67f061-01fc-4682-9a4f-18febce36944', 'name': 'ctest-fvn-92708977', 'tenant_id': '2671c377a59a493a90746702ce4e2df9', 'project_id': '2671c377a59a493a90746702ce4e2df9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVNx-85137739', 'ctest-fvn-92708977'], 'port_security_enabled': True, 'description': ''}} 2025-09-11 02:56:20,667 - DEBUG - Response for create_subnet : {'subnet': {'id': '34a3ed9d-76ef-47a6-a22a-29f6418d26af', 'name': '', 'tenant_id': '2671c377a59a493a90746702ce4e2df9', 'network_id': 'bc67f061-01fc-4682-9a4f-18febce36944', 'ip_version': 4, 'cidr': '86.8.56.64/26', 'allocation_pools': [{'start': '86.8.56.66', 'end': '86.8.56.126'}], 'gateway_ip': '86.8.56.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '86.8.56.66', 'tags': [], 'project_id': '2671c377a59a493a90746702ce4e2df9'}} 2025-09-11 02:56:20,690 - INFO - Created VN ctest-fvn-92708977 2025-09-11 02:56:20,701 - DEBUG - VN ctest-fvn-92708977 UUID is bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:20,771 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:56:21,065 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:56:21,092 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:56:21,117 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:56:21,206 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,216 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,226 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 02:56:21,233 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 02:56:21,240 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/24d9a499-1650-4b5a-b66b-9b2b970eb05c 2025-09-11 02:56:21,247 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-09-11 02:56:21,247 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,257 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 02:56:21,272 - INFO - Verified VN network id 14 for VN bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,272 - INFO - Verifications in API Server for VN ctest-fvn-92708977 passed 2025-09-11 02:56:21,273 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,282 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 02:56:21,289 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 02:56:21,295 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/24d9a499-1650-4b5a-b66b-9b2b970eb05c 2025-09-11 02:56:21,308 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13576083901167453826', 'uuid-lslong': '11119133487370824004'}, 'enable': 'true', 'created': '2025-09-11T02:56:20', 'last-modified': '2025-09-11T02:56:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.697881'} 2025-09-11 02:56:21,313 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-09-11 02:56:21,319 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13576083901167453826', 'uuid-lslong': '11119133487370824004'}, 'enable': 'true', 'created': '2025-09-11T02:56:20', 'last-modified': '2025-09-11T02:56:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.704540'} 2025-09-11 02:56:21,325 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-09-11 02:56:21,330 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '13576083901167453826', 'uuid-lslong': '11119133487370824004'}, 'enable': 'true', 'created': '2025-09-11T02:56:20', 'last-modified': '2025-09-11T02:56:20', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.713327'} 2025-09-11 02:56:21,335 - DEBUG - Route Targets: ['target:64512:8000004'] 2025-09-11 02:56:21,335 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-fvn-92708977 passed 2025-09-11 02:56:21,336 - DEBUG - ====Verifying policy data for ctest-fvn-92708977 in API_Server ====== 2025-09-11 02:56:21,336 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:56:21,341 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:56:21,352 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:56:21,445 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:56:21,455 - DEBUG - =>VN ctest-fvn-92708977 has no policy to be verified 2025-09-11 02:56:21,455 - DEBUG - Verifying the vn in opserver 2025-09-11 02:56:21,455 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977 virtual network link through opserver 10.0.0.249 2025-09-11 02:56:21,456 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks 2025-09-11 02:56:21,758 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks 2025-09-11 02:56:21,808 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977?flat'} 2025-09-11 02:56:21,808 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977 virtual network link through opserver 10.0.0.22 2025-09-11 02:56:21,809 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-09-11 02:56:22,106 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-09-11 02:56:22,160 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977?flat'} 2025-09-11 02:56:22,160 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977 virtual network link through opserver 10.0.0.49 2025-09-11 02:56:22,160 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks 2025-09-11 02:56:22,453 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks 2025-09-11 02:56:22,516 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977?flat'} 2025-09-11 02:56:22,516 - INFO - Validated that VN default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977 is found in opserver 2025-09-11 02:56:22,537 - DEBUG - Do not have enough data to verify VN in agent 2025-09-11 02:56:22,546 - DEBUG - VRF ids for VN ctest-fvn-92708977: {} 2025-09-11 02:56:22,818 - DEBUG - Response for create_network : {'network': {'id': 'ab3d5d48-8028-47d5-9403-514aeebc8edc', 'name': 'ctest-vn1-70138309', 'tenant_id': '2671c377a59a493a90746702ce4e2df9', 'project_id': '2671c377a59a493a90746702ce4e2df9', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVNx-85137739', 'ctest-vn1-70138309'], 'port_security_enabled': True, 'description': ''}} 2025-09-11 02:56:23,076 - DEBUG - Response for create_subnet : {'subnet': {'id': '0f6f5740-ff47-426d-94bb-a26b88092036', 'name': '', 'tenant_id': '2671c377a59a493a90746702ce4e2df9', 'network_id': 'ab3d5d48-8028-47d5-9403-514aeebc8edc', 'ip_version': 4, 'cidr': '15.241.253.0/26', 'allocation_pools': [{'start': '15.241.253.2', 'end': '15.241.253.62'}], 'gateway_ip': '15.241.253.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '15.241.253.2', 'tags': [], 'project_id': '2671c377a59a493a90746702ce4e2df9'}} 2025-09-11 02:56:23,101 - INFO - Created VN ctest-vn1-70138309 2025-09-11 02:56:23,118 - DEBUG - VN ctest-vn1-70138309 UUID is ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,185 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:56:23,205 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:56:23,215 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:56:23,307 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,318 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,326 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 02:56:23,333 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 02:56:23,339 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/da0512df-e47e-41fe-9e0a-5793c38ed253 2025-09-11 02:56:23,346 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-09-11 02:56:23,346 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,355 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 02:56:23,371 - INFO - Verified VN network id 15 for VN ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,371 - INFO - Verifications in API Server for VN ctest-vn1-70138309 passed 2025-09-11 02:56:23,371 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,379 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 02:56:23,385 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 02:56:23,393 - DEBUG - Requesting: http://10.0.0.249:8082/route-target/da0512df-e47e-41fe-9e0a-5793c38ed253 2025-09-11 02:56:23,405 - DEBUG - Control-node 10.0.0.249 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12339121120034179029', 'uuid-lslong': '10665457724818231004'}, 'enable': 'true', 'created': '2025-09-11T02:56:22', 'last-modified': '2025-09-11T02:56:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.384326'} 2025-09-11 02:56:23,412 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-09-11 02:56:23,418 - DEBUG - Control-node 10.0.0.22 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12339121120034179029', 'uuid-lslong': '10665457724818231004'}, 'enable': 'true', 'created': '2025-09-11T02:56:22', 'last-modified': '2025-09-11T02:56:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.392507'} 2025-09-11 02:56:23,423 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-09-11 02:56:23,430 - DEBUG - Control-node 10.0.0.49 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVNx-85137739', 'owner-access': '7', 'group': 'member', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '12339121120034179029', 'uuid-lslong': '10665457724818231004'}, 'enable': 'true', 'created': '2025-09-11T02:56:22', 'last-modified': '2025-09-11T02:56:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.402553'} 2025-09-11 02:56:23,440 - DEBUG - Route Targets: ['target:64512:8000005'] 2025-09-11 02:56:23,440 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-70138309 passed 2025-09-11 02:56:23,440 - DEBUG - ====Verifying policy data for ctest-vn1-70138309 in API_Server ====== 2025-09-11 02:56:23,440 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:56:23,446 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:56:23,456 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:56:23,557 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/ab3d5d48-8028-47d5-9403-514aeebc8edc 2025-09-11 02:56:23,569 - DEBUG - =>VN ctest-vn1-70138309 has no policy to be verified 2025-09-11 02:56:23,570 - DEBUG - Verifying the vn in opserver 2025-09-11 02:56:23,570 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 virtual network link through opserver 10.0.0.249 2025-09-11 02:56:23,570 - DEBUG - Requesting: http://10.0.0.249:8081/analytics/uves/virtual-networks 2025-09-11 02:56:23,629 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'href': 'http://10.0.0.249:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309?flat'} 2025-09-11 02:56:23,629 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 virtual network link through opserver 10.0.0.22 2025-09-11 02:56:23,629 - DEBUG - Requesting: http://10.0.0.22:8081/analytics/uves/virtual-networks 2025-09-11 02:56:23,696 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'href': 'http://10.0.0.22:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309?flat'} 2025-09-11 02:56:23,696 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 virtual network link through opserver 10.0.0.49 2025-09-11 02:56:23,696 - DEBUG - Requesting: http://10.0.0.49:8081/analytics/uves/virtual-networks 2025-09-11 02:56:23,763 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309', 'href': 'http://10.0.0.49:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309?flat'} 2025-09-11 02:56:23,763 - INFO - Validated that VN default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is found in opserver 2025-09-11 02:56:23,786 - DEBUG - Do not have enough data to verify VN in agent 2025-09-11 02:56:23,804 - DEBUG - VRF ids for VN ctest-vn1-70138309: {} 2025-09-11 02:56:23,992 - DEBUG - Image by name ubuntu-sctp not found 2025-09-11 02:56:23,992 - DEBUG - Installing image ubuntu-sctp 2025-09-11 02:56:23,992 - 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'} 2025-09-11 02:56:23,992 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-sctp.vmdk.gz 2025-09-11 02:56:23,992 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-sctp.vmdk.gz 2025-09-11 02:56:24,009 - 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 2025-09-11 02:56:26,147 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-sctp.vmdk.gz 2025-09-11 02:56:26,147 - DEBUG - Unzip image 2025-09-11 02:56:26,147 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-sctp.vmdk.gz 2025-09-11 02:56:33,183 - DEBUG - Try to create image in user context 2025-09-11 02:56:38,489 - DEBUG - Image has been created in user context 2025-09-11 02:56:38,489 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: rm -f /contrail-test/images/ubuntu-sctp.vmdk 2025-09-11 02:56:38,624 - DEBUG - Downloaded image has been removed 2025-09-11 02:56:38,636 - DEBUG - Uploaded image status = active 2025-09-11 02:56:39,714 - 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 02:56:41,286 - 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 02:56:41,391 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-11 02:56:46,474 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-11 02:56:51,551 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-11 02:56:56,627 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-11 02:57:01,708 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2025-09-11 02:57:06,780 - DEBUG - VM is in ACTIVE state now 2025-09-11 02:57:06,780 - INFO - VM name : ctest-vn1_vm1_name-20155990 2025-09-11 02:57:06,854 - DEBUG - VM ctest-vn1_vm1_name-20155990 ID is a7dedfec-de8f-4d54-9108-7d8a98951f8c 2025-09-11 02:57:06,854 - DEBUG - VM ctest-vn1_vm1_name-20155990 launched on Node an-jenkins-deploy-platform-ansible-os-4079-1 2025-09-11 02:57:06,930 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/a7dedfec-de8f-4d54-9108-7d8a98951f8c 2025-09-11 02:57:07,240 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine/a7dedfec-de8f-4d54-9108-7d8a98951f8c 2025-09-11 02:57:07,274 - DEBUG - Requesting: http://10.0.0.49:8082/virtual-machine-interface/8fd9ac28-bfde-4540-93da-03f349f95409 2025-09-11 02:57:10,447 - 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') 2025-09-11 02:57:10,447 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:10,461 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:14,546 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-09-11 02:57:14,547 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:14,561 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:18,644 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1018ms') 2025-09-11 02:57:18,644 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:18,658 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:22,735 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-09-11 02:57:22,736 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:22,752 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:26,833 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2025-09-11 02:57:26,833 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:26,849 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:30,921 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1014ms') 2025-09-11 02:57:30,922 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:30,936 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:35,019 - 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 1021ms') 2025-09-11 02:57:35,019 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:35,033 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:39,121 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1020ms') 2025-09-11 02:57:39,121 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:39,134 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:43,209 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1019ms') 2025-09-11 02:57:43,209 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:43,232 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:47,312 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1015ms') 2025-09-11 02:57:47,312 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:47,326 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:51,401 - 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 1010ms') 2025-09-11 02:57:51,401 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:51,414 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:55,498 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1027ms') 2025-09-11 02:57:55,498 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 failed! 2025-09-11 02:57:55,513 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVNx-85137739:ctest-vn1-70138309 is 15.241.253.1 and allocation pool is NOT set 2025-09-11 02:57:57,578 - DEBUG - (True, 'PING 169.254.0.3 (169.254.0.3) 56(84) bytes of data.\r\n64 bytes from 169.254.0.3: icmp_seq=1 ttl=63 time=4.83 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.939 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.939/2.882/4.825/1.943 ms') 2025-09-11 02:57:57,578 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1_name-20155990 passed 2025-09-11 02:57:57,643 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:57:57,643 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:57:57,710 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:57:57,822 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:02,823 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:02,823 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:02,889 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:02,974 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:07,975 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:07,975 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:08,041 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:08,118 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:13,118 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:13,119 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:13,186 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:13,273 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:18,273 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:18,273 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:18,341 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:18,421 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:23,422 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:23,422 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:23,482 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:23,562 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:28,563 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:28,563 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:28,619 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:28,697 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:33,698 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:33,698 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:33,756 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:33,836 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:38,837 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:38,837 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:38,895 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:38,986 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:43,987 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:43,987 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:44,053 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:44,151 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:49,151 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:49,151 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:49,218 - DEBUG - Error on ssh to ubuntu@169.254.0.3:22, result: /bin/bash: connect: Connection refused /bin/bash: line 1: /dev/tcp/169.254.0.3/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.3/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.3/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''} 2025-09-11 02:58:49,297 - DEBUG - VM ctest-vn1_vm1_name-20155990 is NOT ready for SSH connections, VM status: ACTIVE 2025-09-11 02:58:54,297 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2025-09-11 02:58:54,297 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1_name-20155990, IP 15.241.253.3, Port 22 2025-09-11 02:58:54,455 - DEBUG - VM ctest-vn1_vm1_name-20155990 is ready for SSH connections 2025-09-11 02:58:54,508 - DEBUG - VM is in ERROR state now 2025-09-11 02:58:54,508 - ERROR - VM in error state. 2025-09-11 02:58:54,509 - ERROR - VM is not in ACTIVE state 2025-09-11 02:58:54,654 - INFO - Creating Floating IP pool ctest-some-pool-70684616 in API Server 2025-09-11 02:58:54,824 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:58:54,831 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:58:54,847 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:58:54,937 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:58:54,954 - DEBUG - Requesting: http://10.0.0.249:8082/floating-ip-pool/4ad5916d-4c06-427f-a859-d5e756554db1 2025-09-11 02:58:54,961 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 02:58:54,968 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 02:58:54,981 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 02:58:55,067 - DEBUG - Requesting: http://10.0.0.249:8082/virtual-network/bc67f061-01fc-4682-9a4f-18febce36944 2025-09-11 02:58:55,077 - DEBUG - FIP Pool ctest-some-pool-70684616 found in API Server 2025-09-11 02:58:55,077 - INFO - Verification for FIP pool ctest-some-pool-70684616 in API Server passed 2025-09-11 02:58:55,095 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-70684616 information 2025-09-11 02:58:55,099 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-70684616 information 2025-09-11 02:58:55,104 - DEBUG - Control-node Ifmap-view has FIP pool ctest-some-pool-70684616 information 2025-09-11 02:58:55,104 - INFO - Verification for FIP pool ctest-some-pool-70684616 in Control-node passed 2025-09-11 02:58:55,242 - DEBUG - Created Floating IP : ('86.8.56.67', 'e770e567-268e-4c45-b32a-0de7dcbfc82b') 2025-09-11 02:58:55,242 - DEBUG - Associating FIP 86.8.56.67 to a7dedfec-de8f-4d54-9108-7d8a98951f8c 2025-09-11 02:58:55,268 - DEBUG - Associating FIP ID e770e567-268e-4c45-b32a-0de7dcbfc82b with Port ID 8fd9ac28-bfde-4540-93da-03f349f95409 2025-09-11 02:58:55,514 - INFO - Route for FIP 86.8.56.67 is fine on Control-node 10.0.0.22 2025-09-11 02:58:55,521 - INFO - Route for FIP 86.8.56.67 is fine on Control-node 10.0.0.249 2025-09-11 02:58:55,521 - INFO - FIP 86.8.56.67 verification for passed on all Control-nodes 2025-09-11 02:58:55,521 - INFO - FIP ID e770e567-268e-4c45-b32a-0de7dcbfc82b(86.8.56.67) validation in Control node passed 2025-09-11 02:58:55,545 - DEBUG - agent_label query returned:{'nh': {'type': 'interface', 'ref_count': '56', 'valid': 'true', 'policy': 'enabled', 'itf': 'tap8fd9ac28-bf', 'mac': ['2:8f:d9:ac:28:bf'], 'mcast': 'disabled', 'nh_index': '28', '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.17', 'dest_vn_list': ['default-domain:ctest-TestBasicVMVNx-85137739:ctest-fvn-92708977'], 'unresolved': 'false', 'sg_list': ['8000002'], '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} 2025-09-11 02:58:55,545 - DEBUG - Route for FIP IP 86.8.56.67 is present in agent 10.0.0.254 2025-09-11 02:58:55,545 - DEBUG - FIP 86.8.56.67 verification for VM ctest-vn1_vm1_name-20155990 in Agent 10.0.0.254 passed 2025-09-11 02:58:55,550 - INFO - FIP ID e770e567-268e-4c45-b32a-0de7dcbfc82b(86.8.56.67) validation in agents passed 2025-09-11 02:58:55,550 - DEBUG - Requesting: http://10.0.0.249:8082/floating-ip/e770e567-268e-4c45-b32a-0de7dcbfc82b 2025-09-11 02:58:55,565 - DEBUG - FIP e770e567-268e-4c45-b32a-0de7dcbfc82b is present in API server 2025-09-11 02:58:55,565 - INFO - FIP ID e770e567-268e-4c45-b32a-0de7dcbfc82b(86.8.56.67) validation in API Server passed 2025-09-11 02:58:55,565 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 02:58:55,627 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:00,689 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:05,754 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:10,814 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:15,880 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:20,938 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:20,938 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 02:59:22,939 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 02:59:22,997 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:28,066 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:33,124 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:38,184 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:43,245 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:48,302 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:48,302 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 02:59:50,303 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 02:59:50,377 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 02:59:55,431 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:00,493 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:05,555 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:10,613 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:15,672 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:15,672 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:00:17,673 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:00:17,733 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:22,794 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:27,852 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:32,914 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:37,976 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:43,037 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:43,037 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:00:45,038 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:00:45,096 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:50,163 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:00:55,237 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:00,310 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:05,372 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:10,444 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:10,444 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:01:12,444 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:01:12,514 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:17,573 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:22,684 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:27,768 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:32,850 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:37,907 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:37,907 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:01:37,910 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:01:37,966 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:43,039 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:48,097 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:53,152 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:01:58,216 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:03,273 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:03,274 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:02:05,274 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:02:05,334 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:10,404 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:15,463 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:20,538 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:25,608 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:30,668 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:30,668 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:02:32,669 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:02:32,728 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:37,796 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:42,874 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:47,940 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:53,001 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:58,082 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:02:58,082 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:03:00,083 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:03:00,140 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:05,214 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:10,281 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:15,347 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:20,406 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:25,471 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:25,471 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:03:27,473 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:03:27,531 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:32,589 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:37,649 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:42,717 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:47,781 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:52,840 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:52,840 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:03:54,841 - INFO - VM name : ctest-fvn_vm1_name-81929093 2025-09-11 03:03:54,901 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:03:59,960 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:04:05,026 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:04:10,088 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:04:15,157 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:04:20,219 - DEBUG - VM ctest-fvn_vm1_name-81929093 : Status=ERROR, Addresses : {} 2025-09-11 03:04:20,219 - ERROR - VM b35d64fb-8de5-4859-ad47-d3ad7d11958f is not launched yet 2025-09-11 03:04:20,220 - DEBUG - Disassociating port from FIP ID : e770e567-268e-4c45-b32a-0de7dcbfc82b 2025-09-11 03:04:20,285 - DEBUG - Deleting FIP ID e770e567-268e-4c45-b32a-0de7dcbfc82b 2025-09-11 03:04:20,391 - INFO - Deleting the FIP pool ctest-some-pool-70684616 2025-09-11 03:04:20,520 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-70684616 information 2025-09-11 03:04:20,525 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-70684616 information 2025-09-11 03:04:20,530 - DEBUG - Control-node Ifmap-view does not have FIP pool ctest-some-pool-70684616 information 2025-09-11 03:04:20,531 - INFO - Skip interface_detach for VM ctest-fvn_vm1_name-81929093 in state ERROR 2025-09-11 03:04:20,531 - INFO - Deleting VM ctest-fvn_vm1_name-81929093 2025-09-11 03:04:20,531 - ERROR - VM ctest-fvn_vm1_name-81929093 has failed to come up 2025-09-11 03:04:20,531 - ERROR - Fault seen in nova show is: {'code': 500, 'created': '2025-09-11T02:56:41Z', '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:04:20,531 - INFO - Deleting VM ctest-vn1_vm1_name-20155990 2025-09-11 03:04:20,594 - INFO - Deleting VN ctest-vn1-70138309 2025-09-11 03:04:20,637 - DEBUG - VN ab3d5d48-8028-47d5-9403-514aeebc8edc still in use: Unable to complete operation on network ab3d5d48-8028-47d5-9403-514aeebc8edc. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-f8721dd3-61ae-4017-b65d-d4cc63e4d75d'] 2025-09-11 03:04:20,637 - WARNING - Deleting VN ctest-vn1-70138309 failed..Will retry 2025-09-11 03:04:22,862 - DEBUG - Response for deleting network () 2025-09-11 03:04:22,862 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/214bddc8-fffd-4dad-af96-b36c77acdef8 2025-09-11 03:04:22,908 - DEBUG - Response Code: 404 2025-09-11 03:04:22,909 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 03:04:22,915 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 03:04:22,991 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 03:04:23,081 - INFO - Validated that VN ctest-vn1-70138309 is not found in API Server 2025-09-11 03:04:23,093 - DEBUG - VN ctest-vn1-70138309 is not present in Agent 10.0.0.254 2025-09-11 03:04:23,107 - DEBUG - VN ctest-vn1-70138309 is not present in Agent 10.0.0.19 2025-09-11 03:04:23,107 - INFO - Validated that VN ctest-vn1-70138309 is not in any agent 2025-09-11 03:04:23,143 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-70138309 info 2025-09-11 03:04:23,143 - INFO - Deleting VN ctest-fvn-92708977 2025-09-11 03:04:23,359 - DEBUG - Response for deleting network () 2025-09-11 03:04:23,359 - DEBUG - Requesting: http://10.0.0.249:8082/routing-instance/100d96f6-d053-43b6-9838-bae5c629f8d3 2025-09-11 03:04:23,366 - DEBUG - Response Code: 404 2025-09-11 03:04:23,366 - DEBUG - Requesting: http://10.0.0.249:8082/domains 2025-09-11 03:04:23,371 - DEBUG - Requesting: http://10.0.0.249:8082/domain/6cefd47d-baca-4df6-a10c-ec963319da07 2025-09-11 03:04:23,382 - DEBUG - Requesting: http://10.0.0.249:8082/project/2671c377-a59a-493a-9074-6702ce4e2df9 2025-09-11 03:04:23,478 - INFO - Validated that VN ctest-fvn-92708977 is not found in API Server 2025-09-11 03:04:23,495 - DEBUG - VN ctest-fvn-92708977 is not present in Agent 10.0.0.254 2025-09-11 03:04:23,506 - DEBUG - VN ctest-fvn-92708977 is not present in Agent 10.0.0.19 2025-09-11 03:04:23,506 - INFO - Validated that VN ctest-fvn-92708977 is not in any agent 2025-09-11 03:04:23,541 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-fvn-92708977 info 2025-09-11 03:04:24,804 - 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
2025-09-11 03:04:24,821 - DEBUG - No XMPP flaps were noticed during the test 2025-09-11 03:04:24,822 - INFO -
2025-09-11 03:04:24,822 - INFO - END TEST : test_sctp_traffic_between_vm : FAILED[0:08:06]
2025-09-11 03:04:24,822 - INFO - -------------------------------------------------------------------------------- 2025-09-11 03:04:25,569 - INFO - Deleted project: ctest-TestBasicVMVNx-85137739, ID : 2671c377-a59a-493a-9074-6702ce4e2df9