From b2423e7602b66d7cdcee85c07bbcad14928aa120 Mon Sep 17 00:00:00 2001 From: Nathaniel Case Date: Fri, 21 Dec 2018 10:31:43 -0500 Subject: [PATCH] Log device interaction and push labeled logs back to controller (#50028) * Add session tracing support for network_cli, netconf and httapi connection * Add `persistent_log_messages` configuration option to log device inteaction in log file for network_cli, netconf and httapi connection type * Log jsonrpc request and response in log file is configuration option is enabled * Update docs to talk about warning shown when persistent_log_messages is on --- bin/ansible-connection | 3 +- .../network_debug_troubleshooting.rst | 58 +++++++++++++++++++ lib/ansible/plugins/connection/__init__.py | 10 ++++ lib/ansible/plugins/connection/httpapi.py | 24 +++++++- lib/ansible/plugins/connection/netconf.py | 16 +++++ lib/ansible/plugins/connection/network_cli.py | 28 ++++++++- 6 files changed, 134 insertions(+), 5 deletions(-) diff --git a/bin/ansible-connection b/bin/ansible-connection index 36d22576216..7f35aa981e0 100755 --- a/bin/ansible-connection +++ b/bin/ansible-connection @@ -131,17 +131,18 @@ class ConnectionProcess(object): self.exception = None (s, addr) = self.sock.accept() signal.alarm(0) - signal.signal(signal.SIGALRM, self.command_timeout) while True: data = recv_data(s) if not data: break + self.connection._log_messages("jsonrpc request: %s" % data) signal.alarm(self.connection.get_option('persistent_command_timeout')) resp = self.srv.handle_request(data) signal.alarm(0) + self.connection._log_messages("jsonrpc response: %s" % resp) send_data(s, to_bytes(resp)) s.close() diff --git a/docs/docsite/rst/network/user_guide/network_debug_troubleshooting.rst b/docs/docsite/rst/network/user_guide/network_debug_troubleshooting.rst index e5af30eade9..ba44bd91eea 100644 --- a/docs/docsite/rst/network/user_guide/network_debug_troubleshooting.rst +++ b/docs/docsite/rst/network/user_guide/network_debug_troubleshooting.rst @@ -99,6 +99,64 @@ Because the log files are verbose, you can use grep to look for specific informa grep "p=28990" $ANSIBLE_LOG_PATH + +Enabling Networking device interaction logging +---------------------------------------------- + +**Platforms:** Any + +Ansible 2.8 features added logging of device interaction in log file to help diagnose and troubleshoot +issues regarding Ansible Networking modules. The messages are logged in file pointed by ``log_path`` configuration +option in Ansible configuration file or by set :envvar:`ANSIBLE_LOG_PATH` as mentioned in above section. + +.. warning:: + The device interaction messages consist of command executed on target device and the returned response, as this + log data can contain sensitive information including passwords in plain text it is disabled by default. + Additionally, in order to prevent accidental leakage of data, a warning will be shown on every task with this + setting eneabled specifying which host has it enabled and where the data is being logged. + +Be sure to fully understand the security implications of enabling this option. The device interaction logging can be enabled either globally by setting in configuration file or by setting environment or enabled on per task basis by passing special variable to task. + +Before running ``ansible-playbook`` run the following commands to enable logging:: + + # Specify the location for the log file + export ANSIBLE_LOG_PATH=~/ansible.log + + +Enable device interaction logging for a given task + +.. code-block:: yaml + + - name: get version information + ios_command: + commands: + - show version + vars: + ansible_persistent_log_messages: True + + +To make this a global setting, add the following to your ``ansible.cfg`` file: + +.. code-block:: ini + + [persistent_connection] + log_messages = True + +or enable environment variable `ANSIBLE_PERSISTENT_LOG_MESSAGES` + + # Enable device interaction logging + export ANSIBLE_PERSISTENT_LOG_MESSAGES=True + +If the task is failing at the time on connection initialization itself it is recommended to enable this option +globally else if an individual task is failing intermittently this option can be enabled for that task itself to +find the root cause. + +After Ansible has finished running you can inspect the log file which has been created on the ansible-controller + +.. note:: Be sure to fully understand the security implications of enabling this option as it can log sensitive + information in log file thus creating security vulnerability. + + Isolating an error ------------------ diff --git a/lib/ansible/plugins/connection/__init__.py b/lib/ansible/plugins/connection/__init__.py index edbf270129d..e42783fe9cb 100644 --- a/lib/ansible/plugins/connection/__init__.py +++ b/lib/ansible/plugins/connection/__init__.py @@ -357,6 +357,12 @@ class NetworkConnectionBase(ConnectionBase): def set_options(self, task_keys=None, var_options=None, direct=None): super(NetworkConnectionBase, self).set_options(task_keys=task_keys, var_options=var_options, direct=direct) + if self.get_option('persistent_log_messages'): + warning = "Persistent connection logging is enabled for %s. This will log ALL interactions" % self._play_context.remote_addr + logpath = getattr(C, 'DEFAULT_LOG_PATH') + if logpath is not None: + warning += " to %s" % logpath + self.queue_message('warning', "%s and WILL NOT redact sensitive configuration like passwords. USE WITH CAUTION!" % warning) if self._sub_plugin.get('obj') and self._sub_plugin.get('type') != 'external': try: @@ -386,3 +392,7 @@ class NetworkConnectionBase(ConnectionBase): if os.path.exists(socket_path): self._connected = True self._socket_path = socket_path + + def _log_messages(self, message): + if self.get_option('persistent_log_messages'): + self.queue_message('log', message) diff --git a/lib/ansible/plugins/connection/httpapi.py b/lib/ansible/plugins/connection/httpapi.py index a9d20bcfee2..4e5fd5508c5 100644 --- a/lib/ansible/plugins/connection/httpapi.py +++ b/lib/ansible/plugins/connection/httpapi.py @@ -143,6 +143,22 @@ options: - name: ANSIBLE_PERSISTENT_COMMAND_TIMEOUT vars: - name: ansible_command_timeout + persistent_log_messages: + type: boolean + description: + - This flag will enable logging the command executed and response received from + target device in the ansible log file. For this option to work 'log_path' ansible + configuration option is required to be set to a file path with write access. + - Be sure to fully understand the security implications of enabling this + option as it could create a security vulnerability by logging sensitive information in log file. + default: False + ini: + - section: persistent_connection + key: log_messages + env: + - name: ANSIBLE_PERSISTENT_LOG_MESSAGES + vars: + - name: ansible_persistent_log_messages """ from io import BytesIO @@ -248,7 +264,9 @@ class Connection(NetworkConnectionBase): url_kwargs['url_password'] = self.get_option('password') try: - response = open_url(self._url + path, data=data, **url_kwargs) + url = self._url + path + self._log_messages("send url '%s' with data '%s' and kwargs '%s'" % (url, data, url_kwargs)) + response = open_url(url, data=data, **url_kwargs) except HTTPError as exc: is_handled = self.handle_httperror(exc) if is_handled is True: @@ -261,7 +279,9 @@ class Connection(NetworkConnectionBase): raise AnsibleConnectionFailure('Could not connect to {0}: {1}'.format(self._url + path, exc.reason)) response_buffer = BytesIO() - response_buffer.write(response.read()) + resp_data = response.read() + self._log_messages("received response: '%s'" % resp_data) + response_buffer.write(resp_data) # Try to assign a new auth token if one is given self._auth = self.update_auth(response, response_buffer) or self._auth diff --git a/lib/ansible/plugins/connection/netconf.py b/lib/ansible/plugins/connection/netconf.py index b95f71dd84a..1d8dacbe35d 100644 --- a/lib/ansible/plugins/connection/netconf.py +++ b/lib/ansible/plugins/connection/netconf.py @@ -170,6 +170,22 @@ options: vars: - name: ansible_netconf_ssh_config version_added: '2.7' + persistent_log_messages: + type: boolean + description: + - This flag will enable logging the command executed and response received from + target device in the ansible log file. For this option to work 'log_path' ansible + configuration option is required to be set to a file path with write access. + - Be sure to fully understand the security implications of enabling this + option as it could create a security vulnerability by logging sensitive information in log file. + default: False + ini: + - section: persistent_connection + key: log_messages + env: + - name: ANSIBLE_PERSISTENT_LOG_MESSAGES + vars: + - name: ansible_persistent_log_messages """ import os diff --git a/lib/ansible/plugins/connection/network_cli.py b/lib/ansible/plugins/connection/network_cli.py index e055a376465..1fd2ca0df8c 100644 --- a/lib/ansible/plugins/connection/network_cli.py +++ b/lib/ansible/plugins/connection/network_cli.py @@ -172,6 +172,22 @@ options: - name: ANSIBLE_PERSISTENT_BUFFER_READ_TIMEOUT vars: - name: ansible_buffer_read_timeout + persistent_log_messages: + type: boolean + description: + - This flag will enable logging the command executed and response received from + target device in the ansible log file. For this option to work 'log_path' ansible + configuration option is required to be set to a file path with write access. + - Be sure to fully understand the security implications of enabling this + option as it could create a security vulnerability by logging sensitive information in log file. + default: False + ini: + - section: persistent_connection + key: log_messages + env: + - name: ANSIBLE_PERSISTENT_LOG_MESSAGES + vars: + - name: ansible_persistent_log_messages """ import getpass @@ -374,6 +390,7 @@ class Connection(NetworkConnectionBase): buffer_read_timeout = self.get_option('persistent_buffer_read_timeout') self._validate_timeout_value(buffer_read_timeout, "persistent_buffer_read_timeout") + self._log_messages("command: %s" % command) while True: if command_prompt_matched: try: @@ -381,6 +398,7 @@ class Connection(NetworkConnectionBase): signal.setitimer(signal.ITIMER_REAL, buffer_read_timeout) data = self._ssh_shell.recv(256) signal.alarm(0) + self._log_messages("response-%s: %s" % (window_count + 1, data)) # if data is still received on channel it indicates the prompt string # is wrongly matched in between response chunks, continue to read # remaining response. @@ -396,7 +414,7 @@ class Connection(NetworkConnectionBase): return self._command_response else: data = self._ssh_shell.recv(256) - + self._log_messages("response-%s: %s" % (window_count + 1, data)) # when a channel stream is closed, received data will be empty if not data: break @@ -493,6 +511,9 @@ class Connection(NetworkConnectionBase): for index, regex in enumerate(prompts_regex): match = regex.search(resp) if match: + self._matched_cmd_prompt = match.group() + self._log_messages("matched command prompt: %s" % self._matched_cmd_prompt) + # if prompt_retry_check is enabled to check if same prompt is # repeated don't send answer again. if not prompt_retry_check: @@ -500,7 +521,8 @@ class Connection(NetworkConnectionBase): self._ssh_shell.sendall(b'%s' % prompt_answer) if newline: self._ssh_shell.sendall(b'\r') - self._matched_cmd_prompt = match.group() + prompt_answer += '\r' + self._log_messages("matched command prompt answer: %s" % self.prompt_answer) if check_all and prompts and not single_prompt: prompts.pop(0) answer.pop(0) @@ -536,6 +558,7 @@ class Connection(NetworkConnectionBase): errored_response = response self._matched_pattern = regex.pattern self._matched_prompt = match.group() + self._log_messages("matched error regex '%s' from response '%s'" % (self._matched_pattern, errored_response)) break if not is_error_message: @@ -544,6 +567,7 @@ class Connection(NetworkConnectionBase): if match: self._matched_pattern = regex.pattern self._matched_prompt = match.group() + self._log_messages("matched cli prompt '%s' with regex '%s' from response '%s'" % (self._matched_prompt, self._matched_pattern, response)) if not errored_response: return True