]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-1)
2025-08-11 02:31:03,204 - DEBUG - Image by name ubuntu not found
2025-08-11 02:31:03,204 - DEBUG - Installing image ubuntu
2025-08-11 02:31:03,204 - DEBUG - Image info {'name': 'ubuntu.vmdk.gz', 'webserver': '', 'location': '/images/converts/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_tiny', '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-08-11 02:31:03,205 - DEBUG - Image build path file:///contrail-test/images/ubuntu.vmdk.gz
2025-08-11 02:31:03,205 - DEBUG - Download image from local file file:///contrail-test/images/ubuntu.vmdk.gz
2025-08-11 02:31:03,205 - DEBUG - Unzip image
2025-08-11 02:31:03,205 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu.vmdk.gz
2025-08-11 02:31:03,224 - INFO - image /contrail-test/images/ubuntu.vmdk is not found
2025-08-11 02:31:03,225 - INFO - Skip interface_detach for VM ctest-vm2-16962275 in state BUILD
2025-08-11 02:31:03,225 - INFO - Deleting VM ctest-vm2-16962275
2025-08-11 02:31:03,226 - ERROR - VM ctest-vm2-16962275 has failed to come up
2025-08-11 02:31:03,226 - ERROR - Nova failed to get host of the VM
2025-08-11 02:31:03,227 - ERROR - VM ctest-vm2-16962275 has failed to come up
2025-08-11 02:31:03,227 - ERROR - Nova failed to get host of the VM
2025-08-11 02:31:03,502 - INFO - Skip interface_detach for VM ctest-vm1-01777654 in state BUILD
2025-08-11 02:31:03,502 - INFO - Deleting VM ctest-vm1-01777654
2025-08-11 02:31:03,502 - ERROR - VM ctest-vm1-01777654 has failed to come up
2025-08-11 02:31:03,502 - ERROR - Nova failed to get host of the VM
2025-08-11 02:31:03,502 - ERROR - VM ctest-vm1-01777654 has failed to come up
2025-08-11 02:31:03,502 - ERROR - Nova failed to get host of the VM
2025-08-11 02:31:03,755 - DEBUG - Response for delete_port : ()
2025-08-11 02:31:04,008 - DEBUG - Response for delete_port : ()
2025-08-11 02:31:04,008 - INFO - Deleting VN ctest-vn1-73251625
2025-08-11 02:31:04,242 - DEBUG - Response for deleting network ()
2025-08-11 02:31:05,589 - DEBUG - No XMPP flaps were noticed during the test
2025-08-11 02:31:05,589 - INFO -
2025-08-11 02:31:05,589 - INFO - END TEST : test_aap_with_zero_mac : SKIPPED[0:00:06]
2025-08-11 02:31:05,589 - INFO - --------------------------------------------------------------------------------
2025-08-11 02:31:05,592 - INFO - ================================================================================
2025-08-11 02:31:05,592 - INFO - STARTING TEST : test_ports_bindings
2025-08-11 02:31:05,592 - INFO - TEST DESCRIPTION :
Verify that we are able to create a port with custom port bindings
Steps:
1) Create Port with Port bindings profile set to {'foo': 'bar'}
2) Retrieve and verify the same is set
2025-08-11 02:31:06,886 - DEBUG - Nothing to compare xmpp stats {'10.0.0.57': {'10.20.0.18': '0', '10.20.0.129': '0'}, '10.0.0.65': {'10.20.0.129': '0', '10.20.0.25': '0'}} with
2025-08-11 02:31:06,886 - INFO - Initial checks done. Running the testcase now
2025-08-11 02:31:06,886 - INFO -
2025-08-11 02:31:07,186 - DEBUG - Response for create_network : {'network': {'id': '60b8e087-8501-4990-99b5-4ab68fe8cdd6', 'name': 'ctest-vn-36610625', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'project_id': '2795e46355ca4136b3ac3d0d124081a5', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-56721828', 'ctest-vn-36610625'], 'port_security_enabled': True, 'description': ''}}
2025-08-11 02:31:07,461 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c96c4a72-915d-40c3-b762-40ca5af5bff4', 'name': '', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '60b8e087-8501-4990-99b5-4ab68fe8cdd6', 'ip_version': 4, 'cidr': '92.206.45.0/26', 'allocation_pools': [{'start': '92.206.45.2', 'end': '92.206.45.62'}], 'gateway_ip': '92.206.45.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '92.206.45.2', 'tags': [], 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:07,482 - INFO - Created VN ctest-vn-36610625
2025-08-11 02:31:07,493 - DEBUG - VN ctest-vn-36610625 UUID is 60b8e087-8501-4990-99b5-4ab68fe8cdd6
2025-08-11 02:31:07,566 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestPorts-56721828', 'ctest-vmi-33327276']}
2025-08-11 02:31:07,892 - DEBUG - Response for create_port : {'port': {'name': 'ctest-vmi-33327276', 'id': '4ff7a9f0-9380-4a9b-af29-e1394acee314', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '60b8e087-8501-4990-99b5-4ab68fe8cdd6', 'mac_address': '02:4f:f7:a9:f0:93', 'binding:profile': {'foo': 'bar'}, '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': '92.206.45.3', 'subnet_id': 'c96c4a72-915d-40c3-b762-40ca5af5bff4'}], 'security_groups': ['aaaaf479-4c2a-4694-82fa-d6da0627baeb'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:07,892 - DEBUG - Created port 4ff7a9f0-9380-4a9b-af29-e1394acee314
2025-08-11 02:31:07,966 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/4ff7a9f0-9380-4a9b-af29-e1394acee314
2025-08-11 02:31:07,980 - INFO - VMI 4ff7a9f0-9380-4a9b-af29-e1394acee314 verification in API Server passed
2025-08-11 02:31:08,122 - DEBUG - Response for delete_port : ()
2025-08-11 02:31:08,122 - INFO - Deleted port 4ff7a9f0-9380-4a9b-af29-e1394acee314
2025-08-11 02:31:08,122 - INFO - Deleting VN ctest-vn-36610625
2025-08-11 02:31:08,275 - DEBUG - Response for deleting network ()
2025-08-11 02:31:09,555 - DEBUG - No XMPP flaps were noticed during the test
2025-08-11 02:31:09,555 - INFO - END TEST : test_ports_bindings : PASSED[0:00:04]
2025-08-11 02:31:09,555 - INFO - --------------------------------------------------------------------------------
2025-08-11 02:31:09,559 - INFO - ================================================================================
2025-08-11 02:31:09,559 - INFO - STARTING TEST : test_ports_specific_subnet_ip
2025-08-11 02:31:09,559 - INFO - TEST DESCRIPTION : Create ports with specific Subnet and IP
Create two ports in a VN with 2 subnets and specific IPs
Attach to two VMs
Ping between them should pass
2025-08-11 02:31:10,806 - DEBUG - Nothing to compare xmpp stats {'10.0.0.57': {'10.20.0.18': '0', '10.20.0.129': '0'}, '10.0.0.65': {'10.20.0.129': '0', '10.20.0.25': '0'}} with
2025-08-11 02:31:10,806 - INFO - Initial checks done. Running the testcase now
2025-08-11 02:31:10,806 - INFO -
2025-08-11 02:31:11,091 - DEBUG - Response for create_network : {'network': {'id': '178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8', 'name': 'ctest-vn1-44150045', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'project_id': '2795e46355ca4136b3ac3d0d124081a5', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-56721828', 'ctest-vn1-44150045'], 'port_security_enabled': True, 'description': ''}}
2025-08-11 02:31:11,340 - DEBUG - Response for create_subnet : {'subnet': {'id': 'c6e21321-3ef9-4e4c-855c-103e05c9ec24', 'name': '', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8', 'ip_version': 4, 'cidr': '99.52.94.64/26', 'allocation_pools': [{'start': '99.52.94.66', 'end': '99.52.94.126'}], 'gateway_ip': '99.52.94.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '99.52.94.66', 'tags': [], 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:11,611 - DEBUG - Response for create_subnet : {'subnet': {'id': '15be47bd-8c31-451b-b258-3f8b0933f528', 'name': '', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8', 'ip_version': 4, 'cidr': '149.33.51.192/26', 'allocation_pools': [{'start': '149.33.51.194', 'end': '149.33.51.254'}], 'gateway_ip': '149.33.51.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '149.33.51.194', 'tags': [], 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:11,635 - INFO - Created VN ctest-vn1-44150045
2025-08-11 02:31:11,723 - DEBUG - VN ctest-vn1-44150045 UUID is 178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8
2025-08-11 02:31:12,060 - DEBUG - Response for create_port : {'port': {'name': '473810ff-a75d-41c0-8a51-48c76bf819b3', 'id': '473810ff-a75d-41c0-8a51-48c76bf819b3', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8', 'mac_address': '02:47:38:10:ff:a7', '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': '99.52.94.69', 'subnet_id': 'c6e21321-3ef9-4e4c-855c-103e05c9ec24'}], 'security_groups': ['aaaaf479-4c2a-4694-82fa-d6da0627baeb'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:12,360 - DEBUG - Response for create_port : {'port': {'name': '4ce83eda-43a4-4112-ba4b-33a82328f6b4', 'id': '4ce83eda-43a4-4112-ba4b-33a82328f6b4', 'tenant_id': '2795e46355ca4136b3ac3d0d124081a5', 'network_id': '178ff6cd-2ee2-4dfd-aeab-e8dcac4e13d8', 'mac_address': '02:4c:e8:3e:da:43', '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': '149.33.51.197', 'subnet_id': '15be47bd-8c31-451b-b258-3f8b0933f528'}], 'security_groups': ['aaaaf479-4c2a-4694-82fa-d6da0627baeb'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'port_security_enabled': True, 'description': '', 'project_id': '2795e46355ca4136b3ac3d0d124081a5'}}
2025-08-11 02:31:12,763 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-1)
2025-08-11 02:31:13,202 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3794-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3794-2)
2025-08-11 02:31:13,202 - INFO - Waiting for VM ctest-vn1-vm1-76061125 to be up..
2025-08-11 02:31:13,274 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-08-11 02:31:18,348 - DEBUG - VM is in ACTIVE state now
2025-08-11 02:31:18,348 - INFO - VM name : ctest-vn1-vm1-76061125
2025-08-11 02:31:18,419 - DEBUG - VM ctest-vn1-vm1-76061125 ID is 3309b044-133b-4968-968f-fbf697c6ea2f
2025-08-11 02:31:18,419 - DEBUG - VM ctest-vn1-vm1-76061125 launched on Node an-jenkins-deploy-platform-ansible-os-3794-1
2025-08-11 02:31:18,498 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/3309b044-133b-4968-968f-fbf697c6ea2f
2025-08-11 02:31:18,510 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/473810ff-a75d-41c0-8a51-48c76bf819b3
2025-08-11 02:31:21,731 - 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 1012ms')
2025-08-11 02:31:21,732 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-76061125 failed!
2025-08-11 02:31:21,747 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-56721828:ctest-vn1-44150045 is 99.52.94.65 and allocation pool is NOT set
2025-08-11 02:31:21,747 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-56721828:ctest-vn1-44150045 is 149.33.51.193 and allocation pool is NOT set
2025-08-11 02:31:23,807 - 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.21 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.26 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 = 1.258/2.736/4.214/1.478 ms')
2025-08-11 02:31:23,807 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm1-76061125 passed
2025-08-11 02:31:23,931 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:23,931 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-76061125, IP 99.52.94.69, Port 22
2025-08-11 02:31:23,998 - 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': ''}
2025-08-11 02:31:24,069 - DEBUG - VM ctest-vn1-vm1-76061125 is NOT ready for SSH connections, VM status: ACTIVE
2025-08-11 02:31:29,070 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:29,070 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-76061125, IP 99.52.94.69, Port 22
2025-08-11 02:31:29,232 - DEBUG - VM ctest-vn1-vm1-76061125 is ready for SSH connections
2025-08-11 02:31:29,232 - INFO - Waiting for VM ctest-vn1-vm2-75072302 to be up..
2025-08-11 02:31:29,303 - DEBUG - VM is in ACTIVE state now
2025-08-11 02:31:29,303 - INFO - VM name : ctest-vn1-vm2-75072302
2025-08-11 02:31:29,404 - DEBUG - VM ctest-vn1-vm2-75072302 ID is 960aa5f1-e7c9-4cd4-9ffa-131f48640956
2025-08-11 02:31:29,404 - DEBUG - VM ctest-vn1-vm2-75072302 launched on Node an-jenkins-deploy-platform-ansible-os-3794-2
2025-08-11 02:31:29,481 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine/960aa5f1-e7c9-4cd4-9ffa-131f48640956
2025-08-11 02:31:29,492 - DEBUG - Requesting: http://10.0.0.141:8082/virtual-machine-interface/4ce83eda-43a4-4112-ba4b-33a82328f6b4
2025-08-11 02:31:30,683 - 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=3.08 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.294 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.294/1.689/3.084/1.395 ms')
2025-08-11 02:31:30,683 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm2-75072302 passed
2025-08-11 02:31:30,795 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:30,795 - DEBUG - Waiting to SSH to VM ctest-vn1-vm2-75072302, IP 149.33.51.197, Port 22
2025-08-11 02:31:30,948 - DEBUG - VM ctest-vn1-vm2-75072302 is ready for SSH connections
2025-08-11 02:31:30,948 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:30,949 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:30,949 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-08-11 02:31:30,949 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 99.52.94.69, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.65, gateway password: c0ntrail123
2025-08-11 02:31:30,949 - DEBUG - ping -s 56 -c 3 -W 1 99.52.94.69
2025-08-11 02:31:34,820 - DEBUG - PING 99.52.94.69 (99.52.94.69): 56 data bytes
64 bytes from 99.52.94.69: seq=0 ttl=63 time=5.542 ms
64 bytes from 99.52.94.69: seq=1 ttl=63 time=0.934 ms
64 bytes from 99.52.94.69: seq=2 ttl=63 time=0.947 ms
--- 99.52.94.69 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.934/2.474/5.542 ms
2025-08-11 02:31:34,820 - INFO - Ping to IP 99.52.94.69 from VM ctest-vn1-vm2-75072302 passed
2025-08-11 02:31:34,820 - INFO - Detaching port 4ce83eda-43a4-4112-ba4b-33a82328f6b4 from VM ctest-vn1-vm2-75072302
2025-08-11 02:31:34,864 - INFO - Deleting VM ctest-vn1-vm2-75072302
2025-08-11 02:31:34,922 - INFO - Detaching port 473810ff-a75d-41c0-8a51-48c76bf819b3 from VM ctest-vn1-vm1-76061125
2025-08-11 02:31:34,947 - INFO - Deleting VM ctest-vn1-vm1-76061125
2025-08-11 02:31:35,210 - DEBUG - Response for delete_port : ()
2025-08-11 02:31:35,414 - DEBUG - Response for delete_port : ()
2025-08-11 02:31:35,414 - INFO - Deleting VN ctest-vn1-44150045
2025-08-11 02:31:35,588 - DEBUG - Response for deleting network ()
2025-08-11 02:31:37,507 - DEBUG - No XMPP flaps were noticed during the test
2025-08-11 02:31:37,507 - INFO - END TEST : test_ports_specific_subnet_ip : PASSED[0:00:28]
2025-08-11 02:31:37,507 - INFO - --------------------------------------------------------------------------------
2025-08-11 02:31:38,534 - INFO - Deleted project: ctest-TestPorts-56721828, ID : 2795e463-55ca-4136-b3ac-3d0d124081a5