SCANPY-135 Add log messages through the code (#175)

Author: thomas-serre-sonarsource

src/pysonar_scanner/__main__.py

@@ -18,6 +18,7 @@
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
 
+import logging
 from pysonar_scanner import app_logging
 from pysonar_scanner import cache
 from pysonar_scanner import exceptions
@@ -48,7 +49,7 @@ def scan():
 
 def do_scan():
     app_logging.setup()
-
+    logging.info("Starting Pysonar, the Sonar scanner CLI for Python")
     config = ConfigurationLoader.load()
     set_logging_options(config)
 
@@ -57,10 +58,12 @@ def do_scan():
     api = build_api(config)
     check_version(api)
     update_config_with_api_urls(config, api.base_urls)
+    logging.debug(f"Final loaded configuration: {config}")
 
     cache_manager = cache.get_cache(config)
     scanner = create_scanner_engine(api, cache_manager, config)
 
+    logging.info("Starting the analysis...")
     return scanner.run(config)
 
 
@@ -76,8 +79,11 @@ def build_api(config: dict[str, any]) -> SonarQubeApi:
 
 def check_version(api: SonarQubeApi):
     if api.is_sonar_qube_cloud():
+        logging.debug(f"SonarQube Cloud url: {api.base_urls.base_url}")
         return
     version = api.get_analysis_version()
+    logging.debug(f"SonarQube url: {api.base_urls.base_url}")
+
     if not version.does_support_bootstrapping():
         raise SQTooOldException(
             f"This scanner only supports SonarQube versions >= {MIN_SUPPORTED_SQ_VERSION}. \n"
@@ -97,6 +103,7 @@ def update_config_with_api_urls(config, base_urls: BaseUrls):
 def create_scanner_engine(api, cache_manager, config):
     jre_path = create_jre(api, cache_manager, config)
     config[SONAR_SCANNER_JAVA_EXE_PATH] = str(jre_path.path)
+    logging.debug(f"JRE path: {jre_path.path}")
     scanner_engine_path = ScannerEngineProvisioner(api, cache_manager).provision()
     scanner = ScannerEngine(jre_path, scanner_engine_path)
     return scanner

src/pysonar_scanner/api.py

@@ -24,6 +24,7 @@
 import requests
 import requests.auth
 
+from pysonar_scanner import app_logging
 from pysonar_scanner.configuration.properties import (
     SONAR_HOST_URL,
     SONAR_SCANNER_SONARCLOUD_URL,
@@ -231,7 +232,6 @@ def download_analysis_engine(self, handle: typing.BinaryIO) -> None:
         This method can raise a SonarQubeApiException if the server doesn't respond successfully.
         Alternative, if the file IO fails, an IOError or OSError can be raised.
         """
-
         try:
             res = requests.get(
                 f"{self.base_urls.api_base_url}/analysis/engine",

src/pysonar_scanner/configuration/cli.py

@@ -19,6 +19,7 @@
 #
 import argparse
 
+from pysonar_scanner import app_logging
 from pysonar_scanner.configuration import properties
 from pysonar_scanner.exceptions import UnexpectedCliArgument
 

src/pysonar_scanner/configuration/configuration_loader.py

@@ -17,8 +17,10 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+import logging
 from pathlib import Path
 
+from pysonar_scanner import app_logging
 from pysonar_scanner.configuration.cli import CliConfigurationLoader
 from pysonar_scanner.configuration.pyproject_toml import TomlConfigurationLoader
 from pysonar_scanner.configuration.properties import SONAR_PROJECT_KEY, SONAR_TOKEN, SONAR_PROJECT_BASE_DIR, Key
@@ -35,6 +37,8 @@ def get_static_default_properties() -> dict[Key, any]:
 class ConfigurationLoader:
     @staticmethod
     def load() -> dict[Key, any]:
+        logging.debug("Loading configuration properties...")
+
         # each property loader is required to return NO default values.
         # E.g. if no property has been set, an empty dict must be returned.
         # Default values should be set through the get_static_default_properties() method

src/pysonar_scanner/configuration/environment_variables.py

@@ -17,10 +17,12 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+import logging
 import os
 import json
 from typing import Dict
 
+from pysonar_scanner import app_logging
 from pysonar_scanner.configuration.properties import Key, PROPERTIES
 
 
@@ -48,10 +50,11 @@ def load_json_env_variables():
             json_params = os.environ["SONAR_SCANNER_JSON_PARAMS"]
             json_properties = json.loads(json_params)
             properties.update(json_properties)
-        except json.JSONDecodeError:
-            # If JSON is invalid, continue with regular environment variables
-            # SCANPY-135 should log the error
-            pass
+        except json.JSONDecodeError as e:
+            logging.warning(
+                f"The JSON in SONAR_SCANNER_JSON_PARAMS environment variable is invalid. The other environment variables will still be loaded. Error : {e}"
+            )
+    logging.debug("Loaded environment properties: " + ", ".join(f"{key}={value}" for key, value in properties.items()))
     return properties
 
 

src/pysonar_scanner/configuration/pyproject_toml.py

@@ -17,9 +17,11 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+import logging
 from pathlib import Path
 from typing import Dict
 import os
+from pysonar_scanner import app_logging
 import tomli
 
 from pysonar_scanner.configuration import properties
@@ -39,8 +41,9 @@ class TomlConfigurationLoader:
     def load(base_dir: Path) -> TomlProperties:
         filepath = base_dir / "pyproject.toml"
         if not os.path.isfile(filepath):
+            logging.debug(f"No pyproject.toml at {filepath}")
             return TomlProperties({}, {})
-
+        logging.debug(f"pyproject.toml loaded from {filepath}")
         try:
             with open(filepath, "rb") as f:
                 toml_dict = tomli.load(f)
@@ -49,9 +52,10 @@ def load(base_dir: Path) -> TomlProperties:
             # Look for general project configuration
             project_properties = TomlConfigurationLoader.__read_project_properties(toml_dict)
             return TomlProperties(sonar_properties, project_properties)
-        except Exception:
-            # If there's any error parsing the TOML file, return empty TomlProperties
-            # SCANPY-135: We should log the pyproject.toml parsing error
+        except Exception as e:
+            logging.warning(
+                f"There was an error reading the pyproject.toml file. No properties from the TOML file were extracted. Error: {e}"
+            )
             return TomlProperties({}, {})
 
     @staticmethod

src/pysonar_scanner/configuration/sonar_project_properties.py

@@ -17,6 +17,7 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+import logging
 from pathlib import Path
 from typing import Dict
 import os
@@ -26,8 +27,10 @@
 def load(base_dir: Path) -> Dict[str, str]:
     filepath = base_dir / "sonar-project.properties"
     if not os.path.isfile(filepath):
+        logging.debug(f"no sonar-project.properties file found at {filepath}")
         return {}
 
+    logging.debug(f"sonar-project.properties loaded from {filepath}")
     props = Properties()
     with open(filepath, "rb") as f:
         props.load(f)

src/pysonar_scanner/jre.py

@@ -17,6 +17,7 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+import logging
 import pathlib
 import shutil
 import tarfile
@@ -67,6 +68,7 @@ def provision(self) -> JREResolvedPath:
     def __attempt_provisioning_jre_with_retry(self) -> tuple[JRE, pathlib.Path]:
         jre_and_resolved_path = self.__attempt_provisioning_jre()
         if jre_and_resolved_path is None:
+            logging.warning("Something went wrong while provisionning the JRE. Retrying...")
             jre_and_resolved_path = self.__attempt_provisioning_jre()
         if jre_and_resolved_path is None:
             raise ChecksumException.create("JRE")

src/pysonar_scanner/scannerengine.py

@@ -25,6 +25,7 @@
 from threading import Thread
 from typing import IO, Callable, Optional
 
+from pysonar_scanner import app_logging
 from pysonar_scanner.api import SonarQubeApi
 from pysonar_scanner.cache import Cache, CacheFile
 from pysonar_scanner.exceptions import ChecksumException
@@ -115,6 +116,7 @@ def provision(self) -> pathlib.Path:
         if scanner_file is not None:
             return scanner_file.filepath
         # Retry once in case the checksum failed due to the scanner engine being updated between getting the checksum and downloading the jar
+        logging.warning("Something went wrong while downloading the scanner engine. Retrying...")
         scanner_file = self.__download_and_verify()
         if scanner_file is not None:
             return scanner_file.filepath
@@ -125,6 +127,7 @@ def __download_and_verify(self) -> Optional[CacheFile]:
         engine_info = self.api.get_analysis_engine()
         cache_file = self.cache.get_file(engine_info.filename, engine_info.sha256)
         if not cache_file.is_valid():
+            logging.debug("No valid cached analysis engine jar was found")
             self.__download_scanner_engine(cache_file)
         return cache_file if cache_file.is_valid() else None
 
@@ -140,7 +143,9 @@ def __init__(self, jre_path: JREResolvedPath, scanner_engine_path: pathlib.Path)
 
     def run(self, config: dict[str, any]):
         cmd = self.__build_command(self.jre_path, self.scanner_engine_path)
+        logging.debug(f"Command: {cmd}")
         properties_str = self.__config_to_json(config)
+        logging.debug(f"Properties: {properties_str}")
         return CmdExecutor(cmd, properties_str).execute()
 
     def __build_command(self, jre_path: JREResolvedPath, scanner_engine_path: pathlib.Path) -> list[str]:

tests/test_environment_variables.py

@@ -17,8 +17,9 @@
 # along with this program; if not, write to the Free Software Foundation,
 # Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
 #
+from json import JSONDecodeError
 import unittest
-from unittest.mock import patch
+from unittest.mock import MagicMock, patch
 
 from pysonar_scanner.configuration import environment_variables
 from pysonar_scanner.configuration.properties import (
@@ -105,13 +106,19 @@ def test_environment_variables_from_json_params(self):
             self.assertEqual(len(properties), 2)
             self.assertDictEqual(properties, expected_properties)
 
-    def test_invalid_json_params(self):
+    @patch("pysonar_scanner.configuration.environment_variables.logging")
+    def test_invalid_json_params(self, mock_logging):
+
         env = {"SONAR_SCANNER_JSON_PARAMS": '{"sonar.token": "json-token"'}
         with patch.dict("os.environ", env, clear=True):
             properties = environment_variables.load()
             self.assertEqual(len(properties), 0)
             self.assertDictEqual(properties, {})
 
+        mock_logging.warning.assert_called_once_with(
+            "The JSON in SONAR_SCANNER_JSON_PARAMS environment variable is invalid. The other environment variables will still be loaded. Error : Expecting ',' delimiter: line 1 column 29 (char 28)",
+        )
+
     def test_environment_variables_priority_over_json_params(self):
         env = {
             "SONAR_TOKEN": "regular-token",  # This should take priority