2026-10-20 13:22:41,561 - INFO - Domain Default found not creating
2026-10-20 13:22:41,747 - INFO - Project ctest-TestPorts-29872883 not found, creating it
2026-10-20 13:22:42,226 - INFO - Created Project:ctest-TestPorts-29872883, ID : a2cb3947-c911-401b-89b7-c85d28f8fa40
2026-10-20 13:22:43,952 - INFO - ================================================================================
2026-10-20 13:22:43,952 - INFO - STARTING TEST : test_ports_bindings
2026-10-20 13:22:43,952 - 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
2026-10-20 13:22:44,217 - DEBUG - Nothing to compare xmpp stats {'10.0.0.186': {'10.20.0.25': '0'}} with
2026-10-20 13:22:44,218 - INFO - Initial checks done. Running the testcase now
2026-10-20 13:22:44,218 - INFO -
2026-10-20 13:22:44,825 - DEBUG - Response for create_network : {'network': {'id': '721cb434-f8a2-47af-8f38-10a0a34cca20', 'name': 'ctest-vn-07943905', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-29872883', 'ctest-vn-07943905'], 'port_security_enabled': True, 'description': ''}}
2026-10-20 13:22:45,014 - DEBUG - Response for create_subnet : {'subnet': {'id': '0406cec4-b532-4da1-b696-3bf07872fbe5', 'name': '', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'network_id': '721cb434-f8a2-47af-8f38-10a0a34cca20', 'ip_version': 4, 'cidr': '195.229.134.64/26', 'allocation_pools': [{'start': '195.229.134.66', 'end': '195.229.134.126'}], 'gateway_ip': '195.229.134.65', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '195.229.134.66', 'tags': [], 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40'}}
2026-10-20 13:22:45,032 - INFO - Created VN ctest-vn-07943905
2026-10-20 13:22:45,087 - DEBUG - VN ctest-vn-07943905 UUID is 721cb434-f8a2-47af-8f38-10a0a34cca20
2026-10-20 13:22:45,196 - DEBUG - Read virtual machine interface {'fq_name': ['default-domain', 'ctest-TestPorts-29872883', 'ctest-vmi-36708223']}
2026-10-20 13:22:45,307 - ERROR - Neutron Exception while creating port in vn with id 721cb434-f8a2-47af-8f38-10a0a34cca20
Traceback (most recent call last):
File "/contrail-test/fixtures/port_fixture.py", line 85, in setUp
obj = self.vnc_h.read_virtual_machine_interface(fq_name=self.fq_name)
File "/contrail-test/fixtures/contrailapi.py", line 3169, in read_virtual_machine_interface
return self._vnc.virtual_machine_interface_read(**kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 52, in wrapper
return func(self, *args, **kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 700, in _object_read
(args_ok, result) = self._read_args_to_id(
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1114, in _read_args_to_id
return (True, self.fq_name_to_id(res_type, fq_name))
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 52, in wrapper
return func(self, *args, **kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1395, in fq_name_to_id
content = self._request_server(OP_POST, uri, data=json_body)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1126, in _request_server
return self._request(
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1180, in _request
raise NoIdError('Error: oper %s url %s body %s response %s'
vnc_api.exceptions.NoIdError: Unknown id: Error: oper 1 url /fqname-to-id body {"type": "virtual-machine-interface", "fq_name": ["default-domain", "ctest-TestPorts-29872883", "ctest-vmi-36708223"]} response Name ['default-domain', 'ctest-TestPorts-29872883', 'ctest-vmi-36708223'] not found
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/contrail-test/fixtures/quantum_test.py", line 167, in create_port
port_rsp = self.obj.create_port({'port': port_req_dict})
File "/usr/local/lib/python3.9/site-packages/neutronclient/v2_0/client.py", line 803, in create_port
return self.post(self.ports_path, body=body)
File "/usr/local/lib/python3.9/site-packages/neutronclient/v2_0/client.py", line 358, in post
return self.do_request("POST", action, body=body,
File "/usr/local/lib/python3.9/site-packages/neutronclient/v2_0/client.py", line 294, in do_request
self._handle_fault_response(status_code, replybody, resp)
File "/usr/local/lib/python3.9/site-packages/neutronclient/v2_0/client.py", line 269, in _handle_fault_response
exception_handler_v20(status_code, error_body)
File "/usr/local/lib/python3.9/site-packages/neutronclient/v2_0/client.py", line 91, in exception_handler_v20
raise client_exc(message=error_message,
neutronclient.common.exceptions.Forbidden: (rule:create_port and rule:create_port:binding:profile) is disallowed by policy
Neutron server returns request_ids: ['req-73513532-7e4b-457e-a6a6-6445ef8ed69d']
2026-10-20 13:22:45,311 - INFO - Deleting VN ctest-vn-07943905
2026-10-20 13:22:45,416 - DEBUG - Response for deleting network ()
2026-10-20 13:22:45,677 - ERROR - TypeError
Python 3.9.25: /usr/bin/python3
Tue Oct 20 13:22:45 2026
A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
78 log.info('Initial checks done. Running the testcase now')
79 log.info('')
80 result = function(self, *args, **kwargs)
81 if self.inputs.upgrade:
82 pid = os.getpid()
result = None
function =
self =
args = ()
kwargs = {}
/contrail-test/scripts/neutron/test_ports.py in test_ports_bindings(self=)
1202 bind_dict = {'foo': 'bar'}
1203 vn = self.create_vn()
1204 port = self.useFixture(PortFixture(vn.uuid, connections=self.connections,
1205 binding_profile=bind_dict))
1206 assert port.verify_on_setup(), 'VMI %s verification has failed'%port.uuid
port undefined
self =
self.useFixture = >
global PortFixture =
vn =
vn.uuid = '721cb434-f8a2-47af-8f38-10a0a34cca20'
connections undefined
self.connections =
binding_profile undefined
bind_dict = {'foo': 'bar'}
/usr/local/lib/python3.9/site-packages/testtools/testcase.py in useFixture(self=, fixture=)
754 # Gather_details worked, so raise the exception setUp
755 # encountered.
756 reraise(*exc_info)
757 else:
758 self.addCleanup(fixture.cleanUp)
global reraise =
exc_info = (, TypeError("'NoneType' object is not subscriptable"), )
/usr/local/lib/python3.9/site-packages/testtools/_compat3x.py in reraise(exc_class=, exc_obj=TypeError("'NoneType' object is not subscriptable"), exc_tb=, _marker=)
13
14 def reraise(exc_class, exc_obj, exc_tb, _marker=object()):
15 """Re-raise an exception received from sys.exc_info() or similar."""
16 raise exc_obj.with_traceback(exc_tb)
17
exc_obj = TypeError("'NoneType' object is not subscriptable")
exc_obj.with_traceback =
exc_tb =
/usr/local/lib/python3.9/site-packages/testtools/testcase.py in useFixture(self=, fixture=)
729 """
730 try:
731 fixture.setUp()
732 except MultipleExceptions as e:
733 if (fixtures is not None and
fixture =
fixture.setUp = >
/contrail-test/fixtures/port_fixture.py in setUp(self=)
88 self.vn_obj = self.vnc_api_h.virtual_network_read(id=self.vn_id)
89 if self.api_type == 'neutron':
90 self._neutron_create_port()
91 else:
92 self._contrail_create_port()
self =
self._neutron_create_port = >
/contrail-test/fixtures/port_fixture.py in _neutron_create_port(self=)
108 binding_profile=self.binding_profile)
109 self.neutron_obj = neutron_obj
110 self.uuid = neutron_obj['id']
111
112 def _contrail_create_port(self):
self =
self.uuid = None
neutron_obj = None
TypeError: 'NoneType' object is not subscriptable
__cause__ = None
__class__ =
__context__ = NoIdError('Error: oper 1 url /fqname-to-id body ...s-29872883\', \'ctest-vmi-36708223\'] not found')
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = 'Inappropriate argument type.'
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
args = ("'NoneType' object is not subscriptable",)
with_traceback =
The above is a description of an error in a Python program. Here is
the original traceback:
Traceback (most recent call last):
File "/contrail-test/fixtures/port_fixture.py", line 85, in setUp
obj = self.vnc_h.read_virtual_machine_interface(fq_name=self.fq_name)
File "/contrail-test/fixtures/contrailapi.py", line 3169, in read_virtual_machine_interface
return self._vnc.virtual_machine_interface_read(**kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 52, in wrapper
return func(self, *args, **kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 700, in _object_read
(args_ok, result) = self._read_args_to_id(
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1114, in _read_args_to_id
return (True, self.fq_name_to_id(res_type, fq_name))
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 52, in wrapper
return func(self, *args, **kwargs)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1395, in fq_name_to_id
content = self._request_server(OP_POST, uri, data=json_body)
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1126, in _request_server
return self._request(
File "/usr/local/lib/python3.9/site-packages/vnc_api/vnc_api.py", line 1180, in _request
raise NoIdError('Error: oper %s url %s body %s response %s'
vnc_api.exceptions.NoIdError: Unknown id: Error: oper 1 url /fqname-to-id body {"type": "virtual-machine-interface", "fq_name": ["default-domain", "ctest-TestPorts-29872883", "ctest-vmi-36708223"]} response Name ['default-domain', 'ctest-TestPorts-29872883', 'ctest-vmi-36708223'] not found
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/neutron/test_ports.py", line 1204, in test_ports_bindings
port = self.useFixture(PortFixture(vn.uuid, connections=self.connections,
File "/usr/local/lib/python3.9/site-packages/testtools/testcase.py", line 756, in useFixture
reraise(*exc_info)
File "/usr/local/lib/python3.9/site-packages/testtools/_compat3x.py", line 16, in reraise
raise exc_obj.with_traceback(exc_tb)
File "/usr/local/lib/python3.9/site-packages/testtools/testcase.py", line 731, in useFixture
fixture.setUp()
File "/contrail-test/fixtures/port_fixture.py", line 90, in setUp
self._neutron_create_port()
File "/contrail-test/fixtures/port_fixture.py", line 110, in _neutron_create_port
self.uuid = neutron_obj['id']
TypeError: 'NoneType' object is not subscriptable
2026-10-20 13:22:45,684 - DEBUG - No XMPP flaps were noticed during the test
2026-10-20 13:22:45,684 - INFO -
2026-10-20 13:22:45,684 - INFO - END TEST : test_ports_bindings : FAILED[0:00:02]
2026-10-20 13:22:45,684 - INFO - --------------------------------------------------------------------------------
2026-10-20 13:22:45,687 - INFO - ================================================================================
2026-10-20 13:22:45,687 - INFO - STARTING TEST : test_ports_specific_subnet_ip
2026-10-20 13:22:45,687 - 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
2026-10-20 13:22:45,980 - DEBUG - Nothing to compare xmpp stats {'10.0.0.186': {'10.20.0.25': '0'}} with
2026-10-20 13:22:45,980 - INFO - Initial checks done. Running the testcase now
2026-10-20 13:22:45,980 - INFO -
2026-10-20 13:22:46,167 - DEBUG - Response for create_network : {'network': {'id': '84afa9b1-4d85-4a65-8d7b-3100d1350c65', 'name': 'ctest-vn1-85989064', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'tags': [], 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestPorts-29872883', 'ctest-vn1-85989064'], 'port_security_enabled': True, 'description': ''}}
2026-10-20 13:22:46,373 - DEBUG - Response for create_subnet : {'subnet': {'id': '1f0b93a0-b5e9-4ccb-84f7-271e2addf785', 'name': '', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'network_id': '84afa9b1-4d85-4a65-8d7b-3100d1350c65', 'ip_version': 4, 'cidr': '205.103.1.192/26', 'allocation_pools': [{'start': '205.103.1.194', 'end': '205.103.1.254'}], 'gateway_ip': '205.103.1.193', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '205.103.1.194', 'tags': [], 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40'}}
2026-10-20 13:22:46,558 - DEBUG - Response for create_subnet : {'subnet': {'id': 'e708fcb9-004d-4288-a420-dd90b71084bf', 'name': '', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'network_id': '84afa9b1-4d85-4a65-8d7b-3100d1350c65', 'ip_version': 4, 'cidr': '33.139.199.128/26', 'allocation_pools': [{'start': '33.139.199.130', 'end': '33.139.199.190'}], 'gateway_ip': '33.139.199.129', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '33.139.199.130', 'tags': [], 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40'}}
2026-10-20 13:22:46,576 - INFO - Created VN ctest-vn1-85989064
2026-10-20 13:22:46,627 - DEBUG - VN ctest-vn1-85989064 UUID is 84afa9b1-4d85-4a65-8d7b-3100d1350c65
2026-10-20 13:22:46,950 - DEBUG - Response for create_port : {'port': {'name': '949fb0b9-f2ee-4ef7-9631-2e395cb6d7a7', 'id': '949fb0b9-f2ee-4ef7-9631-2e395cb6d7a7', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'network_id': '84afa9b1-4d85-4a65-8d7b-3100d1350c65', 'mac_address': '02:94:9f:b0:b9:f2', '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': '205.103.1.197', 'subnet_id': '1f0b93a0-b5e9-4ccb-84f7-271e2addf785'}], 'security_groups': ['2669b75e-ea52-4e21-9564-fa73d4976f49'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'tags': [], 'port_security_enabled': True, 'description': '', 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40'}}
2026-10-20 13:22:47,142 - DEBUG - Response for create_port : {'port': {'name': '6581a184-a087-4e6a-981a-b3b409dea72b', 'id': '6581a184-a087-4e6a-981a-b3b409dea72b', 'tenant_id': 'a2cb3947c911401b89b7c85d28f8fa40', 'network_id': '84afa9b1-4d85-4a65-8d7b-3100d1350c65', 'mac_address': '02:65:81:a1:84:a0', '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': '33.139.199.133', 'subnet_id': 'e708fcb9-004d-4288-a420-dd90b71084bf'}], 'security_groups': ['2669b75e-ea52-4e21-9564-fa73d4976f49'], 'admin_state_up': True, 'device_id': '', 'device_owner': '', 'status': 'DOWN', 'tags': [], 'port_security_enabled': True, 'description': '', 'project_id': 'a2cb3947c911401b89b7c85d28f8fa40'}}
2026-10-20 13:22:47,200 - DEBUG - Services list from nova: [, , ]
2026-10-20 13:22:47,563 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6373-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6373-1)
2026-10-20 13:22:47,970 - INFO - VM ([]) created on node: (cn-jenkins-deploy-platform-ansible-os-6373-1), Zone: (nova:cn-jenkins-deploy-platform-ansible-os-6373-1)
2026-10-20 13:22:47,970 - INFO - Waiting for VM ctest-vn1-vm1-72221386 to be up..
2026-10-20 13:22:48,012 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:22:53,061 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:22:58,148 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:03,231 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:08,318 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:13,401 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:18,485 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:23,566 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:28,666 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2026-10-20 13:23:33,751 - DEBUG - VM is in ACTIVE state now
2026-10-20 13:23:33,751 - INFO - VM name : ctest-vn1-vm1-72221386
2026-10-20 13:23:33,828 - DEBUG - VM ctest-vn1-vm1-72221386 ID is bf6f3de3-67fe-4b51-966b-c0b2d97eef6b
2026-10-20 13:23:33,850 - DEBUG - VM ctest-vn1-vm1-72221386 launched on Node cn-jenkins-deploy-platform-ansible-os-6373-1
2026-10-20 13:23:33,925 - DEBUG - Requesting: http://10.0.0.186:8082/virtual-machine/bf6f3de3-67fe-4b51-966b-c0b2d97eef6b
2026-10-20 13:23:34,295 - DEBUG - Requesting: http://10.0.0.186:8082/virtual-machine/bf6f3de3-67fe-4b51-966b-c0b2d97eef6b
2026-10-20 13:23:34,328 - DEBUG - Requesting: http://10.0.0.186:8082/virtual-machine-interface/949fb0b9-f2ee-4ef7-9631-2e395cb6d7a7
2026-10-20 13:23:37,596 - DEBUG - (True, 'PING 169.254.0.4 (169.254.0.4) 56(84) bytes of data.\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 0 received, 100% packet loss, time 1024ms')
2026-10-20 13:23:37,596 - DEBUG - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1-vm1-72221386 failed!
2026-10-20 13:23:37,651 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-29872883:ctest-vn1-85989064 is 205.103.1.193 and allocation pool is NOT set
2026-10-20 13:23:37,651 - DEBUG - Gateway for vn default-domain:ctest-TestPorts-29872883:ctest-vn1-85989064 is 33.139.199.129 and allocation pool is NOT set
2026-10-20 13:23:39,713 - 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.73 ms\r\n64 bytes from 169.254.0.4: icmp_seq=2 ttl=63 time=0.630 ms\r\n\r\n--- 169.254.0.4 ping statistics ---\r\n2 packets transmitted, 2 received, 0% packet loss, time 1001ms\r\nrtt min/avg/max/mdev = 0.630/2.178/3.727/1.548 ms')
2026-10-20 13:23:39,713 - INFO - Ping to Metadata IP 169.254.0.4 of VM ctest-vn1-vm1-72221386 passed
2026-10-20 13:23:39,867 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:23:39,867 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:23:39,934 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:23:40,016 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:23:45,017 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:23:45,017 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:23:45,075 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:23:45,153 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:23:50,154 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:23:50,155 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:23:50,221 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:23:50,306 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:23:55,307 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:23:55,307 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:23:55,363 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:23:55,447 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:24:00,448 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:00,448 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:24:00,503 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:24:00,588 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:24:05,588 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:05,588 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:24:05,658 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:24:05,737 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:24:10,738 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:10,738 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:24:10,805 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:24:10,894 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:24:15,895 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:15,895 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:24:15,962 - DEBUG - Error on ssh to cirros@169.254.0.4:22, result: /bin/bash: connect: Connection refused
/bin/bash: line 1: /dev/tcp/169.254.0.4/22: Connection refused {'failed': True, 'command': '(echo > /dev/tcp/169.254.0.4/22)', 'real_command': '/bin/bash -l -c "(echo > /dev/tcp/169.254.0.4/22)"', 'return_code': 1, 'succeeded': False, 'stderr': ''}
2026-10-20 13:24:16,051 - DEBUG - VM ctest-vn1-vm1-72221386 is NOT ready for SSH connections, VM status: ACTIVE
2026-10-20 13:24:21,052 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:21,053 - DEBUG - Waiting to SSH to VM ctest-vn1-vm1-72221386, IP 205.103.1.197, Port 22
2026-10-20 13:24:21,222 - DEBUG - VM ctest-vn1-vm1-72221386 is ready for SSH connections
2026-10-20 13:24:21,222 - INFO - Waiting for VM ctest-vn1-vm2-42382517 to be up..
2026-10-20 13:24:21,297 - DEBUG - VM is in ACTIVE state now
2026-10-20 13:24:21,297 - INFO - VM name : ctest-vn1-vm2-42382517
2026-10-20 13:24:21,373 - DEBUG - VM ctest-vn1-vm2-42382517 ID is 4169d030-ef70-4b99-949b-554b45b5f114
2026-10-20 13:24:21,373 - DEBUG - VM ctest-vn1-vm2-42382517 launched on Node cn-jenkins-deploy-platform-ansible-os-6373-1
2026-10-20 13:24:21,451 - DEBUG - Requesting: http://10.0.0.186:8082/virtual-machine/4169d030-ef70-4b99-949b-554b45b5f114
2026-10-20 13:24:21,459 - DEBUG - Requesting: http://10.0.0.186:8082/virtual-machine-interface/6581a184-a087-4e6a-981a-b3b409dea72b
2026-10-20 13:24:22,697 - 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=2.52 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=0.451 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.451/1.485/2.519/1.034 ms')
2026-10-20 13:24:22,697 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1-vm2-42382517 passed
2026-10-20 13:24:22,851 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:22,851 - DEBUG - Waiting to SSH to VM ctest-vn1-vm2-42382517, IP 33.139.199.133, Port 22
2026-10-20 13:24:23,029 - DEBUG - VM ctest-vn1-vm2-42382517 is ready for SSH connections
2026-10-20 13:24:23,029 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:23,030 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:23,030 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2026-10-20 13:24:23,030 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 205.103.1.197, host_string: cirros@169.254.0.3, password: cubswin:)gateway: ubuntu@10.0.0.186, gateway password: c0ntrail123
2026-10-20 13:24:23,030 - DEBUG - ping -s 56 -c 3 -W 1 205.103.1.197
2026-10-20 13:24:27,038 - DEBUG - PING 205.103.1.197 (205.103.1.197): 56 data bytes
64 bytes from 205.103.1.197: seq=0 ttl=63 time=1.748 ms
64 bytes from 205.103.1.197: seq=1 ttl=63 time=0.914 ms
64 bytes from 205.103.1.197: seq=2 ttl=63 time=1.045 ms
--- 205.103.1.197 ping statistics ---
3 packets transmitted, 3 packets received, 0% packet loss
round-trip min/avg/max = 0.914/1.235/1.748 ms
2026-10-20 13:24:27,038 - INFO - Ping to IP 205.103.1.197 from VM ctest-vn1-vm2-42382517 passed
2026-10-20 13:24:27,039 - INFO - Detaching port 6581a184-a087-4e6a-981a-b3b409dea72b from VM ctest-vn1-vm2-42382517
2026-10-20 13:24:27,100 - INFO - Deleting VM ctest-vn1-vm2-42382517
2026-10-20 13:24:27,186 - INFO - Detaching port 949fb0b9-f2ee-4ef7-9631-2e395cb6d7a7 from VM ctest-vn1-vm1-72221386
2026-10-20 13:24:27,233 - INFO - Deleting VM ctest-vn1-vm1-72221386
2026-10-20 13:24:27,509 - DEBUG - Response for delete_port : ()
2026-10-20 13:24:27,682 - DEBUG - Response for delete_port : ()
2026-10-20 13:24:27,682 - INFO - Deleting VN ctest-vn1-85989064
2026-10-20 13:24:27,846 - DEBUG - Response for deleting network ()
2026-10-20 13:24:28,142 - DEBUG - No XMPP flaps were noticed during the test
2026-10-20 13:24:28,142 - INFO - END TEST : test_ports_specific_subnet_ip : PASSED[0:01:43]
2026-10-20 13:24:28,142 - INFO - --------------------------------------------------------------------------------
2026-10-20 13:24:29,348 - INFO - Deleted project: ctest-TestPorts-29872883, ID : a2cb3947-c911-401b-89b7-c85d28f8fa40