Agent Logging - Networking Issue

Description

Issue reported by c312:

Agent installed. Failure when trying to run agent test script:

2020-04-21 19:41:18,959 - cloudify.amqp_client - INFO - Registered handler for CloudifyOperationConsumer [operation]
2020-04-21 19:41:18,998 - cloudify.amqp_client - INFO - Registered handler for CloudifyWorkflowConsumer [workflow]
2020-04-21 19:41:19,040 - cloudify.amqp_client - INFO - Registered handler for ServiceTaskConsumer [service]
2020-04-21 19:41:19,783 - worker.rhldmr4dc_9omfei - INFO - Received `ping` service task with kwargs: {}
2020-04-21 19:41:19,784 - worker.rhldmr4dc_9omfei - INFO - Result: {'time': 1587498079.784059}
2020-04-21 19:41:52,726 - worker.rhldmr4dc_9omfei - INFO - Received `ping` service task with kwargs: {}
2020-04-21 19:41:52,726 - worker.rhldmr4dc_9omfei - INFO - Result: {'time': 1587498112.726851}
2020-04-21 19:43:06,548 - worker.rhldmr4dc_9omfei - INFO - Received `ping` service task with kwargs: {}
2020-04-21 19:43:06,548 - worker.rhldmr4dc_9omfei - INFO - Result: {'time': 1587498186.54848}
2020-04-21 19:43:07,169 - worker.rhldmr4dc_9omfei - INFO -
Started handling operation on queue `rhldmr4dc_9omfei` on tenant `GTS_Orchestration_Team`:
Task name: script_runner.tasks.run
Execution ID: 97746c86-2695-4d71-bff4-bd5093e3ce7e
Workflow ID: install
Node ID: agent_test_387wc5
2020-04-21 19:43:13,169 - worker.rhldmr4dc_9omfei - ERROR - ERROR - caught: RecoverableError(u'',)
Traceback (most recent call last):
File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify_agent/worker.py", line 128, in handle_task
rv = handler.handle_or_dispatch_to_subprocess_if_remote()
File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 153, in handle_or_dispatch_to_subprocess_if_remote
return self.dispatch_to_subprocess()
File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 231, in dispatch_to_subprocess
raise error
RecoverableError
2020-04-21 19:43:13,170 - worker.rhldmr4dc_9omfei - INFO -
Finished handling operation on queue `rhldmr4dc_9omfei` on tenant `GTS_Orchestration_Team`:
Task name: script_runner.tasks.run
Execution ID: 97746c86-2695-4d71-bff4-bd5093e3ce7e
Workflow ID: install
Node ID: agent_test_387wc5
Status: ERROR - result: {'ok': False, 'error': {'traceback': 'Traceback (most recent call last):\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify_agent/worker.py", line 128, in handle_task\n rv = handler.handle_or_dispatch_to_subprocess_if_remote()\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 153, in handle_or_dispatch_to_subprocess_if_remote\n return self.dispatch_to_subprocess()\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 231, in dispatch_to_subprocess\n raise error\nRecoverableError\n', 'append_message': False, 'exception_type': 'RecoverableError', 'known_exception_type': 'RecoverableError', 'known_exception_type_kwargs': {'causes': [{'message': u'', 'traceback': u'Traceback (most recent call last):\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 712, in main\n payload = handler.handle()\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 402, in handle\n result = self._run_operation_func(ctx, kwargs)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/dispatch.py", line 431, in _run_operation_func\n return self.func(*self.args, **kwargs)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/script_runner/tasks.py", line 78, in run\n script_result = process_execution(script_func, script_path, ctx, process)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/script_runner/tasks.py", line 154, in process_execution\n script_func(script_path, ctx, process)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/script_runner/tasks.py", line 192, in execute\n proxy = start_ctx_proxy(ctx, process)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/script_runner/tasks.py", line 297, in start_ctx_proxy\n return HTTPCtxProxy(ctx)\n File "/home/cloud-user/rhldmr4dc_9omfei/env/lib/python2.7/site-packages/cloudify/proxy/server.py", line 80, in _init_\n self._started.get(timeout=5)\n File "/usr/lib64/python2.7/Queue.py", line 176, in get\n raise Empty\nEmpty\n', 'type': u'Empty'}]}, 'message': '', 'known_exception_type_args': [None]}}

Agent finds port on 127.0.0.1:

def get_unused_port():
sock = socket.socket()
sock.bind(('127.0.0.1', 0))
_, port = sock.getsockname()
sock.close()
return port

But we bing on localhost:

https://github.com/cloudify-cosmo/cloudify-common/blob/master/cloudify/proxy/server.py#L74

This results in failure above when localhost doesn't resolve to 127.0.0.1.

The customer was able to make the change on their side, it's resolved. But we should fix on our end.

Steps to Reproduce

Environment:
OS (CLI), HA cluster, cloud provider
------------------------------------

Steps to reproduce:
------------------
1.
2.
3.

Expected result:
---------------

Actual result:
-------------

Why Propose Close?

None

Activity

Show:
Alex Molev
September 1, 2020, 2:29 PM

is it still happening?

Assignee

Łukasz Maksymczuk

Reporter

Eve Land

Labels

Severity

Medium

Target Version

5.2

Premium Only

no

Found In Version

5.0.5

QA Owner

None

Bug Type

legacy bug

Customer Encountered

Yes

Customer Name

None

Release Notes

yes

Priority

None

Epic Link

Priority

Unprioritized
Configure