adding option to debug http logging

pass timeout and operation timeout to file copier

contents/winrm-exec.py

@@ -19,10 +19,22 @@ def filter(self, record):
 
 try:
     from urllib3.connectionpool import log
-    log.addFilter(SuppressFilter())
+    #log.addFilter(SuppressFilter())
 except:
     pass
 
+import http.client
+httpclient_logger = logging.getLogger("http.client")
+
+
+def httpclient_logging_patch(level=logging.DEBUG):
+    def httpclient_log(*args):
+        httpclient_logger.log(level, " ".join(args))
+
+    http.client.print = httpclient_log
+    http.client.HTTPConnection.debuglevel = 1
+
+
 #checking and importing dependencies
 ISPY3 = sys.version_info[0] == 3
 WINRM_INSTALLED = False
@@ -96,6 +108,10 @@ def filter(self, record):
 log.addHandler(console)
 log.setLevel(log_level)
 
+requests_log = logging.getLogger("requests.packages.urllib3")
+requests_log.setLevel(logging.DEBUG)
+requests_log.propagate = True
+
 parser = argparse.ArgumentParser(description='Run Bolt command.')
 parser.add_argument('hostname', help='the hostname')
 args = parser.parse_args()
@@ -118,6 +134,7 @@ def filter(self, record):
 forcefail = False
 exitBehaviour = "console"
 cleanescapingflg = False
+enabledHttpDebug = False
 
 if "RD_CONFIG_AUTHTYPE" in os.environ:
     authentication = os.getenv("RD_CONFIG_AUTHTYPE")
@@ -164,6 +181,12 @@ def filter(self, record):
      else:
         cleanescapingflg = False
 
+if "RD_CONFIG_ENABLEHTTPDEBUG" in os.environ:
+    if os.getenv("RD_CONFIG_ENABLEHTTPDEBUG") == "true":
+        enabledHttpDebug = True
+    else:
+        enabledHttpDebug = False
+
 exec_command = os.getenv("RD_EXEC_COMMAND")
 log.debug("Command will be executed: " + exec_command)
 
@@ -229,8 +252,12 @@ def filter(self, record):
 log.debug("operationtimeout:" + str(operationtimeout))
 log.debug("exit Behaviour:" + exitBehaviour)
 log.debug("cleanescapingflg: " + str(cleanescapingflg))
+log.debug("enabledHttpDebug: " + str(enabledHttpDebug))
 log.debug("------------------------------------------")
 
+if enabledHttpDebug:
+    httpclient_logging_patch(logging.DEBUG)
+
 if not URLLIB_INSTALLED:
     log.error("request and urllib3 not installed, try: pip install requests &&  pip install urllib3")
     sys.exit(1)

contents/winrm-filecopier.py

@@ -15,6 +15,7 @@
 import colored_formatter
 from colored_formatter import ColoredFormatter
 import kerberosauth
+import http.client
 
 #checking and importing dependencies
 ISPY3 = sys.version_info[0] == 3
@@ -81,14 +82,7 @@
 else:
     log_level = 'ERROR'
 
-##end
-
-
-log_level = 'INFO'
-if os.environ.get('RD_JOB_LOGLEVEL') == 'DEBUG':
-    log_level = 'DEBUG'
-else:
-    log_level = 'ERROR'
+# end
 
 console = logging.StreamHandler()
 console.setFormatter(ColoredFormatter(colored_formatter.format()))
@@ -98,6 +92,17 @@
 log.addHandler(console)
 log.setLevel(log_level)
 
+httpclient_logger = logging.getLogger("http.client")
+
+
+def httpclient_logging_patch(level=logging.DEBUG):
+    def httpclient_log(*args):
+        httpclient_logger.log(level, " ".join(args))
+
+    http.client.print = httpclient_log
+    http.client.HTTPConnection.debuglevel = 1
+
+
 def _clean_error_msg(self, msg):
     """converts a Powershell CLIXML message to a more human readable string
     """
@@ -250,6 +255,7 @@ def winrm_upload(self,
 krbdelegation = False
 forceTicket = False
 override=False
+enabledHttpDebug = False
 
 if os.environ.get('RD_CONFIG_OVERRIDE') == 'true':
     override = True
@@ -313,6 +319,21 @@ def winrm_upload(self,
     else:
         krbdelegation = False
 
+if "RD_CONFIG_READTIMEOUT" in os.environ:
+    readtimeout = os.getenv("RD_CONFIG_READTIMEOUT")
+
+if "RD_CONFIG_OPERATIONTIMEOUT" in os.environ:
+    operationtimeout = os.getenv("RD_CONFIG_OPERATIONTIMEOUT")
+
+if "RD_CONFIG_ENABLEHTTPDEBUG" in os.environ:
+    if os.getenv("RD_CONFIG_ENABLEHTTPDEBUG") == "true":
+        enabledHttpDebug = True
+    else:
+        enabledHttpDebug = False
+
+if enabledHttpDebug:
+    httpclient_logging_patch(logging.DEBUG)
+
 endpoint = transport+'://'+args.hostname+':'+port
 
 arguments = {}
@@ -327,6 +348,11 @@ def winrm_upload(self,
 
 arguments["credssp_disable_tlsv1_2"] = diabletls12
 
+if(readtimeout):
+    arguments["read_timeout_sec"] = readtimeout
+
+if(operationtimeout):
+    arguments["operation_timeout_sec"] = operationtimeout
 
 if not URLLIB_INSTALLED:
     log.error("request and urllib3 not installed, try: pip install requests &&  pip install urllib3")

plugin.yaml

@@ -183,6 +183,16 @@ providers:
         renderingOptions:
           groupName: Misc
           instance-scope-node-attribute: "clean-escaping"
+      - name: enabledhttpdebug
+        title: Enable HTTP logging in debug mode
+        description: "Print extra http logging in debug mode"
+        type: Boolean
+        default: "false"
+        required: true
+        scope: Instance
+        renderingOptions:
+          groupName: Connection
+          instance-scope-node-attribute: "winrm-enable-http-logging"
   - name: WinRMcpPython
     title: WinRM Python File Copier
     description: Copying files to remote Windows computer
@@ -262,6 +272,24 @@ providers:
         renderingOptions:
           groupName: Connection
           instance-scope-node-attribute: "winrm-certpath"
+      - name: readtimeout
+        title: connect/read times out
+        description: "maximum seconds to wait before an HTTP connect/read times out (default 30). This value should be slightly higher than operation timeout, as the server can block *at least* that long. It can be overwriting at node level using `winrm-readtimeout`"
+        type: String
+        required: false
+        scope: Instance
+        renderingOptions:
+          groupName: Connection
+          instance-scope-node-attribute: "winrm-readtimeout"
+      - name: operationtimeout
+        title: operation timeout
+        description: "maximum allowed time in seconds for any single wsman HTTP operation (default 20). Note that operation timeouts while receiving output (the only wsman operation that should take any significant time, and where these timeouts are expected) will be silently retried indefinitely. It can be overwriting at node level using `winrm-operationtimeout`"
+        type: String
+        required: false
+        scope: Instance
+        renderingOptions:
+          groupName: Connection
+          instance-scope-node-attribute: "winrm-operationtimeout"
       - name: username
         title: Username
         type: String
@@ -314,6 +342,16 @@ providers:
         required: false
         renderingOptions:
           groupName: Kerberos
+      - name: enabledhttpdebug
+        title: Enable HTTP logging in debug mode
+        description: "Print extra http logging in debug mode"
+        type: Boolean
+        default: "false"
+        required: true
+        scope: Instance
+        renderingOptions:
+          groupName: Connection
+          instance-scope-node-attribute: "winrm-enable-http-logging"
   - name: WinRMCheck
     title: WinRM Check Step
     description: Check the connection with a remote node using winrm-python