2024-09-11 07:02:54,277 - INFO - Domain Default found not creating 2024-09-11 07:02:54,489 - INFO - Project ctest-TestBasicVMVN-26438550 not found, creating it 2024-09-11 07:02:55,052 - INFO - Created Project:ctest-TestBasicVMVN-26438550, ID : 7271f648-2d71-4c07-ade0-7446368c7662 2024-09-11 07:02:56,903 - INFO - ================================================================================ 2024-09-11 07:02:56,903 - INFO - STARTING TEST : test_generic_link_local_service 2024-09-11 07:02:56,903 - INFO - TEST DESCRIPTION : Description: Test to validate generic linklocal service - running nova list from vm. 1.Create generic link local service to be able to wget to jenkins 2.Create a vm 3.Try wget to jenkins - passes if successful else fails Maintainer: sandipd@juniper.net 2024-09-11 07:02:57,178 - DEBUG - Nothing to compare xmpp stats {'10.0.0.12': {'10.20.0.21': '0'}} with 2024-09-11 07:02:57,178 - INFO - Initial checks done. Running the testcase now 2024-09-11 07:02:57,179 - INFO - 2024-09-11 07:02:57,844 - DEBUG - Response for create_network : {'network': {'id': '4d94f92c-79fd-40b1-8e5d-6b80a51ead98', 'name': 'ctest-vn2_metadata-62205435', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'project_id': '7271f6482d714c07ade07446368c7662', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN-26438550', 'ctest-vn2_metadata-62205435'], 'port_security_enabled': True, 'description': ''}} 2024-09-11 07:02:58,085 - DEBUG - Response for create_subnet : {'subnet': {'id': 'f22381a1-f26c-4538-b529-a79ccee5ab15', 'name': '', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'network_id': '4d94f92c-79fd-40b1-8e5d-6b80a51ead98', 'ip_version': 4, 'cidr': '11.1.1.0/24', 'allocation_pools': [{'start': '11.1.1.2', 'end': '11.1.1.254'}], 'gateway_ip': '11.1.1.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '11.1.1.2', 'tags': [], 'project_id': '7271f6482d714c07ade07446368c7662'}} 2024-09-11 07:02:58,110 - INFO - Created VN ctest-vn2_metadata-62205435 2024-09-11 07:02:58,164 - DEBUG - VN ctest-vn2_metadata-62205435 UUID is 4d94f92c-79fd-40b1-8e5d-6b80a51ead98 2024-09-11 07:02:58,391 - DEBUG - Services list from nova: [, , ] 2024-09-11 07:02:59,771 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-1890-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-1890-1) 2024-09-11 07:02:59,883 - DEBUG - Link local service introspect added 2024-09-11 07:02:59,939 - DEBUG - VM is still in BUILD state, Expected: ACTIVE 2024-09-11 07:03:05,037 - DEBUG - VM is in ACTIVE state now 2024-09-11 07:03:05,199 - INFO - Waiting for VM ctest-TestBasicVMVN-26438550-64030445 to be up.. 2024-09-11 07:03:05,199 - INFO - VM name : ctest-TestBasicVMVN-26438550-64030445 2024-09-11 07:03:05,302 - DEBUG - VM ctest-TestBasicVMVN-26438550-64030445 ID is 9ed9a853-f458-4989-8ec1-94bee1932e3f 2024-09-11 07:03:05,303 - DEBUG - VM ctest-TestBasicVMVN-26438550-64030445 launched on Node cn-jenkins-deploy-platform-ansible-os-1890-1 2024-09-11 07:03:05,404 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine/9ed9a853-f458-4989-8ec1-94bee1932e3f 2024-09-11 07:03:05,751 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine/9ed9a853-f458-4989-8ec1-94bee1932e3f 2024-09-11 07:03:05,792 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine-interface/7a4faff1-72ed-4ba6-ab95-ebbc57f02bda 2024-09-11 07:03:09,064 - 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') 2024-09-11 07:03:09,064 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicVMVN-26438550-64030445 failed! 2024-09-11 07:03:09,120 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN-26438550:ctest-vn2_metadata-62205435 is 11.1.1.1 and allocation pool is NOT set 2024-09-11 07:03:11,182 - 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=14.2 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.419 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1000ms\r\nrtt min/avg/max/mdev = 0.419/7.330/14.241/6.911 ms') 2024-09-11 07:03:11,182 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicVMVN-26438550-64030445 passed 2024-09-11 07:03:11,336 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:11,336 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-64030445, IP 11.1.1.3, Port 22 2024-09-11 07:03:11,402 - DEBUG - Error on ssh to cirros@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': ''} 2024-09-11 07:03:11,503 - DEBUG - VM ctest-TestBasicVMVN-26438550-64030445 is NOT ready for SSH connections, VM status: ACTIVE 2024-09-11 07:03:16,504 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:16,505 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-64030445, IP 11.1.1.3, Port 22 2024-09-11 07:03:16,682 - DEBUG - VM ctest-TestBasicVMVN-26438550-64030445 is ready for SSH connections 2024-09-11 07:03:16,682 - INFO - Retry 0 2024-09-11 07:03:16,682 - DEBUG - Running remote_cmd, Cmd : wget http://169.254.1.2:8083 --spider && echo "Successful", host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:16,682 - DEBUG - wget http://169.254.1.2:8083 --spider && echo "Successful" 2024-09-11 07:03:18,707 - DEBUG - Connecting to 169.254.1.2:8083 (169.254.1.2:8083) Successful 2024-09-11 07:03:18,707 - INFO - Generic metadata worked 2024-09-11 07:03:18,936 - DEBUG - Link local service introspect removed 2024-09-11 07:03:18,936 - INFO - Deleting VM ctest-TestBasicVMVN-26438550-64030445 2024-09-11 07:03:19,011 - INFO - Deleting VN ctest-vn2_metadata-62205435 2024-09-11 07:03:19,062 - DEBUG - VN 4d94f92c-79fd-40b1-8e5d-6b80a51ead98 still in use: Unable to complete operation on network 4d94f92c-79fd-40b1-8e5d-6b80a51ead98. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-32145113-e503-40cc-ab4c-ecb3bc1b2994'] 2024-09-11 07:03:19,062 - WARNING - Deleting VN ctest-vn2_metadata-62205435 failed..Will retry 2024-09-11 07:03:21,185 - DEBUG - Response for deleting network () 2024-09-11 07:03:21,448 - DEBUG - No XMPP flaps were noticed during the test 2024-09-11 07:03:21,448 - INFO - -------------------------------------------------------------------------------- 2024-09-11 07:03:21,455 - INFO - ================================================================================ 2024-09-11 07:03:21,455 - INFO - STARTING TEST : test_ping_within_vn_two_vms_two_different_subnets 2024-09-11 07:03:21,455 - INFO - TEST DESCRIPTION : Description: Validate Ping between 2 VMs in the same VN, 2 VMs in different VN subnets. Test steps: 1. Create 1 IPAM's. 2. Create 1 VN with 2 subnets and launch 2 VMs in them. 3. Ping between the VMs in the same VN should go thru fine. 4. Ping to the subnet broadcast and all-broadcast address. Pass criteria: VM in the same subnet will respond to both the pings, while the VM in a different VN should respond only to the all-broadcast address. Maintainer : ganeshahv@juniper.net 2024-09-11 07:03:21,741 - DEBUG - Nothing to compare xmpp stats {'10.0.0.12': {'10.20.0.21': '0'}} with 2024-09-11 07:03:21,741 - INFO - Initial checks done. Running the testcase now 2024-09-11 07:03:21,741 - INFO - 2024-09-11 07:03:22,256 - DEBUG - Response for create_network : {'network': {'id': 'ed34094c-c3d6-462f-8c88-28c808d61420', 'name': 'ctest-vn-75195116', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'project_id': '7271f6482d714c07ade07446368c7662', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicVMVN-26438550', 'ctest-vn-75195116'], 'port_security_enabled': True, 'description': ''}} 2024-09-11 07:03:22,487 - DEBUG - Response for create_subnet : {'subnet': {'id': '5169ab44-0f6f-4989-b50e-65ba62920e94', 'name': '', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'network_id': 'ed34094c-c3d6-462f-8c88-28c808d61420', 'ip_version': 4, 'cidr': '31.1.1.0/29', 'allocation_pools': [{'start': '31.1.1.2', 'end': '31.1.1.6'}], 'gateway_ip': '31.1.1.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '31.1.1.2', 'tags': [], 'project_id': '7271f6482d714c07ade07446368c7662'}} 2024-09-11 07:03:22,679 - DEBUG - Response for create_subnet : {'subnet': {'id': '756bd845-20a7-4485-84c3-6101181fa734', 'name': '', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'network_id': 'ed34094c-c3d6-462f-8c88-28c808d61420', 'ip_version': 4, 'cidr': '31.1.2.0/29', 'allocation_pools': [{'start': '31.1.2.2', 'end': '31.1.2.6'}], 'gateway_ip': '31.1.2.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '31.1.2.2', 'tags': [], 'project_id': '7271f6482d714c07ade07446368c7662'}} 2024-09-11 07:03:22,703 - INFO - Created VN ctest-vn-75195116 2024-09-11 07:03:22,756 - DEBUG - VN ctest-vn-75195116 UUID is ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:23,170 - DEBUG - Response for create_port : {'port': {'name': '33b3f7d9-af99-4a1f-a47e-1e2cb899391a', 'id': '33b3f7d9-af99-4a1f-a47e-1e2cb899391a', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'network_id': 'ed34094c-c3d6-462f-8c88-28c808d61420', 'mac_address': '02:33:b3:f7:d9:af', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '31.1.1.4', 'subnet_id': '5169ab44-0f6f-4989-b50e-65ba62920e94'}], 'security_groups': ['189f7b1a-ce64-4ac3-ac7a-dc43149b833e'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '7271f6482d714c07ade07446368c7662'}} 2024-09-11 07:03:23,374 - DEBUG - Response for create_port : {'port': {'name': '6cc91176-a98b-4433-beb2-53657ef2cc12', 'id': '6cc91176-a98b-4433-beb2-53657ef2cc12', 'tenant_id': '7271f6482d714c07ade07446368c7662', 'network_id': 'ed34094c-c3d6-462f-8c88-28c808d61420', 'mac_address': '02:6c:c9:11:76:a9', 'binding:vnic_type': 'normal', 'binding:vif_details': {'port_filter': True}, 'binding:vif_type': 'unbound', 'binding:host_id': None, 'allowed_address_pairs': [], 'fixed_ips': [{'ip_address': '31.1.2.4', 'subnet_id': '756bd845-20a7-4485-84c3-6101181fa734'}], 'security_groups': ['189f7b1a-ce64-4ac3-ac7a-dc43149b833e'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '7271f6482d714c07ade07446368c7662'}} 2024-09-11 07:03:23,856 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-1890-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-1890-1) 2024-09-11 07:03:24,359 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-1890-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-1890-1) 2024-09-11 07:03:25,837 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-1890-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-1890-1) 2024-09-11 07:03:25,837 - DEBUG - Requesting: http://10.0.0.12:8082/domains 2024-09-11 07:03:25,845 - DEBUG - Requesting: http://10.0.0.12:8082/domain/e5789681-1145-42b1-8757-ad577d040188 2024-09-11 07:03:25,860 - DEBUG - Requesting: http://10.0.0.12:8082/project/7271f648-2d71-4c07-ade0-7446368c7662 2024-09-11 07:03:25,934 - DEBUG - Requesting: http://10.0.0.12:8082/network-ipam/457cb135-b8e1-4e36-ae5a-5362bf4f9aa1 2024-09-11 07:03:25,955 - INFO - Verifications in API Server for IPAM: ctest-ipam-18761562 passed 2024-09-11 07:03:25,966 - DEBUG - Control-node 10.0.0.12 : IPAM object is : {'node_name': 'network-ipam:default-domain:ctest-TestBasicVMVN-26438550:ctest-ipam-18761562', 'interests': '0', 'advertised': '0', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN-26438550', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '5007071730022305334', 'uuid-lslong': '12563445794084985505'}, 'enable': 'true', 'created': '2024-09-11T07:03:21', 'last-modified': '2024-09-11T07:03:21', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:03.973288'} 2024-09-11 07:03:25,966 - INFO - Verifications in Control node for IPAM: ctest-ipam-18761562 passed 2024-09-11 07:03:25,966 - DEBUG - Requesting: http://10.0.0.12:8082/domains 2024-09-11 07:03:25,977 - DEBUG - Requesting: http://10.0.0.12:8082/domain/e5789681-1145-42b1-8757-ad577d040188 2024-09-11 07:03:26,001 - DEBUG - Requesting: http://10.0.0.12:8082/project/7271f648-2d71-4c07-ade0-7446368c7662 2024-09-11 07:03:26,087 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-network/ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,106 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-network/ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,119 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:03:26,134 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:03:26,144 - DEBUG - Requesting: http://10.0.0.12:8082/route-target/cfee41f2-9df9-4e3f-a995-f4d68915d2dc 2024-09-11 07:03:26,154 - DEBUG - Route Targets: ['target:64512:8000005'] 2024-09-11 07:03:26,155 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-network/ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,167 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:03:26,186 - INFO - Verified VN network id 9 for VN ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,186 - INFO - Verifications in API Server for VN ctest-vn-75195116 passed 2024-09-11 07:03:26,186 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-network/ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,196 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:03:26,205 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:03:26,214 - DEBUG - Requesting: http://10.0.0.12:8082/route-target/cfee41f2-9df9-4e3f-a995-f4d68915d2dc 2024-09-11 07:03:26,235 - DEBUG - Control-node 10.0.0.12 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116', 'interests': '0', 'advertised': '0', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicVMVN-26438550', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '17092296711085639215', 'uuid-lslong': '10126388601749378080'}, 'enable': 'true', 'created': '2024-09-11T07:03:22', 'last-modified': '2024-09-11T07:03:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:03.585552'} 2024-09-11 07:03:26,244 - DEBUG - Route Targets: ['target:64512:8000005'] 2024-09-11 07:03:26,244 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn-75195116 passed 2024-09-11 07:03:26,244 - DEBUG - ====Verifying policy data for ctest-vn-75195116 in API_Server ====== 2024-09-11 07:03:26,244 - DEBUG - Requesting: http://10.0.0.12:8082/domains 2024-09-11 07:03:26,252 - DEBUG - Requesting: http://10.0.0.12:8082/domain/e5789681-1145-42b1-8757-ad577d040188 2024-09-11 07:03:26,266 - DEBUG - Requesting: http://10.0.0.12:8082/project/7271f648-2d71-4c07-ade0-7446368c7662 2024-09-11 07:03:26,348 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-network/ed34094c-c3d6-462f-8c88-28c808d61420 2024-09-11 07:03:26,367 - DEBUG - =>VN ctest-vn-75195116 has no policy to be verified 2024-09-11 07:03:26,367 - DEBUG - Verifying the vn in opserver 2024-09-11 07:03:26,367 - DEBUG - Verifying the default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 virtual network link through opserver 10.0.0.12 2024-09-11 07:03:26,368 - DEBUG - Requesting: http://10.0.0.12:8081/analytics/uves/virtual-networks 2024-09-11 07:03:26,879 - DEBUG - Requesting: http://10.0.0.12:8081/analytics/uves/virtual-networks 2024-09-11 07:03:27,025 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116', 'href': 'http://10.0.0.12:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116?flat'} 2024-09-11 07:03:27,025 - INFO - Validated that VN default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 is found in opserver 2024-09-11 07:03:27,032 - DEBUG - VRF ids for VN ctest-vn-75195116: {'10.0.0.12': '2'} 2024-09-11 07:03:27,032 - INFO - Waiting for VM ctest-TestBasicVMVN-26438550-89532877 to be up.. 2024-09-11 07:03:27,176 - DEBUG - VM is in ACTIVE state now 2024-09-11 07:03:27,176 - INFO - VM name : ctest-TestBasicVMVN-26438550-89532877 2024-09-11 07:03:27,307 - DEBUG - VM ctest-TestBasicVMVN-26438550-89532877 ID is 95b14226-ea22-4121-8c6b-6e7f38d84312 2024-09-11 07:03:27,307 - DEBUG - VM ctest-TestBasicVMVN-26438550-89532877 launched on Node cn-jenkins-deploy-platform-ansible-os-1890-1 2024-09-11 07:03:27,421 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine/95b14226-ea22-4121-8c6b-6e7f38d84312 2024-09-11 07:03:27,434 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine-interface/33b3f7d9-af99-4a1f-a47e-1e2cb899391a 2024-09-11 07:03:30,703 - 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') 2024-09-11 07:03:30,703 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicVMVN-26438550-89532877 failed! 2024-09-11 07:03:30,764 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 is 31.1.1.1 and allocation pool is NOT set 2024-09-11 07:03:30,764 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 is 31.1.2.1 and allocation pool is NOT set 2024-09-11 07:03:34,822 - 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 1002ms') 2024-09-11 07:03:34,822 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicVMVN-26438550-89532877 failed! 2024-09-11 07:03:34,876 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 is 31.1.1.1 and allocation pool is NOT set 2024-09-11 07:03:34,876 - DEBUG - Gateway for vn default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 is 31.1.2.1 and allocation pool is NOT set 2024-09-11 07:03:36,936 - 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.23 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.791 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.791/2.512/4.234/1.721 ms') 2024-09-11 07:03:36,936 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-TestBasicVMVN-26438550-89532877 passed 2024-09-11 07:03:37,100 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:37,100 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-89532877, IP 31.1.1.4, Port 22 2024-09-11 07:03:37,166 - DEBUG - Error on ssh to cirros@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': ''} 2024-09-11 07:03:37,277 - DEBUG - VM ctest-TestBasicVMVN-26438550-89532877 is NOT ready for SSH connections, VM status: ACTIVE 2024-09-11 07:03:42,278 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:42,278 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-89532877, IP 31.1.1.4, Port 22 2024-09-11 07:03:42,447 - DEBUG - VM ctest-TestBasicVMVN-26438550-89532877 is ready for SSH connections 2024-09-11 07:03:42,447 - INFO - Waiting for VM ctest-TestBasicVMVN-26438550-65539910 to be up.. 2024-09-11 07:03:42,540 - DEBUG - VM is in ACTIVE state now 2024-09-11 07:03:42,540 - INFO - VM name : ctest-TestBasicVMVN-26438550-65539910 2024-09-11 07:03:42,628 - DEBUG - VM ctest-TestBasicVMVN-26438550-65539910 ID is 9dfc7eab-2b27-43de-a7cc-9f67dbc7a64c 2024-09-11 07:03:42,629 - DEBUG - VM ctest-TestBasicVMVN-26438550-65539910 launched on Node cn-jenkins-deploy-platform-ansible-os-1890-1 2024-09-11 07:03:42,830 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine/9dfc7eab-2b27-43de-a7cc-9f67dbc7a64c 2024-09-11 07:03:42,841 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine-interface/6cc91176-a98b-4433-beb2-53657ef2cc12 2024-09-11 07:03:44,093 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n64 bytes from 169.254.0.4: icmp_seq=1 ttl=63 time=3.91 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.478 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.478/2.193/3.908/1.715 ms') 2024-09-11 07:03:44,093 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-TestBasicVMVN-26438550-65539910 passed 2024-09-11 07:03:44,244 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:44,244 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-65539910, IP 31.1.2.4, Port 22 2024-09-11 07:03:44,411 - DEBUG - VM ctest-TestBasicVMVN-26438550-65539910 is ready for SSH connections 2024-09-11 07:03:44,411 - INFO - Waiting for VM ctest-TestBasicVMVN-26438550-17362776 to be up.. 2024-09-11 07:03:44,506 - DEBUG - VM is in ACTIVE state now 2024-09-11 07:03:44,506 - INFO - VM name : ctest-TestBasicVMVN-26438550-17362776 2024-09-11 07:03:44,602 - DEBUG - VM ctest-TestBasicVMVN-26438550-17362776 ID is d4ba1f95-efb3-41a7-9676-7b0c5f542c54 2024-09-11 07:03:44,603 - DEBUG - VM ctest-TestBasicVMVN-26438550-17362776 launched on Node cn-jenkins-deploy-platform-ansible-os-1890-1 2024-09-11 07:03:44,703 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine/d4ba1f95-efb3-41a7-9676-7b0c5f542c54 2024-09-11 07:03:44,712 - DEBUG - Requesting: http://10.0.0.12:8082/virtual-machine-interface/231ae740-0254-4847-aa3a-59ab86e2d4f6 2024-09-11 07:03:45,981 - DEBUG - (True, 'PING 169.254.0.5 (169.254.0.5) 56(84) bytes of data.\r\n64 bytes from 169.254.0.5: icmp_seq=1 ttl=63 time=3.77 ms\r\n64 bytes from 169.254.0.5: icmp_seq=2 ttl=63 time=0.779 ms\r\n\r\n--- 169.254.0.5 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1002ms\r\nrtt min/avg/max/mdev = 0.779/2.276/3.774/1.497 ms') 2024-09-11 07:03:45,981 - INFO - Ping to Metadata IP 169.254.0.5 of VM ctest-TestBasicVMVN-26438550-17362776 passed 2024-09-11 07:03:46,132 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:46,132 - DEBUG - Waiting to SSH to VM ctest-TestBasicVMVN-26438550-17362776, IP 31.1.1.3, Port 22 2024-09-11 07:03:46,302 - DEBUG - VM ctest-TestBasicVMVN-26438550-17362776 is ready for SSH connections 2024-09-11 07:03:46,302 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:46,302 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 31.1.2.4, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:46,302 - DEBUG - ping -s 56 -c 3 -W 1 31.1.2.4 2024-09-11 07:03:50,420 - DEBUG - PING 31.1.2.4 (31.1.2.4): 56 data bytes 64 bytes from 31.1.2.4: seq=0 ttl=63 time=4.844 ms 64 bytes from 31.1.2.4: seq=1 ttl=63 time=0.841 ms 64 bytes from 31.1.2.4: seq=2 ttl=63 time=1.026 ms --- 31.1.2.4 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.841/2.237/4.844 ms 2024-09-11 07:03:50,420 - INFO - Ping to IP 31.1.2.4 from VM ctest-TestBasicVMVN-26438550-89532877 passed 2024-09-11 07:03:50,420 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:50,420 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 31.1.1.4, host_string: cirros@169.254.0.4, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:50,420 - DEBUG - ping -s 56 -c 3 -W 1 31.1.1.4 2024-09-11 07:03:54,123 - DEBUG - PING 31.1.1.4 (31.1.1.4): 56 data bytes 64 bytes from 31.1.1.4: seq=0 ttl=63 time=3.198 ms 64 bytes from 31.1.1.4: seq=1 ttl=63 time=0.920 ms 64 bytes from 31.1.1.4: seq=2 ttl=63 time=0.999 ms --- 31.1.1.4 ping statistics --- 3 packets transmitted, 3 packets received, 0% packet loss round-trip min/avg/max = 0.920/1.705/3.198 ms 2024-09-11 07:03:54,124 - INFO - Ping to IP 31.1.1.4 from VM ctest-TestBasicVMVN-26438550-65539910 passed 2024-09-11 07:03:54,124 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:54,124 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:54,124 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set 2024-09-11 07:03:54,124 - DEBUG - Running remote_cmd, Cmd : echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:54,124 - DEBUG - echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts 2024-09-11 07:03:54,324 - DEBUG - None 2024-09-11 07:03:54,324 - DEBUG - Running remote_cmd, Cmd : echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts, host_string: cirros@169.254.0.4, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:54,324 - DEBUG - echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts 2024-09-11 07:03:54,521 - DEBUG - None 2024-09-11 07:03:54,521 - DEBUG - Running remote_cmd, Cmd : echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts, host_string: cirros@169.254.0.5, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:54,521 - DEBUG - echo 0 > /proc/sys/net/ipv4/icmp_echo_ignore_broadcasts 2024-09-11 07:03:55,222 - DEBUG - None 2024-09-11 07:03:55,223 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 31.1.1.7, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:55,223 - DEBUG - ping -s 56 -c 3 -W 1 31.1.1.7 2024-09-11 07:03:57,468 - DEBUG - PING 31.1.1.7 (31.1.1.7): 56 data bytes 64 bytes from 31.1.1.4: seq=0 ttl=64 time=2.055 ms 64 bytes from 31.1.1.3: seq=0 ttl=64 time=7.373 ms (DUP!) 64 bytes from 31.1.1.4: seq=1 ttl=64 time=0.414 ms 64 bytes from 31.1.1.3: seq=1 ttl=64 time=2.012 ms (DUP!) 64 bytes from 31.1.1.4: seq=2 ttl=64 time=0.359 ms --- 31.1.1.7 ping statistics --- 3 packets transmitted, 3 packets received, 2 duplicates, 0% packet loss round-trip min/avg/max = 0.359/2.442/7.373 ms 2024-09-11 07:03:57,468 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 224.0.0.1, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:57,468 - DEBUG - ping -s 56 -c 3 -W 1 224.0.0.1 2024-09-11 07:03:59,728 - DEBUG - PING 224.0.0.1 (224.0.0.1): 56 data bytes 64 bytes from 31.1.1.4: seq=0 ttl=64 time=1.102 ms 64 bytes from 31.1.2.4: seq=0 ttl=63 time=3.711 ms (DUP!) 64 bytes from 31.1.1.3: seq=0 ttl=64 time=4.756 ms (DUP!) 64 bytes from 31.1.1.4: seq=1 ttl=64 time=0.396 ms 64 bytes from 31.1.2.4: seq=1 ttl=63 time=2.034 ms (DUP!) 64 bytes from 31.1.1.3: seq=1 ttl=64 time=3.498 ms (DUP!) 64 bytes from 31.1.1.4: seq=2 ttl=64 time=0.426 ms --- 224.0.0.1 ping statistics --- 3 packets transmitted, 3 packets received, 4 duplicates, 0% packet loss round-trip min/avg/max = 0.396/2.274/4.756 ms 2024-09-11 07:03:59,729 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 255.255.255.255, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.12, gateway password: c0ntrail123 2024-09-11 07:03:59,729 - DEBUG - ping -s 56 -c 3 -W 1 255.255.255.255 2024-09-11 07:04:02,007 - DEBUG - PING 255.255.255.255 (255.255.255.255): 56 data bytes 64 bytes from 31.1.1.4: seq=0 ttl=64 time=0.756 ms 64 bytes from 31.1.2.4: seq=0 ttl=63 time=2.971 ms (DUP!) 64 bytes from 31.1.1.3: seq=0 ttl=64 time=3.921 ms (DUP!) 64 bytes from 31.1.1.4: seq=1 ttl=64 time=0.745 ms 64 bytes from 31.1.2.4: seq=1 ttl=63 time=2.144 ms (DUP!) 64 bytes from 31.1.1.3: seq=1 ttl=64 time=3.329 ms (DUP!) 64 bytes from 31.1.1.4: seq=2 ttl=64 time=0.481 ms --- 255.255.255.255 ping statistics --- 3 packets transmitted, 3 packets received, 4 duplicates, 0% packet loss round-trip min/avg/max = 0.481/2.049/3.921 ms 2024-09-11 07:04:02,008 - INFO - Deleting VM ctest-TestBasicVMVN-26438550-17362776 2024-09-11 07:04:02,082 - INFO - Detaching port 6cc91176-a98b-4433-beb2-53657ef2cc12 from VM ctest-TestBasicVMVN-26438550-65539910 2024-09-11 07:04:02,142 - INFO - Deleting VM ctest-TestBasicVMVN-26438550-65539910 2024-09-11 07:04:02,213 - INFO - Detaching port 33b3f7d9-af99-4a1f-a47e-1e2cb899391a from VM ctest-TestBasicVMVN-26438550-89532877 2024-09-11 07:04:02,249 - INFO - Deleting VM ctest-TestBasicVMVN-26438550-89532877 2024-09-11 07:04:02,338 - INFO - Deleting VN ctest-vn-75195116 2024-09-11 07:04:02,531 - DEBUG - Response for delete_port : () 2024-09-11 07:04:02,773 - DEBUG - Response for delete_port : () 2024-09-11 07:04:02,835 - DEBUG - VN ed34094c-c3d6-462f-8c88-28c808d61420 still in use: Unable to complete operation on network ed34094c-c3d6-462f-8c88-28c808d61420. There are one or more ports still in use on the network. Neutron server returns request_ids: ['req-7fb014f7-36e7-4210-a40f-c5ea9c55dbaa'] 2024-09-11 07:04:02,835 - WARNING - Deleting VN ctest-vn-75195116 failed..Will retry 2024-09-11 07:04:04,990 - DEBUG - Response for deleting network () 2024-09-11 07:04:04,990 - DEBUG - Requesting: http://10.0.0.12:8082/routing-instance/0a0c97a1-1ed9-46ce-990b-f149dbd4bf79 2024-09-11 07:04:04,996 - DEBUG - Response Code: 404 2024-09-11 07:04:04,997 - DEBUG - Requesting: http://10.0.0.12:8082/domains 2024-09-11 07:04:05,003 - DEBUG - Requesting: http://10.0.0.12:8082/domain/e5789681-1145-42b1-8757-ad577d040188 2024-09-11 07:04:05,058 - DEBUG - Requesting: http://10.0.0.12:8082/project/7271f648-2d71-4c07-ade0-7446368c7662 2024-09-11 07:04:05,137 - INFO - Validated that VN ctest-vn-75195116 is not found in API Server 2024-09-11 07:04:05,150 - DEBUG - VN ctest-vn-75195116 is not present in Agent 10.0.0.12 2024-09-11 07:04:05,150 - INFO - Validated that VN ctest-vn-75195116 is not in any agent 2024-09-11 07:04:05,156 - DEBUG - VRF 2 is not seen in agent 10.0.0.12 2024-09-11 07:04:05,162 - DEBUG - Vrouter 10.0.0.12 does not have vrf 2 for VN ctest-vn-75195116 2024-09-11 07:04:05,162 - INFO - Validated that all vrouters do not have the route table for VN default-domain:ctest-TestBasicVMVN-26438550:ctest-vn-75195116 2024-09-11 07:04:05,174 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn-75195116 info 2024-09-11 07:04:05,271 - INFO - IPAM: ctest-ipam-18761562 is not found in API Server 2024-09-11 07:04:05,286 - INFO - IPAM:ctest-ipam-18761562 is not found in control node 2024-09-11 07:04:05,551 - DEBUG - No XMPP flaps were noticed during the test
2024-09-11 07:04:05,551 - INFO - END TEST : test_ping_within_vn_two_vms_two_different_subnets : PASSED[0:00:44]
2024-09-11 07:04:05,551 - INFO - -------------------------------------------------------------------------------- 2024-09-11 07:04:06,372 - INFO - Deleted project: ctest-TestBasicVMVN-26438550, ID : 7271f648-2d71-4c07-ade0-7446368c7662