]
2025-07-22 16:00:09,615 - DEBUG - Image by name ubuntu-traffic-py3 not found
2025-07-22 16:00:09,615 - DEBUG - Installing image ubuntu-traffic-py3
2025-07-22 16:00:09,615 - DEBUG - Image info {'name': 'ubuntu-traffic-py3.qcow2.gz', 'webserver': '', 'location': '/images/converts/', 'username': 'ubuntu', 'password': 'ubuntu', 'type': 'os', 'flavor': 'contrail_flavor_small', 'params': '--container-format ovf --disk-format qcow2 --property hypervisor_type=qemu', 'name_docker': 'phusion-baseimage-enablesshd'}
2025-07-22 16:00:09,616 - DEBUG - Image build path http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic-py3.qcow2.gz
2025-07-22 16:00:09,616 - DEBUG - Download image from web http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic-py3.qcow2.gz
2025-07-22 16:00:09,631 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: wget -nv http://nexus.opensdn.io/repository///images/converts//ubuntu-traffic-py3.qcow2.gz -O /contrail-test/images/ubuntu-traffic-py3.qcow2.gz
2025-07-22 16:00:09,664 - DEBUG - Image has been downloaded to /contrail-test/images/ubuntu-traffic-py3.qcow2.gz
2025-07-22 16:00:09,664 - DEBUG - Unzip image
2025-07-22 16:00:09,664 - DEBUG - Image download (local=True) (proxy=None): Execute cmd: gunzip -f /contrail-test/images/ubuntu-traffic-py3.qcow2.gz
2025-07-22 16:00:09,679 - DEBUG - Try to create image in user context
2025-07-22 16:00:09,735 - DEBUG - Detaching the Policy for VN :ctest-vnet3-00672432
2025-07-22 16:00:09,735 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:09,745 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:09,764 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:09,875 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/313944cc-1701-4642-ada4-c7f06a00cbb3
2025-07-22 16:00:10,122 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy6-08882684'], ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy7-52605687']] from ctest-vnet3-00672432
2025-07-22 16:00:10,122 - DEBUG - Detaching the Policy for VN :ctest-vnet2-69889011
2025-07-22 16:00:10,122 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:10,129 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:10,142 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:10,242 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/2d57d0bd-07e1-4d8a-b58c-28094dd1b50b
2025-07-22 16:00:10,502 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy4-65251743'], ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy5-87282007']] from ctest-vnet2-69889011
2025-07-22 16:00:10,502 - DEBUG - Detaching the Policy for VN :ctest-vnet1-58605313
2025-07-22 16:00:10,502 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:10,509 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:10,521 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:10,624 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/4fa50dce-1ee9-4146-b6de-01b68259bc50
2025-07-22 16:00:10,911 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy2-99011261'], ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy3-22751076']] from ctest-vnet1-58605313
2025-07-22 16:00:10,911 - DEBUG - Detaching the Policy for VN :ctest-vnet0-07185902
2025-07-22 16:00:10,911 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:10,921 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:10,940 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:11,032 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/930346a2-f353-4062-9290-f50c77e95b43
2025-07-22 16:00:11,296 - DEBUG - Detached Policy:[['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy0-02365197'], ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy1-18987800']] from ctest-vnet0-07185902
2025-07-22 16:00:11,345 - INFO - Deleted policy ctest-policy7-52605687
2025-07-22 16:00:11,501 - DEBUG - policy ctest-policy7-52605687 is not found in API Server
2025-07-22 16:00:11,551 - INFO - Deleted policy ctest-policy6-08882684
2025-07-22 16:00:11,740 - DEBUG - policy ctest-policy6-08882684 is not found in API Server
2025-07-22 16:00:11,799 - INFO - Deleted policy ctest-policy5-87282007
2025-07-22 16:00:11,996 - DEBUG - policy ctest-policy5-87282007 is not found in API Server
2025-07-22 16:00:12,043 - INFO - Deleted policy ctest-policy4-65251743
2025-07-22 16:00:12,240 - DEBUG - policy ctest-policy4-65251743 is not found in API Server
2025-07-22 16:00:12,290 - INFO - Deleted policy ctest-policy3-22751076
2025-07-22 16:00:12,488 - DEBUG - policy ctest-policy3-22751076 is not found in API Server
2025-07-22 16:00:12,538 - INFO - Deleted policy ctest-policy2-99011261
2025-07-22 16:00:12,732 - DEBUG - policy ctest-policy2-99011261 is not found in API Server
2025-07-22 16:00:12,784 - INFO - Deleted policy ctest-policy1-18987800
2025-07-22 16:00:12,988 - DEBUG - policy ctest-policy1-18987800 is not found in API Server
2025-07-22 16:00:13,053 - INFO - Deleted policy ctest-policy0-02365197
2025-07-22 16:00:13,264 - DEBUG - policy ctest-policy0-02365197 is not found in API Server
2025-07-22 16:00:13,264 - INFO - Deleting VN ctest-vnet3-00672432
2025-07-22 16:00:13,495 - DEBUG - Response for deleting network ()
2025-07-22 16:00:13,495 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/0a5e5660-1f27-4057-bb1c-7216001cd43a
2025-07-22 16:00:13,502 - DEBUG - Response Code: 404
2025-07-22 16:00:13,502 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:13,509 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:13,522 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:13,622 - INFO - Validated that VN ctest-vnet3-00672432 is not found in API Server
2025-07-22 16:00:13,635 - DEBUG - VN ctest-vnet3-00672432 is not present in Agent 10.0.0.19
2025-07-22 16:00:13,646 - DEBUG - VN ctest-vnet3-00672432 is not present in Agent 10.0.0.27
2025-07-22 16:00:13,647 - INFO - Validated that VN ctest-vnet3-00672432 is not in any agent
2025-07-22 16:00:13,684 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vnet3-00672432 info
2025-07-22 16:00:13,684 - INFO - Deleting VN ctest-vnet2-69889011
2025-07-22 16:00:13,950 - DEBUG - Response for deleting network ()
2025-07-22 16:00:13,950 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/d1819c80-a701-429b-8ba9-3a0d07cfe574
2025-07-22 16:00:13,959 - DEBUG - Response Code: 404
2025-07-22 16:00:13,959 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:13,967 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:14,027 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:14,135 - INFO - Validated that VN ctest-vnet2-69889011 is not found in API Server
2025-07-22 16:00:14,150 - DEBUG - VN ctest-vnet2-69889011 is not present in Agent 10.0.0.19
2025-07-22 16:00:14,163 - DEBUG - VN ctest-vnet2-69889011 is not present in Agent 10.0.0.27
2025-07-22 16:00:14,163 - INFO - Validated that VN ctest-vnet2-69889011 is not in any agent
2025-07-22 16:00:14,200 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vnet2-69889011 info
2025-07-22 16:00:14,200 - INFO - Deleting VN ctest-vnet1-58605313
2025-07-22 16:00:14,419 - DEBUG - Response for deleting network ()
2025-07-22 16:00:14,419 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/3afa00b1-3eba-4eb3-aa4b-d09d15383c67
2025-07-22 16:00:14,428 - DEBUG - Response Code: 404
2025-07-22 16:00:14,428 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:14,436 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:14,451 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:14,560 - INFO - Validated that VN ctest-vnet1-58605313 is not found in API Server
2025-07-22 16:00:14,578 - DEBUG - VN ctest-vnet1-58605313 is not present in Agent 10.0.0.19
2025-07-22 16:00:14,592 - DEBUG - VN ctest-vnet1-58605313 is not present in Agent 10.0.0.27
2025-07-22 16:00:14,592 - INFO - Validated that VN ctest-vnet1-58605313 is not in any agent
2025-07-22 16:00:14,633 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vnet1-58605313 info
2025-07-22 16:00:14,634 - INFO - Deleting VN ctest-vnet0-07185902
2025-07-22 16:00:14,868 - DEBUG - Response for deleting network ()
2025-07-22 16:00:14,868 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/a2a72d7e-8596-4c9c-aa54-9d4a4513bd1b
2025-07-22 16:00:14,876 - DEBUG - Response Code: 404
2025-07-22 16:00:14,877 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:14,885 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:14,902 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:15,004 - INFO - Validated that VN ctest-vnet0-07185902 is not found in API Server
2025-07-22 16:00:15,019 - DEBUG - VN ctest-vnet0-07185902 is not present in Agent 10.0.0.19
2025-07-22 16:00:15,033 - DEBUG - VN ctest-vnet0-07185902 is not present in Agent 10.0.0.27
2025-07-22 16:00:15,033 - INFO - Validated that VN ctest-vnet0-07185902 is not in any agent
2025-07-22 16:00:15,082 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vnet0-07185902 info
2025-07-22 16:00:15,188 - INFO - IPAM: ctest-TestBasicPolicyIpv4v6-16424035-default-ipam is not found in API Server
2025-07-22 16:00:15,226 - INFO - IPAM:ctest-TestBasicPolicyIpv4v6-16424035-default-ipam is not found in control node
2025-07-22 16:00:15,786 - DEBUG - Skipping the deletion of Project ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035']
2025-07-22 16:00:15,786 - DEBUG - Skipping the deletion of User ctest-TestBasicPolicyIpv4v6-16424035
2025-07-22 16:00:17,065 - 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/policy/test_policy_basic.py", line 59, in test_policy
out = setup_obj.topo_setup()
File "/contrail-test/tcutils/topo/sdn_topo_setup.py", line 94, in topo_setup
topo_steps.createVMNova(self, config_option, vms_on_single_compute)
File "/contrail-test/tcutils/topo/topo_steps.py", line 516, in createVMNova
vm_name=vm))
File "/usr/local/lib/python3.6/site-packages/fixtures/fixture.py", line 257, in useFixture
fixture.setUp()
File "/contrail-test/fixtures/vm_test.py", line 188, in setUp
self.create()
File "/contrail-test/fixtures/vm_test.py", line 240, in create
fixed_ips=self.fixed_ips)
File "/contrail-test/fixtures/openstack.py", line 118, in create_vm
return self.nova_h.create_vm(vm_name=vm_name, image_name=image_name, vn_ids=vn_ids, **kwargs)
File "/contrail-test/fixtures/nova_test.py", line 577, in create_vm
image = self.get_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 198, in get_image
self._install_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 338, in _install_image
return self.copy_and_glance(build_path, image_name, params)
File "/contrail-test/fixtures/nova_test.py", line 407, in copy_and_glance
image_id = self.glance_h.create_image(generic_image_name, image_path_real, **params)
File "/contrail-test/fixtures/glance_test.py", line 50, in create_image
self.upload_image(obj['id'], filename)
File "/contrail-test/fixtures/glance_test.py", line 54, in upload_image
self.obj.images.upload(uuid, open(filename, 'rb'))
FileNotFoundError: [Errno 2] No such file or directory: '/contrail-test/images/ubuntu-traffic-py3.qcow2'
2025-07-22 16:00:17,081 - DEBUG - No XMPP flaps were noticed during the test
2025-07-22 16:00:17,081 - INFO -
2025-07-22 16:00:17,081 - INFO - END TEST : test_policy : FAILED[0:00:24]
2025-07-22 16:00:17,081 - INFO - --------------------------------------------------------------------------------
2025-07-22 16:00:18,332 - ERROR - TestFailed
Python 3.6.8: /usr/bin/python3
Tue Jul 22 16:00:17 2025
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/policy/test_policy.py in test_policy(self=)
602 @preposttest_wrapper
603 def test_policy(self):
604 super(TestBasicPolicyIpv4v6, self).test_policy()
605
606 @test.attr(type=['sanity', 'quick_sanity'])
builtinsuper =
global TestBasicPolicyIpv4v6 =
self =
).test_policy = >
/contrail-test/tcutils/wrappers.py in wrapper(self=, *args=(), **kwargs={})
174 if 'ci_image' in list(os.environ.keys()):
175 os.environ['stop_execution_flag'] = 'set'
176 raise TestFailed("\n ".join(errmsg))
177 elif testskip:
178 log.info('')
global TestFailed =
"\n ".join undefined
errmsg = ["Test failed: Traceback (most recent call la...ail-test/images/ubuntu-traffic-py3.qcow2'\n
\n"]
TestFailed: Test failed: Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/policy/test_policy_basic.py", line 59, in test_policy
out = setup_obj.topo_setup()
File "/contrail-test/tcutils/topo/sdn_topo_setup.py", line 94, in topo_setup
topo_steps.createVMNova(self, config_option, vms_on_single_compute)
File "/contrail-test/tcutils/topo/topo_steps.py", line 516, in createVMNova
vm_name=vm))
File "/usr/local/lib/python3.6/site-packages/fixtures/fixture.py", line 257, in useFixture
fixture.setUp()
File "/contrail-test/fixtures/vm_test.py", line 188, in setUp
self.create()
File "/contrail-test/fixtures/vm_test.py", line 240, in create
fixed_ips=self.fixed_ips)
File "/contrail-test/fixtures/openstack.py", line 118, in create_vm
return self.nova_h.create_vm(vm_name=vm_name, image_name=image_name, vn_ids=vn_ids, **kwargs)
File "/contrail-test/fixtures/nova_test.py", line 577, in create_vm
image = self.get_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 198, in get_image
self._install_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 338, in _install_image
return self.copy_and_glance(build_path, image_name, params)
File "/contrail-test/fixtures/nova_test.py", line 407, in copy_and_glance
image_id = self.glance_h.create_image(generic_image_name, image_path_real, **params)
File "/contrail-test/fixtures/glance_test.py", line 50, in create_image
self.upload_image(obj['id'], filename)
File "/contrail-test/fixtures/glance_test.py", line 54, in upload_image
self.obj.images.upload(uuid, open(filename, 'rb'))
FileNotFoundError: [Errno 2] No such file or directory: '/contrail-test/images/ubuntu-traffic-py3.qcow2'
__cause__ = None
__class__ =
__context__ = None
__delattr__ =
__dict__ = {}
__dir__ =
__doc__ = None
__eq__ =
__format__ =
__ge__ =
__getattribute__ =
__gt__ =
__hash__ =
__init__ =
__init_subclass__ =
__le__ =
__lt__ =
__module__ = 'tcutils.cores'
__ne__ =
__new__ =
__reduce__ =
__reduce_ex__ =
__repr__ =
__setattr__ =
__setstate__ =
__sizeof__ =
__str__ =
__subclasshook__ =
__suppress_context__ = False
__traceback__ =
__weakref__ = None
args = ("Test failed: Traceback (most recent call la...ail-test/images/ubuntu-traffic-py3.qcow2'\n
\n",)
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/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/policy/test_policy.py", line 604, in test_policy
super(TestBasicPolicyIpv4v6, self).test_policy()
File "/contrail-test/tcutils/wrappers.py", line 176, in wrapper
raise TestFailed("\n ".join(errmsg))
tcutils.cores.TestFailed: Test failed: Traceback (most recent call last):
File "/contrail-test/tcutils/wrappers.py", line 80, in wrapper
result = function(self, *args, **kwargs)
File "/contrail-test/scripts/policy/test_policy_basic.py", line 59, in test_policy
out = setup_obj.topo_setup()
File "/contrail-test/tcutils/topo/sdn_topo_setup.py", line 94, in topo_setup
topo_steps.createVMNova(self, config_option, vms_on_single_compute)
File "/contrail-test/tcutils/topo/topo_steps.py", line 516, in createVMNova
vm_name=vm))
File "/usr/local/lib/python3.6/site-packages/fixtures/fixture.py", line 257, in useFixture
fixture.setUp()
File "/contrail-test/fixtures/vm_test.py", line 188, in setUp
self.create()
File "/contrail-test/fixtures/vm_test.py", line 240, in create
fixed_ips=self.fixed_ips)
File "/contrail-test/fixtures/openstack.py", line 118, in create_vm
return self.nova_h.create_vm(vm_name=vm_name, image_name=image_name, vn_ids=vn_ids, **kwargs)
File "/contrail-test/fixtures/nova_test.py", line 577, in create_vm
image = self.get_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 198, in get_image
self._install_image(image_name=image_name)
File "/contrail-test/fixtures/nova_test.py", line 338, in _install_image
return self.copy_and_glance(build_path, image_name, params)
File "/contrail-test/fixtures/nova_test.py", line 407, in copy_and_glance
image_id = self.glance_h.create_image(generic_image_name, image_path_real, **params)
File "/contrail-test/fixtures/glance_test.py", line 50, in create_image
self.upload_image(obj['id'], filename)
File "/contrail-test/fixtures/glance_test.py", line 54, in upload_image
self.obj.images.upload(uuid, open(filename, 'rb'))
FileNotFoundError: [Errno 2] No such file or directory: '/contrail-test/images/ubuntu-traffic-py3.qcow2'
2025-07-22 16:00:18,347 - DEBUG - No XMPP flaps were noticed during the test
2025-07-22 16:00:18,347 - INFO -
2025-07-22 16:00:18,348 - INFO - END TEST : test_policy : FAILED[0:00:26]
2025-07-22 16:00:18,348 - INFO - --------------------------------------------------------------------------------
2025-07-22 16:00:18,351 - INFO - ================================================================================
2025-07-22 16:00:18,351 - INFO - STARTING TEST : test_policy_to_deny
2025-07-22 16:00:19,629 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.14': '0', '10.20.0.17': '0'}, '10.0.0.27': {'10.20.0.14': '0', '10.20.0.254': '0'}} with
2025-07-22 16:00:19,629 - INFO - Initial checks done. Running the testcase now
2025-07-22 16:00:19,629 - INFO -
2025-07-22 16:00:19,629 - INFO - ================================================================================
2025-07-22 16:00:19,629 - INFO - STARTING TEST : test_policy_to_deny
2025-07-22 16:00:19,629 - INFO - TEST DESCRIPTION : Test to validate that with policy having rule to disable icmp within the VN, ping between VMs should fail
1. Pick 2 VN from resource pool which have one VM in each
2. Create policy with icmp deny rule
3. Associate policy to both VN
4. Ping from one VM to another. Ping should fail
Pass criteria: Step 2,3 and 4 should pass
2025-07-22 16:00:20,919 - DEBUG - Nothing to compare xmpp stats {'10.0.0.19': {'10.20.0.14': '0', '10.20.0.17': '0'}, '10.0.0.27': {'10.20.0.14': '0', '10.20.0.254': '0'}} with
2025-07-22 16:00:20,919 - INFO - Initial checks done. Running the testcase now
2025-07-22 16:00:20,919 - INFO -
2025-07-22 16:00:20,927 - DEBUG - Policy np_rules : [rule_sequence = None, rule_uuid = None, direction = <>, protocol = icmp, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = deny, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None, rule_sequence = None, rule_uuid = None, direction = <>, protocol = 58, src_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202, security_group = None, network_policy = None, subnet_list = []], src_ports = [start_port = -1, end_port = -1], application = [], dst_addresses = [subnet = None, virtual_network = default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202, security_group = None, network_policy = None, subnet_list = []], dst_ports = [start_port = -1, end_port = -1], action_list = simple_action = deny, gateway_name = None, apply_service = [], service_properties = None, mirror_to = None, assign_routing_instance = None, log = False, alert = False, qos_action = None, host_based_service = False, ethertype = None, created = None, last_modified = None, description = None]
2025-07-22 16:00:21,824 - DEBUG - Response for create_network : {'network': {'id': '7ab83431-e9a4-4b13-84e4-f3c62d4fd146', 'name': 'ctest-vn1-97821202', 'tenant_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'project_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': [], 'fq_name': ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-vn1-97821202'], 'port_security_enabled': True, 'description': ''}}
2025-07-22 16:00:22,130 - DEBUG - Response for create_subnet : {'subnet': {'id': '1ce7205d-b3fa-4253-97b0-4169fb2d0207', 'name': '', 'tenant_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'network_id': '7ab83431-e9a4-4b13-84e4-f3c62d4fd146', 'ip_version': 4, 'cidr': '192.168.10.0/24', 'allocation_pools': [{'start': '192.168.10.2', 'end': '192.168.10.254'}], 'gateway_ip': '192.168.10.1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '192.168.10.2', 'tags': [], 'project_id': '5f9b62e0ec1c4e189e0673b004547ae7'}}
2025-07-22 16:00:22,401 - DEBUG - Response for create_subnet : {'subnet': {'id': 'bceb2c3b-932b-4b98-bf67-d6a608f2f38b', 'name': '', 'tenant_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'network_id': '7ab83431-e9a4-4b13-84e4-f3c62d4fd146', 'ip_version': 6, 'cidr': '304b:4c3e:648a:5030:22b3:594b::/96', 'allocation_pools': [{'start': '304b:4c3e:648a:5030:22b3:594b:0:2', 'end': '304b:4c3e:648a:5030:22b3:594b:ffff:fffe'}], 'gateway_ip': '304b:4c3e:648a:5030:22b3:594b:0:1', 'enable_dhcp': True, 'ipv6_ra_mode': None, 'ipv6_address_mode': None, 'dns_nameservers': [], 'host_routes': [], 'dns_server_address': '304b:4c3e:648a:5030:22b3:594b:0:2', 'tags': [], 'project_id': '5f9b62e0ec1c4e189e0673b004547ae7'}}
2025-07-22 16:00:22,430 - INFO - Created VN ctest-vn1-97821202
2025-07-22 16:00:22,446 - DEBUG - VN ctest-vn1-97821202 UUID is 7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:22,693 - DEBUG - Response for mapping policy(s) with vn {'network': {'id': '7ab83431-e9a4-4b13-84e4-f3c62d4fd146', 'name': 'ctest-vn1-97821202', 'tenant_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'project_id': '5f9b62e0ec1c4e189e0673b004547ae7', 'admin_state_up': True, 'shared': False, 'status': 'ACTIVE', 'router:external': False, 'mtu': 0, 'subnets': ['1ce7205d-b3fa-4253-97b0-4169fb2d0207', 'bceb2c3b-932b-4b98-bf67-d6a608f2f38b'], 'fq_name': ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-vn1-97821202'], 'policys': [['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy1-02230731']], 'subnet_ipam': [{'subnet_cidr': '192.168.10.0/24', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}, {'subnet_cidr': '304b:4c3e:648a:5030:22b3:594b::/96', 'ipam_fq_name': ['default-domain', 'default-project', 'default-network-ipam']}], 'port_security_enabled': True, 'description': ''}}
2025-07-22 16:00:22,799 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:22,806 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:22,822 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:22,935 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:22,954 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:22,967 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:00:22,976 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:00:22,984 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/9e1ebc06-5ee3-404c-a4c9-657654ce4042
2025-07-22 16:00:22,992 - DEBUG - Route Targets: ['target:64512:8000005']
2025-07-22 16:00:22,992 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:23,005 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:00:23,025 - INFO - Verified VN network id 12 for VN 7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:23,026 - INFO - Verifications in API Server for VN ctest-vn1-97821202 passed
2025-07-22 16:00:23,026 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:23,041 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:00:23,059 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:00:23,075 - DEBUG - Requesting: http://10.0.0.254:8082/route-target/9e1ebc06-5ee3-404c-a4c9-657654ce4042
2025-07-22 16:00:23,094 - DEBUG - Control-node 10.0.0.254 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicyIpv4v6-16424035', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8842875257319869203', 'uuid-lslong': '9576046740185796934'}, 'enable': 'true', 'created': '2025-07-22T16:00:21', 'last-modified': '2025-07-22T16:00:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.467728'}
2025-07-22 16:00:23,103 - DEBUG - Route Targets: ['target:64512:8000005']
2025-07-22 16:00:23,112 - DEBUG - Control-node 10.0.0.50 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicyIpv4v6-16424035', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8842875257319869203', 'uuid-lslong': '9576046740185796934'}, 'enable': 'true', 'created': '2025-07-22T16:00:21', 'last-modified': '2025-07-22T16:00:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.481449'}
2025-07-22 16:00:23,131 - DEBUG - Route Targets: ['target:64512:8000005']
2025-07-22 16:00:23,141 - DEBUG - Control-node 10.0.0.23 : VN object is : {'node_name': 'virtual-network:default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'interests': '-', 'advertised': '-', 'dbentryflags': None, 'obj_info': {'sequence_number': '0', 'origin': 'Cassandra', 'data': {'id-perms': {'permissions': {'owner': 'ctest-TestBasicPolicyIpv4v6-16424035', 'owner-access': '7', 'group': 'reader', 'group-access': '7', 'other-access': '7'}, 'uuid': {'uuid-mslong': '8842875257319869203', 'uuid-lslong': '9576046740185796934'}, 'enable': 'true', 'created': '2025-07-22T16:00:21', 'last-modified': '2025-07-22T16:00:22', 'description': None, 'user-visible': 'true', 'creator': None}}}, 'neighbors': None, 'last_modified': '00:00:00.515435'}
2025-07-22 16:00:23,153 - DEBUG - Route Targets: ['target:64512:8000005']
2025-07-22 16:00:23,153 - INFO - On all control nodes, Config, RI and RT verification for VN ctest-vn1-97821202 passed
2025-07-22 16:00:23,154 - DEBUG - ====Verifying policy data for ctest-vn1-97821202 in API_Server ======
2025-07-22 16:00:23,154 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:00:23,164 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:00:23,179 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:00:23,289 - DEBUG - Requesting: http://10.0.0.254:8082/virtual-network/7ab83431-e9a4-4b13-84e4-f3c62d4fd146
2025-07-22 16:00:23,307 - DEBUG - ==>Verifying data for policy with id: 0dcfd30c-4d72-456b-a8c9-4378686b15d4, fqn: ['default-domain', 'ctest-TestBasicPolicyIpv4v6-16424035', 'ctest-policy1-02230731']
2025-07-22 16:00:23,307 - INFO - VN ctest-vn1-97821202 Policy verification: verify_vn_policy_in_api_server, status: True
2025-07-22 16:00:23,307 - DEBUG - Verifying the vn in opserver
2025-07-22 16:00:23,307 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 virtual network link through opserver 10.0.0.254
2025-07-22 16:00:23,308 - DEBUG - Requesting: http://10.0.0.254:8081/analytics/uves/virtual-networks
2025-07-22 16:00:23,324 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'href': 'http://10.0.0.254:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202?flat'}
2025-07-22 16:00:23,324 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 virtual network link through opserver 10.0.0.50
2025-07-22 16:00:23,324 - DEBUG - Requesting: http://10.0.0.50:8081/analytics/uves/virtual-networks
2025-07-22 16:00:23,339 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'href': 'http://10.0.0.50:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202?flat'}
2025-07-22 16:00:23,339 - DEBUG - Verifying the default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 virtual network link through opserver 10.0.0.23
2025-07-22 16:00:23,339 - DEBUG - Requesting: http://10.0.0.23:8081/analytics/uves/virtual-networks
2025-07-22 16:00:23,354 - DEBUG - vn link and name as {'name': 'default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202', 'href': 'http://10.0.0.23:8081/analytics/uves/virtual-network/default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202?flat'}
2025-07-22 16:00:23,354 - INFO - Validated that VN default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is found in opserver
2025-07-22 16:00:23,383 - DEBUG - Do not have enough data to verify VN in agent
2025-07-22 16:00:23,396 - DEBUG - VRF ids for VN ctest-vn1-97821202: {}
2025-07-22 16:00:24,581 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3693-2), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3693-2)
2025-07-22 16:00:26,399 - INFO - VM ([]) created on node: (an-jenkins-deploy-platform-ansible-os-3693-1), Zone: (nova:an-jenkins-deploy-platform-ansible-os-3693-1)
2025-07-22 16:00:26,399 - INFO - Waiting for VM ctest-vn1_vm1-69248442 to be up..
2025-07-22 16:00:26,521 - DEBUG - VM is still in BUILD state, Expected: ACTIVE
2025-07-22 16:00:31,625 - DEBUG - VM is in ACTIVE state now
2025-07-22 16:00:31,626 - INFO - VM name : ctest-vn1_vm1-69248442
2025-07-22 16:00:31,728 - DEBUG - VM ctest-vn1_vm1-69248442 ID is 131a4ab7-1167-435c-8e42-79d6d8b566f2
2025-07-22 16:00:31,728 - DEBUG - VM ctest-vn1_vm1-69248442 launched on Node an-jenkins-deploy-platform-ansible-os-3693-2
2025-07-22 16:00:31,849 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/131a4ab7-1167-435c-8e42-79d6d8b566f2
2025-07-22 16:00:31,863 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/eb62b51c-56ea-4e36-b9f4-cb9207756dde
2025-07-22 16:00:35,102 - 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 1023ms')
2025-07-22 16:00:35,102 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:35,125 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:35,125 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:39,201 - 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-07-22 16:00:39,201 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:39,218 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:39,218 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:43,292 - 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 1011ms')
2025-07-22 16:00:43,292 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:43,310 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:43,310 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:47,394 - 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-07-22 16:00:47,395 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:47,415 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:47,415 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:51,488 - 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-07-22 16:00:51,488 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:51,506 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:51,507 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:55,583 - 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 1011ms')
2025-07-22 16:00:55,583 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:55,601 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:55,601 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:00:59,677 - 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 1016ms')
2025-07-22 16:00:59,678 - DEBUG - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 failed!
2025-07-22 16:00:59,694 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 192.168.10.1 and allocation pool is NOT set
2025-07-22 16:00:59,694 - DEBUG - Gateway for vn default-domain:ctest-TestBasicPolicyIpv4v6-16424035:ctest-vn1-97821202 is 304b:4c3e:648a:5030:22b3:594b:0:1 and allocation pool is NOT set
2025-07-22 16:01:03,769 - 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=2 ttl=63 time=6.38 ms\r\n\r\n--- 169.254.0.3 ping statistics ---\r\n2 packets transmitted, 1 received, 50% packet loss, time 1015ms\r\nrtt min/avg/max/mdev = 6.383/6.383/6.383/0.000 ms')
2025-07-22 16:01:03,769 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm1-69248442 passed
2025-07-22 16:01:03,891 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:03,891 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-69248442, IP 192.168.10.3, Port 22
2025-07-22 16:01:03,959 - 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-07-22 16:01:04,049 - DEBUG - VM ctest-vn1_vm1-69248442 is NOT ready for SSH connections, VM status: ACTIVE
2025-07-22 16:01:09,049 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:09,050 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-69248442, IP 192.168.10.3, Port 22
2025-07-22 16:01:09,120 - 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-07-22 16:01:09,208 - DEBUG - VM ctest-vn1_vm1-69248442 is NOT ready for SSH connections, VM status: ACTIVE
2025-07-22 16:01:14,209 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:14,209 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-69248442, IP 192.168.10.3, Port 22
2025-07-22 16:01:14,276 - 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-07-22 16:01:14,369 - DEBUG - VM ctest-vn1_vm1-69248442 is NOT ready for SSH connections, VM status: ACTIVE
2025-07-22 16:01:19,369 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:19,370 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-69248442, IP 192.168.10.3, Port 22
2025-07-22 16:01:19,425 - 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-07-22 16:01:19,518 - DEBUG - VM ctest-vn1_vm1-69248442 is NOT ready for SSH connections, VM status: ACTIVE
2025-07-22 16:01:24,519 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:24,519 - DEBUG - Waiting to SSH to VM ctest-vn1_vm1-69248442, IP 192.168.10.3, Port 22
2025-07-22 16:01:24,687 - DEBUG - VM ctest-vn1_vm1-69248442 is ready for SSH connections
2025-07-22 16:01:24,687 - INFO - Waiting for VM ctest-vn1_vm2-07886754 to be up..
2025-07-22 16:01:24,797 - DEBUG - VM is in ACTIVE state now
2025-07-22 16:01:24,797 - INFO - VM name : ctest-vn1_vm2-07886754
2025-07-22 16:01:24,893 - DEBUG - VM ctest-vn1_vm2-07886754 ID is 97ba7199-a69a-4741-915c-cb4a222fad10
2025-07-22 16:01:24,893 - DEBUG - VM ctest-vn1_vm2-07886754 launched on Node an-jenkins-deploy-platform-ansible-os-3693-1
2025-07-22 16:01:24,980 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine/97ba7199-a69a-4741-915c-cb4a222fad10
2025-07-22 16:01:24,993 - DEBUG - Requesting: http://10.0.0.23:8082/virtual-machine-interface/0a8219ad-bca3-4e50-b030-b20948a9ad57
2025-07-22 16:01:26,216 - 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=5.11 ms\r\n64 bytes from 169.254.0.3: icmp_seq=2 ttl=63 time=1.27 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.265/3.188/5.111/1.923 ms')
2025-07-22 16:01:26,216 - INFO - Ping to Metadata IP 169.254.0.3 of VM ctest-vn1_vm2-07886754 passed
2025-07-22 16:01:26,332 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:26,332 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-07886754, IP 192.168.10.4, Port 22
2025-07-22 16:01:26,389 - 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-07-22 16:01:26,541 - DEBUG - VM ctest-vn1_vm2-07886754 is NOT ready for SSH connections, VM status: ACTIVE
2025-07-22 16:01:31,543 - DEBUG - verify_vm_launched is skipped since self.vm_launch_flag is set
2025-07-22 16:01:31,543 - DEBUG - Waiting to SSH to VM ctest-vn1_vm2-07886754, IP 192.168.10.4, Port 22
2025-07-22 16:01:31,715 - DEBUG - VM ctest-vn1_vm2-07886754 is ready for SSH connections
2025-07-22 16:01:31,716 - DEBUG - Running remote_cmd, Cmd : ping -s 56 -c 3 -W 1 192.168.10.4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2025-07-22 16:01:31,716 - DEBUG - ping -s 56 -c 3 -W 1 192.168.10.4
2025-07-22 16:01:50,160 - DEBUG - PING 192.168.10.4 (192.168.10.4) 56(84) bytes of data.
--- 192.168.10.4 ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2003ms
2025-07-22 16:01:50,160 - WARNING - Ping to IP 192.168.10.4 from VM ctest-vn1_vm1-69248442 failed
2025-07-22 16:01:50,160 - DEBUG - Running remote_cmd, Cmd : ping6 -s 56 -c 3 -W 1 304b:4c3e:648a:5030:22b3:594b:0:4, host_string: ubuntu@169.254.0.3, password: ubuntugateway: ubuntu@10.0.0.27, gateway password: c0ntrail123
2025-07-22 16:01:50,160 - DEBUG - ping6 -s 56 -c 3 -W 1 304b:4c3e:648a:5030:22b3:594b:0:4
2025-07-22 16:01:53,674 - DEBUG - PING 304b:4c3e:648a:5030:22b3:594b:0:4(304b:4c3e:648a:5030:22b3:594b:0:4) 56 data bytes
--- 304b:4c3e:648a:5030:22b3:594b:0:4 ping statistics ---
3 packets transmitted, 0 received, 100% packet loss, time 2002ms
2025-07-22 16:01:53,674 - WARNING - Ping to IP 304b:4c3e:648a:5030:22b3:594b:0:4 from VM ctest-vn1_vm1-69248442 failed
2025-07-22 16:01:53,674 - INFO - Deleting VM ctest-vn1_vm2-07886754
2025-07-22 16:01:53,742 - INFO - Deleting VM ctest-vn1_vm1-69248442
2025-07-22 16:01:54,025 - INFO - Deleting VN ctest-vn1-97821202
2025-07-22 16:01:54,082 - DEBUG - VN 7ab83431-e9a4-4b13-84e4-f3c62d4fd146 still in use: Unable to complete operation on network 7ab83431-e9a4-4b13-84e4-f3c62d4fd146. There are one or more ports still in use on the network.
Neutron server returns request_ids: ['req-79f3ac45-d90a-426f-a2ce-a3e93b3dc94a']
2025-07-22 16:01:54,082 - WARNING - Deleting VN ctest-vn1-97821202 failed..Will retry
2025-07-22 16:01:56,316 - DEBUG - Response for deleting network ()
2025-07-22 16:01:56,316 - DEBUG - Requesting: http://10.0.0.254:8082/routing-instance/375328b9-b4e9-42a1-9370-50a04186e589
2025-07-22 16:01:56,324 - DEBUG - Response Code: 404
2025-07-22 16:01:56,324 - DEBUG - Requesting: http://10.0.0.254:8082/domains
2025-07-22 16:01:56,332 - DEBUG - Requesting: http://10.0.0.254:8082/domain/6830e6da-995f-41aa-841e-c47f32c16910
2025-07-22 16:01:56,346 - DEBUG - Requesting: http://10.0.0.254:8082/project/5f9b62e0-ec1c-4e18-9e06-73b004547ae7
2025-07-22 16:01:56,437 - INFO - Validated that VN ctest-vn1-97821202 is not found in API Server
2025-07-22 16:01:56,451 - DEBUG - VN ctest-vn1-97821202 is not present in Agent 10.0.0.19
2025-07-22 16:01:56,463 - DEBUG - VN ctest-vn1-97821202 is not present in Agent 10.0.0.27
2025-07-22 16:01:56,463 - INFO - Validated that VN ctest-vn1-97821202 is not in any agent
2025-07-22 16:01:56,501 - INFO - Validated that Routing instances and Config db in Control-nodes does not have VN ctest-vn1-97821202 info
2025-07-22 16:01:56,542 - INFO - Deleted policy ctest-policy1-02230731
2025-07-22 16:01:57,811 - DEBUG - No XMPP flaps were noticed during the test
2025-07-22 16:01:57,811 - INFO - END TEST : test_policy_to_deny : PASSED[0:01:38]
2025-07-22 16:01:57,811 - INFO - --------------------------------------------------------------------------------
2025-07-22 16:01:59,078 - DEBUG - No XMPP flaps were noticed during the test
2025-07-22 16:01:59,078 - INFO - END TEST : test_policy_to_deny : PASSED[0:01:41]
2025-07-22 16:01:59,078 - INFO - --------------------------------------------------------------------------------
2025-07-22 16:01:59,878 - INFO - Deleted project: ctest-TestBasicPolicyIpv4v6-16424035, ID : 5f9b62e0-ec1c-4e18-9e06-73b004547ae7