Repository: ansible/ansible
Pull request: Raise exception if command timeout is triggered


##### SUMMARY
<!--- Describe the change, including rationale and design decisions -->
Fixes #43076

If persistent connection timeout is triggered, riase
exception which will be send over socket to module code
instead of silently shutting down the socket.
<!--- If you are fixing an existing issue, please include "Fixes #nnn" in your
commit message and your description; but you should still explain what
the change does.-->

##### ISSUE TYPE
<!--- Pick one below and delete the rest: -->
 - Bugfix Pull Request

##### COMPONENT NAME
<!--- Name of the module, plugin, module or task -->
bin/ansible-connection

##### ANSIBLE VERSION
<!--- Paste verbatim output from "ansible --version" between quotes below -->
```
2.7
```


##### ADDITIONAL INFORMATION
<!--- Include additional information to help people understand the change here.
For bugs that don't have a linked bug report, a step-by-step reproduction
of the problem is helpful. -->

<!--- Paste verbatim command output below, e.g. before and after your change -->
Before:
```
ok: [ios] => {
    "changed": false,
    "invocation": {
        "module_args": {
            "auth_pass": null,
            "authorize": null,
            "commands": [
                "show running-config all"
            ],
            "host": null,
            "interval": 1,
            "match": "all",
            "password": null,
            "port": null,
            "provider": null,
            "retries": 10,
            "ssh_keyfile": null,
            "timeout": null,
            "username": null,
            "wait_for": null
        }
    },
    "stdout": [
        "None"
    ],
    "stdout_lines": [
        [
            "None"
        ]
    ]
}
```
After:
```
[ios]: FAILED! => {
    "changed": false,
    "module_stderr": "Traceback (most recent call last):\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_module_ios_command.py\", line 247, in <module>\n    main()\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_module_ios_command.py\", line 217, in main\n    responses = run_commands(module, commands)\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_modlib.zip/ansible/module_utils/network/ios/ios.py\", line 125, in run_commands\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_modlib.zip/ansible/module_utils/connection.py\", line 149, in __rpc__\nansible.module_utils.connection.ConnectionError: command timeout triggered, timeout value is 1 secs\n",
    "module_stdout": "",
    "msg": "MODULE FAILURE",
    "rc": 1
}
```


Problem statement:
ios_command return empty output if persistent socket timeout is triggered 
<!---
Verify first that your issue/request is not already reported on GitHub.
THIS FORM WILL BE READ BY A MACHINE, COMPLETE ALL SECTIONS AS DESCRIBED.
Also test if the latest release, and devel branch are affected too.
ALWAYS add information AFTER (OUTSIDE) these html comments.
Otherwise it may end up being automatically closed by our bot. -->

##### SUMMARY
<!--- Explain the problem briefly -->
If a command timeout triggers and persistent socket is closed is results in empty output

##### ISSUE TYPE
 - Bug Report

##### COMPONENT NAME
<!--- Insert, BELOW THIS COMMENT, the name of the module, plugin, task or feature.
Do not include extra details here, e.g. "vyos_command" not "the network module vyos_command" or the full path-->
bin/ansible-connection

##### ANSIBLE VERSION
<!--- Paste, BELOW THIS COMMENT, verbatim output from "ansible --version" between quotes below -->
```
2.7
```

##### CONFIGURATION
<!--- If using Ansible 2.4 or above, paste, BELOW THIS COMMENT, the results of "ansible-config dump --only-changed"
Otherwise, mention any settings you have changed/added/removed in ansible.cfg
(or using the ANSIBLE_* environment variables).-->

##### OS / ENVIRONMENT
<!--- Mention, BELOW THIS COMMENT, the OS you are running Ansible from, and the OS you are
managing, or say "N/A" for anything that is not platform-specific.
Also mention the specific version of what you are trying to control,
e.g. if this is a network bug the version of firmware on the network device.-->

##### STEPS TO REPRODUCE
<!--- For bugs, show exactly how to reproduce the problem, using a minimal test-case.
For new features, show how the feature would be used. -->

<!--- Paste example playbooks or commands between quotes below -->
```yaml
  tasks:
  - name: fetch running config
    ios_command:
      commands: 
        - show running-config all
    vars:
      ansible_command_timeout: 1
```

<!--- You can also paste gist.github.com links for larger files -->

##### EXPECTED RESULTS
<!--- What did you expect to happen when running the steps above? -->
```
[ios]: FAILED! => {
    "changed": false,
    "module_stderr": "Traceback (most recent call last):\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_module_ios_command.py\", line 247, in <module>\n    main()\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_module_ios_command.py\", line 217, in main\n    responses = run_commands(module, commands)\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_modlib.zip/ansible/module_utils/network/ios/ios.py\", line 125, in run_commands\n  File \"/var/folders/8l/27cd4l3n2vnc2cpk3498__680000gn/T/ansible_BoEKEj/ansible_modlib.zip/ansible/module_utils/connection.py\", line 149, in __rpc__\nansible.module_utils.connection.ConnectionError: command timeout triggered, timeout value is 1 secs\n",
    "module_stdout": "",
    "msg": "MODULE FAILURE",
    "rc": 1
}
```
##### ACTUAL RESULTS
<!--- What actually happened? If possible run with extra verbosity (-vvvv) -->

<!--- Paste verbatim command output between quotes below -->
```
ok: [ios] => {
    "changed": false,
    "invocation": {
        "module_args": {
            "auth_pass": null,
            "authorize": null,
            "commands": [
                "show running-config all"
            ],
            "host": null,
            "interval": 1,
            "match": "all",
            "password": null,
            "port": null,
            "provider": null,
            "retries": 10,
            "ssh_keyfile": null,
            "timeout": null,
            "username": null,
            "wait_for": null
        }
    },
    "stdout": [
        "None"
    ],
    "stdout_lines": [
        [
            "None"
        ]
    ]
}
```

Hints from issue discussion:
Files identified in the description:
* [bin/ansible-connection](https://github.com/ansible/ansible/blob/devel/bin/ansible-connection)

If these files are inaccurate, please update the `component name` section of the description or use the `!component` bot command.

[click here for bot help](https://github.com/ansible/ansibullbot/blob/master/ISSUE_HELP.md)
<!--- boilerplate: components_banner --->

Commit message: Fix review comment

Patch to review:
diff --git a/bin/ansible-connection b/bin/ansible-connection
index f77e3f2fe6f0be..8c9375cdc3fbb4 100755
--- a/bin/ansible-connection
+++ b/bin/ansible-connection
@@ -16,6 +16,7 @@ import os
 import signal
 import socket
 import sys
+import time
 import traceback
 import errno
 import json
@@ -34,6 +35,8 @@ from ansible.utils.path import unfrackpath, makedirs_safe
 from ansible.utils.display import Display
 from ansible.utils.jsonrpc import JsonRpcServer
 
+TIMEOUT_TROUBLESHOOT_URL = "https://docs.ansible.com/ansible/latest/network/user_guide/network_debug_troubleshooting.html#timeout-issues"
+
 
 @contextmanager
 def file_lock(lock_path):
@@ -136,22 +139,28 @@ class ConnectionProcess(object):
                 self.exception = traceback.format_exc()
 
         finally:
-            # when done, close the connection properly and cleanup
-            # the socket file so it can be recreated
+            # allow time for any exception msg send over socket to receive at other end before shutting down
+            time.sleep(0.1)
+
+            # when done, close the connection properly and cleanup the socket file so it can be recreated
             self.shutdown()
 
     def connect_timeout(self, signum, frame):
-        display.display('persistent connection idle timeout triggered, timeout value is %s secs'
-                        % self.connection.get_option('persistent_connect_timeout'), log_only=True)
-        self.shutdown()
+        msg = 'persistent connection idle timeout triggered, timeout value is %s secs.\nFor more details refer %s' %\
+              (self.connection.get_option('persistent_connect_timeout'), TIMEOUT_TROUBLESHOOT_URL)
+        display.display(msg, log_only=True)
+        raise Exception(msg)
 
     def command_timeout(self, signum, frame):
-        display.display('command timeout triggered, timeout value is %s secs' % self.connection.get_option('persistent_command_timeout'), log_only=True)
-        self.shutdown()
+        msg = 'command timeout triggered, timeout value is %s secs.\nFor more details refer %s' %\
+              (self.connection.get_option('persistent_command_timeout'), TIMEOUT_TROUBLESHOOT_URL)
+        display.display(msg, log_only=True)
+        raise Exception(msg)
 
     def handler(self, signum, frame):
-        display.display('signal handler called with signal %s' % signum, log_only=True)
-        self.shutdown()
+        msg = 'signal handler called with signal %s.\nFor more details refer %s' % (signum, TIMEOUT_TROUBLESHOOT_URL)
+        display.display(msg, log_only=True)
+        raise Exception(msg)
 
     def shutdown(self):
         """ Shuts down the local domain socket


Code review comments:
diff_hunk: @@ -136,22 +139,28 @@ class ConnectionProcess(object):
                 self.exception = traceback.format_exc()
 
         finally:
-            # when done, close the connection properly and cleanup
-            # the socket file so it can be recreated
+            # allow time for any exception msg send over socket to receive at other end before shutting down
+            time.sleep(0.1)
+
+            # when done, close the connection properly and cleanup the socket file so it can be recreated
             self.shutdown()
 
     def connect_timeout(self, signum, frame):
-        display.display('persistent connection idle timeout triggered, timeout value is %s secs'
-                        % self.connection.get_option('persistent_connect_timeout'), log_only=True)
-        self.shutdown()
+        msg = 'persistent connection idle timeout triggered, timeout value is %s secs.\nFor more details refer %s' %\
+              (self.connection.get_option('persistent_connect_timeout'), TIMEOUT_TROUBLESHOOT_URL)
+        display.display(msg, log_only=True)
+        raise Exception(msg)
 
     def command_timeout(self, signum, frame):
-        display.display('command timeout triggered, timeout value is %s secs' % self.connection.get_option('persistent_command_timeout'), log_only=True)
-        self.shutdown()
+        msg = 'command timeout triggered, timeout value is %s secs.\nFor more details refer %s' %\
+              (self.connection.get_option('persistent_command_timeout'), TIMEOUT_TROUBLESHOOT_URL)
+        display.display(msg, log_only=True)
+        raise Exception(msg)
 
     def handler(self, signum, frame):
-        display.display('signal handler called with signal %s' % signum, log_only=True)
-        self.shutdown()
+        msg = 'signal handler called with signal %s.\nFor more details refer %s' % (signum, TIMEOUT_TROUBLESHOOT_URL)
path: bin/ansible-connection
text: @user1:
The url discussion aside, I really don't think we need it here- this is not a timeout, it's SIGTERM.

@author:
Good catch