Add-audit-progress-logging (#1416)

* Improve logging of object loading

* Fixes #1415

* Don't request same component tree 4 times to detect project type

* Fix log on project type

* Improve pro_type algo

* Fixes #1417

Author: okorach

sonar/platform.py

@@ -35,7 +35,7 @@
 import tempfile
 import requests
 import jprops
-from requests import HTTPError, RequestException, Timeout
+from requests import HTTPError, RequestException
 
 import sonar.logging as log
 import sonar.utilities as util
@@ -254,8 +254,6 @@ def __run_request(
                 lvl = log.DEBUG if r.status_code in mute else log.ERROR
                 log.log(lvl, "%s (%s request)", util.error_msg(e), req_type)
                 raise e
-        except Timeout as e:
-            util.exit_fatal(str(e), errcodes.HTTP_TIMEOUT)
         except (ConnectionError, RequestException) as e:
             if exit_on_error:  # or (r.status_code not in mute and r.status_code not in _NORMAL_HTTP_ERRORS):
                 util.exit_fatal(str(e), errcodes.SONAR_API)
@@ -539,9 +537,15 @@ def _audit_logs(self, audit_settings: types.ConfigSettings) -> list[Problem]:
             log.info("Logs audit is disabled, skipping logs audit...")
             return []
         log_map = {"app": "sonar.log", "ce": "ce.log", "web": "web.log", "es": "es.log"}
+        if self.edition() == "datacenter":
+            log_map.pop("es")
         problems = []
         for logtype, logfile in log_map.items():
-            logs = self.get("system/logs", params={"name": logtype}).text
+            try:
+                logs = self.get("system/logs", params={"name": logtype}).text
+            except (ConnectionError, RequestException) as e:
+                log.error("%s while retrieving %s logs", util.error_msg(e), logtype)
+                continue
             for line in logs.splitlines():
                 log.debug("Inspection log line %s", line)
                 try:

sonar/projects.py

@@ -578,21 +578,19 @@ def get_type(self) -> str:
             if "gradle" in comp["name"]:
                 return "GRADLE"
         data = json.loads(self.get(api=_TREE_API, params={"component": self.key, "ps": 500}).text)
+        projtype = "UNKNOWN"
         for comp in data["components"]:
             if re.match(r".*\.(cs|csx|vb)$", comp["name"]):
-                log.info("%s is a DOTNET project", str(self))
-                return "DOTNET"
-        data = json.loads(self.get(api=_TREE_API, params={"component": self.key, "ps": 500}).text)
-        for comp in data["components"]:
+                projtype = "DOTNET"
+                break
             if re.match(r".*\.(java)$", comp["name"]):
-                log.info("%s is a JAVA project", str(self))
-                return "JAVA"
-        data = json.loads(self.get(api=_TREE_API, params={"component": self.key, "ps": 500}).text)
-        for comp in data["components"]:
+                projtype = "JAVA"
+                break
             if re.match(r".*\.(py|rb|cbl|vbs|go|js|ts)$", comp["name"]):
-                log.info("%s is a DOTNET project", str(self))
-                return "CLI"
-        return "UNKNOWN"
+                projtype = "CLI"
+                break
+        log.info("%s is a %s project", str(self), projtype)
+        return projtype
 
     def last_task(self) -> Optional[tasks.Task]:
         """Returns the last analysis background task of a problem, or none if not found"""
@@ -667,10 +665,7 @@ def audit(self, audit_settings: types.ConfigSettings) -> list[Problem]:
             problems += self.__audit_binding_valid(audit_settings)
             problems += self.__audit_scanner(audit_settings)
         except (ConnectionError, RequestException) as e:
-            if isinstance(e, HTTPError) and e.response.status_code == HTTPStatus.FORBIDDEN:
-                log.error("Not enough permission to fully audit %s", str(self))
-            else:
-                log.error("%s while auditing %s", util.error_msg(e), str(self))
+            log.error("%s while auditing %s", util.error_msg(e), str(self))
         return problems
 
     def export_zip(self, timeout: int = 180) -> dict[str, str]:
@@ -1430,9 +1425,10 @@ def __audit_thread(queue: Queue[Project], results: list[Problem], audit_settings
                 bindings[bindkey] = project
         except (ConnectionError, RequestException) as e:
             log.error("%s while auditing %s", util.error_msg(e), str(project))
+        __increment_processed(audit_settings)
         queue.task_done()
-        log.debug("%s audit complete", str(project))
-    log.debug("Queue empty, exiting thread")
+
+    log.debug("Audit of projects completed")
 
 
 def audit(endpoint: pf.Platform, audit_settings: types.ConfigSettings, key_list: types.KeyList = None) -> list[Problem]:
@@ -1448,6 +1444,8 @@ def audit(endpoint: pf.Platform, audit_settings: types.ConfigSettings, key_list:
     plist = get_list(endpoint, key_list)
     problems = []
     q = Queue(maxsize=0)
+    audit_settings["NBR_PROJECTS"] = len(plist)
+    audit_settings["PROCESSED"] = 0
     for p in plist.values():
         q.put(p)
     bindings = {}
@@ -1469,6 +1467,15 @@ def audit(endpoint: pf.Platform, audit_settings: types.ConfigSettings, key_list:
     return problems
 
 
+def __increment_processed(counters: dict[str, str]) -> None:
+    """Increments the counter of processed projects and display log"""
+    with _CLASS_LOCK:
+        counters["PROCESSED"] += 1
+    nb, tot = counters["PROCESSED"], counters["NBR_PROJECTS"]
+    lvl = log.INFO if nb % 10 == 0 or tot - nb < 10 else log.DEBUG
+    log.log(lvl, "%d/%d projects exported (%d%%)", nb, tot, (nb * 100) // tot)
+
+
 def __export_thread(queue: Queue[Project], results: dict[str, str], export_settings: types.ConfigSettings, write_q: Optional[Queue] = None) -> None:
     """Project export callback function for multitheaded export"""
     while not queue.empty():
@@ -1479,11 +1486,7 @@ def __export_thread(queue: Queue[Project], results: dict[str, str], export_setti
         else:
             results[project.key] = exp_json
             results[project.key].pop("key", None)
-        with _CLASS_LOCK:
-            export_settings["EXPORTED"] += 1
-        nb, tot = export_settings["EXPORTED"], export_settings["NBR_PROJECTS"]
-        lvl = log.INFO if nb % 10 == 0 or tot - nb < 10 else log.DEBUG
-        log.log(lvl, "%d/%d projects exported (%d%%)", nb, tot, (nb * 100) // tot)
+        __increment_processed(export_settings)
         queue.task_done()
     log.info("Project export queue empty, export complete")
 

sonar/sqobject.py

@@ -135,7 +135,7 @@ def search_objects(endpoint: object, object_class: any, params: types.ApiParams,
     data = json.loads(endpoint.get(api, params=new_params).text)
     nb_pages = utilities.nbr_pages(data)
     nb_objects = max(len(data[returned_field]), utilities.nbr_total_elements(data))
-    log.info("%d %s to load", nb_objects, object_class.__name__)
+    log.info("Loading %d %ss...", nb_objects, object_class.__name__)
     for obj in data[returned_field]:
         if object_class.__name__ in ("Portfolio", "Group", "QualityProfile", "User", "Application", "Project", "Organization"):
             objects_list[obj[key_field]] = object_class.load(endpoint=endpoint, data=obj)