chore: Improve and simplify logging

* Card ID: CCT-705

This patch will help us with identifying what is happening at given
times.

- Include phase, version and arguments on each phase load.
  Some of the information may not be necessary, as newer builds of
  insights-client contain logs that carry the information about phase
  and version. However, older builds do not, and these bits are valuable
  when debugging.

- Include payloads, headers and file attachments in the log message, if
  present. This should make it easier to debug PATCH calls.
  BASIC authentication credentials are not included in these headers,
  the library adds them later when constructing the request.

- Disable logging of HTTP responses for checkin. It is verbose and do
  not need to be logged in a file every time.

Signed-off-by: mhorky <[email protected]>

insights/client/__init__.py

@@ -50,6 +50,14 @@ def __init__(self, config=None, from_phase=True, **kwargs):
         if from_phase:
             _init_client_config_dirs()
             self.set_up_logging()
+            logger.debug(
+                "phase={phase}, version={version};{path}, arguments={arguments}".format(
+                    phase=os.getenv("INSIGHTS_PHASE", "unknown"),
+                    version=package_info.get("VERSION", "unknown"),
+                    path=client.__file__,
+                    arguments=" ".join(sys.argv[1:]),
+                )
+            )
             try_auto_configuration(self.config)
             self.initialize_tags()
         else:  # from wrapper

insights/client/connection.py

@@ -170,13 +170,28 @@ def _http_request(self, url, method, log_response_text=True, **kwargs):
         Returns
             HTTP response object
         '''
-        logger.log(NETWORK, "%s %s", method, url)
+        log_message = "{method} {url}".format(method=method, url=url)
+        if "data" in kwargs.keys():
+            log_message += " data={data}".format(data=kwargs["data"])
+        if "json" in kwargs.keys():
+            log_message += " json={json}".format(json=json.dumps(kwargs["json"]))
+        if "headers" in kwargs.keys():
+            log_message += " headers={headers}".format(headers=kwargs["headers"])
+        if "files" in kwargs.keys():
+            attachments = []
+            for name, content in six.iteritems(kwargs["files"]):
+                if isinstance(content, tuple):
+                    attachments.append("{name}:{file}".format(name=name, file=content[0]))
+                else:
+                    attachments.append(name)
+            log_message += " attachments={files}".format(files=",".join(attachments))
+        logger.log(NETWORK, log_message)
         try:
             res = self.session.request(url=url, method=method, timeout=self.config.http_timeout, **kwargs)
         except Exception:
             raise
         logger.log(NETWORK, "HTTP Status: %d %s", res.status_code, res.reason)
-        if log_response_text or res.status_code != 200:
+        if log_response_text or res.status_code // 100 != 2:
             logger.log(NETWORK, "HTTP Response Text: %s", res.text)
         return res
 
@@ -1143,7 +1158,12 @@ def checkin(self):
         url = self.inventory_url + "/hosts/checkin"
         logger.debug("Sending check-in request to %s with %s" % (url, canonical_facts))
         try:
-            response = self.post(url, headers={"Content-Type": "application/json"}, data=json.dumps(canonical_facts))
+            response = self.post(
+                url,
+                headers={"Content-Type": "application/json"},
+                data=json.dumps(canonical_facts),
+                log_response_text=False,
+            )
             # Change to POST when the API is fixed.
         except REQUEST_FAILED_EXCEPTIONS as exception:
             _api_request_failed(exception)

insights/client/phase/v1.py

@@ -7,7 +7,6 @@
 import sys
 import runpy
 
-import insights
 from insights.client import InsightsClient
 from insights.client.config import InsightsConfig
 from insights.client.constants import InsightsConstants as constants
@@ -28,9 +27,6 @@ def _f():
             sys.stderr.write('ERROR: ' + str(e) + '\n')
             sys.exit(constants.sig_kill_bad)
 
-        logger.debug("Core path: %s", os.path.dirname(insights.__path__[0]))
-        logger.debug("Core version: %s", client.version())
-
         try:
             func(client, config)
         except Exception:

insights/tests/client/connection/test_checkin.py

@@ -47,7 +47,7 @@ def test_canonical_facts_request(get_proxies, post, get_canonical_facts, rm_conf
     expected_headers = {"Content-Type": "application/json"}
     expected_data = get_canonical_facts.return_value
     post.assert_called_once_with(
-        expected_url, headers=expected_headers, data=dumps(expected_data)
+        expected_url, headers=expected_headers, data=dumps(expected_data), log_response_text=False
     )
 
 
@@ -78,7 +78,7 @@ def test_canonical_facts_request_cleaned(get_proxies, post, get_canonical_facts,
     expected_data = get_canonical_facts.return_value
     expected_data = connection._clean_facts(expected_data)
     post.assert_called_once_with(
-        expected_url, headers=expected_headers, data=dumps(expected_data)
+        expected_url, headers=expected_headers, data=dumps(expected_data), log_response_text=False
     )
 
 
@@ -106,7 +106,7 @@ def test_insights_id_request(get_proxies, post, get_canonical_facts, generate_ma
     expected_headers = {"Content-Type": "application/json"}
     expected_data = {"insights_id": generate_machine_id.return_value}
     post.assert_called_once_with(
-        expected_url, headers=expected_headers, data=dumps(expected_data)
+        expected_url, headers=expected_headers, data=dumps(expected_data), log_response_text=False
     )