Fix trace all api calls

conans/client/rest/conan_requester.py

@@ -3,8 +3,12 @@
 import requests
 import platform
 
+import time
+
 from conans.util.files import save
 from conans import __version__ as client_version
+from conans.util.tracer import log_client_rest_api_call
+
 
 class ConanRequester(object):
 
@@ -58,7 +62,7 @@ def _add_kwargs(self, url, kwargs):
         if self._timeout_seconds:
             kwargs["timeout"] = self._timeout_seconds
         if not kwargs.get("headers"):
-            kwargs["headers"]  = {}
+            kwargs["headers"] = {}
         kwargs["headers"]["User-Agent"] = "Conan/%s (Python %s) %s" % (client_version,
                                                                        platform.python_version(),
                                                                        requests.utils.default_user_agent())
@@ -85,7 +89,12 @@ def _call_method(self, method, url, **kwargs):
                 popped = popped or os.environ.pop(var_name, None)
                 popped = popped or os.environ.pop(var_name.upper(), None)
         try:
-            return getattr(self._requester, method)(url, **self._add_kwargs(url, kwargs))
+            t1 = time.time()
+            all_kwargs = self._add_kwargs(url, kwargs)
+            tmp = getattr(self._requester, method)(url, **all_kwargs)
+            duration = time.time() - t1
+            log_client_rest_api_call(url, method.upper(), duration, all_kwargs.get("headers"))
+            return tmp
         finally:
             if popped:
                 os.environ.clear()

conans/client/rest/rest_client_common.py

@@ -10,11 +10,10 @@
 from conans.errors import (EXCEPTION_CODE_MAPPING, NotFoundException, ConanException,
                            AuthenticationException)
 from conans.model.manifest import FileTreeManifest
-from conans.model.ref import ConanFileReference, PackageReference
+from conans.model.ref import ConanFileReference
 from conans.search.search import filter_packages
 from conans.util.files import decode_text, load
 from conans.util.log import logger
-from conans.util.tracer import log_client_rest_api_call
 
 
 class JWTAuth(AuthBase):
@@ -84,7 +83,6 @@ def authenticate(self, user, password):
         """Sends user + password to get a token"""
         auth = HTTPBasicAuth(user, password)
         url = "%s/users/authenticate" % self.remote_api_url
-        t1 = time.time()
         ret = self.requester.get(url, auth=auth, headers=self.custom_headers,
                                  verify=self.verify_ssl)
         if ret.status_code == 401:
@@ -93,20 +91,15 @@ def authenticate(self, user, password):
         if not ret.ok or "html>" in str(ret.content):
             raise ConanException("%s\n\nInvalid server response, check remote URL and "
                                  "try again" % str(ret.content))
-        duration = time.time() - t1
-        log_client_rest_api_call(url, "GET", duration, self.custom_headers)
         return ret
 
     @handle_return_deserializer()
     def check_credentials(self):
         """If token is not valid will raise AuthenticationException.
         User will be asked for new user/pass"""
         url = "%s/users/check_credentials" % self.remote_api_url
-        t1 = time.time()
         ret = self.requester.get(url, auth=self.auth, headers=self.custom_headers,
                                  verify=self.verify_ssl)
-        duration = time.time() - t1
-        log_client_rest_api_call(url, "GET", duration, self.custom_headers)
         return ret
 
     def server_info(self):
@@ -125,7 +118,6 @@ def server_info(self):
         return version_check, server_version, server_capabilities
 
     def get_json(self, url, data=None):
-        t1 = time.time()
         headers = self.custom_headers
         if data:  # POST request
             headers.update({'Content-type': 'application/json',
@@ -140,9 +132,6 @@ def get_json(self, url, data=None):
                                           verify=self.verify_ssl,
                                           stream=True)
 
-        duration = time.time() - t1
-        method = "POST" if data else "GET"
-        log_client_rest_api_call(url, method, duration, headers)
         if response.status_code != 200:  # Error message is text
             response.charset = "utf-8"  # To be able to access ret.text (ret.content are bytes)
             raise get_exception_from_error(response.status_code)(response.text)

conans/test/functional/conan_trace_file_test.py

@@ -92,21 +92,42 @@ def test_trace_actions(self):
         self.assertIn('"Authorization": "**********"', traces)
         self.assertIn('"X-Client-Anonymous-Id": "**********"', traces)
         actions = traces.splitlines()
-        self.assertTrue(len(actions) in [20, 16])  # APIv1 vs APIv2
+        without_rest_api = [it for it in actions if "REST_API_CALL" not in it]
+        self.assertTrue(len(without_rest_api) == 11)
         for trace in actions:
             doc = json.loads(trace)
             self.assertIn("_action", doc)  # Valid jsons
 
-        self.assertEquals(json.loads(actions[0])["_action"], "COMMAND")
-        self.assertEquals(json.loads(actions[0])["name"], "authenticate")
-
-        self.assertEquals(json.loads(actions[3])["_action"], "COMMAND")
-        self.assertEquals(json.loads(actions[3])["name"], "export")
-
-        self.assertEquals(json.loads(actions[4])["_action"], "COMMAND")
-        self.assertEquals(json.loads(actions[4])["name"], "install_reference")
-
-        self.assertEquals(json.loads(actions[5])["_action"], "GOT_RECIPE_FROM_LOCAL_CACHE")
-        self.assertEquals(json.loads(actions[5])["_id"], "Hello0/0.1@lasote/stable")
-
-        self.assertEquals(json.loads(actions[-1])["_action"], "UPLOADED_PACKAGE")
+        self.assertEquals(json.loads(without_rest_api[0])["_action"], "COMMAND")
+        self.assertEquals(json.loads(without_rest_api[0])["name"], "authenticate")
+        self.assertEquals(json.loads(without_rest_api[2])["_action"], "COMMAND")
+        self.assertEquals(json.loads(without_rest_api[2])["name"], "export")
+        self.assertEquals(json.loads(without_rest_api[3])["_action"], "COMMAND")
+        self.assertEquals(json.loads(without_rest_api[3])["name"], "install_reference")
+        self.assertEquals(json.loads(without_rest_api[4])["_action"], "GOT_RECIPE_FROM_LOCAL_CACHE")
+        self.assertEquals(json.loads(without_rest_api[4])["_id"], "Hello0/0.1@lasote/stable")
+        self.assertEquals(json.loads(without_rest_api[5])["_action"], "PACKAGE_BUILT_FROM_SOURCES")
+        self.assertEquals(json.loads(without_rest_api[6])["_action"], "COMMAND")
+        self.assertEquals(json.loads(without_rest_api[6])["name"], "upload")
+        self.assertEquals(json.loads(without_rest_api[7])["_action"], "ZIP")
+        self.assertEquals(json.loads(without_rest_api[8])["_action"], "UPLOADED_RECIPE")
+        self.assertEquals(json.loads(without_rest_api[9])["_action"], "ZIP")
+        self.assertEquals(json.loads(without_rest_api[10])["_action"], "UPLOADED_PACKAGE")
+
+        num_put = len([it for it in actions if "REST_API_CALL" in it and "PUT" in it])
+        self.assertEquals(num_put, 6)   # 3 files the recipe 3 files the package
+
+        num_post = len([it for it in actions if "REST_API_CALL" in it and "POST" in it])
+        if "/v2/" in traces:
+            self.assertEquals(num_post, 0)
+        else:
+            self.assertEquals(num_post, 2)  # 2 get urls
+
+        num_get = len([it for it in actions if "REST_API_CALL" in it and "GET" in it])
+        self.assertEquals(num_get, 10)
+
+        # Check masked signature
+        for action in actions:
+            doc = json.loads(action)
+            if doc.get("url") and "signature" in doc.get("url"):
+                self.assertIn("signature=*****", doc.get("url"))

conans/util/tracer.py

@@ -136,6 +136,8 @@ def log_client_rest_api_call(url, method, duration, headers):
     headers = copy.copy(headers)
     headers["Authorization"] = MASKED_FIELD
     headers["X-Client-Anonymous-Id"] = MASKED_FIELD
+    if "signature=" in url:
+        url = url.split("signature=")[0] + "signature=%s" % MASKED_FIELD
     _append_action("REST_API_CALL", {"method": method, "url": url,
                                      "duration": duration, "headers": headers})