logging PR

Signed-off-by: Miguel Brandão <[email protected]>

Author: HolyMichael

deepsearch/artifacts/artifact_manager.py

@@ -1,3 +1,7 @@
+import logging
+
+logger = logging.getLogger("root.artifacts")
+
 import json
 import os
 import shutil
@@ -40,6 +44,7 @@ def get_index_path(self) -> Path:
     def get_artifact_path_in_cache(self, artifact_name: str) -> Path:
         artifact_path = self._cache_path / artifact_name
         if not artifact_path.exists():
+            logger.error(f'Artifact "{artifact_name}" not in cache')
             raise FileNotFoundError(f'Artifact "{artifact_name}" not in cache')
         return artifact_path
 
@@ -52,13 +57,18 @@ def download_artifact_to_cache(
     ) -> None:
         artifact_path = self._cache_path / artifact_name
         if artifact_path.exists():
+            logger.info(f"Artifact already in cache using {hit_strategy=}")
             if hit_strategy == self.HitStrategy.RAISE:
+                logger.error(f'Artifact "{artifact_name}" already in cache')
                 raise ValueError(f'Artifact "{artifact_name}" already in cache')
             elif hit_strategy == self.HitStrategy.PASS:
+                logger.info(f"Skipped artifact")
                 return
             elif hit_strategy == self.HitStrategy.OVERWRITE:
+                logger.info(f"Overwriting artifact")
                 shutil.rmtree(artifact_path)
             else:
+                logger.error(f'Unexcpected value "{hit_strategy=}"')
                 raise RuntimeError(f'Unexcpected value "{hit_strategy=}"')
 
         artifact_path.mkdir(exist_ok=False)
@@ -70,6 +80,7 @@ def download_artifact_to_cache(
         download_url = artifact_meta[ARTF_META_URL_FIELD]
 
         with tempfile.TemporaryDirectory() as temp_dir:
+            logger.info("Downloading artifact to temporary directory")
             download_path = self._download_file(
                 artifact_name=artifact_name,
                 download_url=download_url,
@@ -108,6 +119,7 @@ def _download_file(
         with_progress_bar: bool,
     ) -> Path:
         response = requests.get(download_url, stream=True)
+        logger.info(f"{response.status_code} response from {download_url}")
         response.raise_for_status()
 
         dl_filename = None
@@ -123,10 +135,13 @@ def _download_file(
                     dl_filename = "=".join(split_param[1:]).strip().strip("'\"")
                     break
 
-        # otherwise, use name from URL:
-        if dl_filename is None:
+        if dl_filename:
+            logger.info(f"Resolved filename from response header {dl_filename}")
+        else:
+            # otherwise, use name from URL:
             parsed_url = urlparse(download_url)
             dl_filename = Path(parsed_url.path).name
+            logger.info(f"Resolved filename from url {dl_filename}")
 
         total_size = int(response.headers.get("content-length", 0))
         block_size = 1024  # 1 KB
@@ -168,13 +183,16 @@ def _finalize_download(
                     attempt_unpack = True
 
         if attempt_unpack:
+            logger.info("Unpacking archive and moving to destination")
             shutil.unpack_archive(dl_path_str, target_path)
         else:
+            logger.info("Moving archive to destination")
             shutil.move(dl_path_str, target_path / "")
 
     def _get_artifact_meta(self, artifact_name: str) -> Dict:
         file_path = self._index_path / artifact_name / ARTF_META_FILENAME
         if not file_path.exists():
+            logger.error(f'File "{file_path}" does not exist')
             raise FileNotFoundError(f'File "{file_path}" does not exist')
         with open(file_path, "r") as file:
             meta_info = json.load(file)

deepsearch/artifacts/cli/main.py

@@ -1,3 +1,6 @@
+import logging
+
+logger = logging.getLogger("root.artifacts")
 import typer
 
 from deepsearch.artifacts.artifact_manager import (
@@ -36,6 +39,7 @@
 def list_index(
     index: str = INDEX_OPTION,
 ):
+    logger.info("Listing artifacts in index")
     artf_mgr = ArtifactManager(index=index)
     artifacts = artf_mgr.get_artifacts_in_index()
     for artf in artifacts:
@@ -47,6 +51,7 @@ def list_index(
 def list_cache(
     cache: str = CACHE_OPTION,
 ):
+    logger.info("Listing artifacts in cache")
     artf_mgr = ArtifactManager(cache=cache)
     artifacts = artf_mgr.get_artifacts_in_cache()
     for artf in artifacts:
@@ -56,6 +61,7 @@ def list_cache(
 @app.command(help="Show cache path")
 @cli_handler()
 def locate_default_cache():
+    logger.info("Resolving cache path")
     artf_mgr = ArtifactManager()
     path_str = str(artf_mgr.get_cache_path().resolve())
     typer.echo(path_str)
@@ -83,6 +89,7 @@ def download(
     unpack: bool = typer.Option(True),
     progress_bar: bool = typer.Option(True),
 ):
+    logger.info(f"Attempting to download {artifact_name=} from {index=}")
     artf_mgr = ArtifactManager(index=index, cache=cache)
     artf_mgr.download_artifact_to_cache(
         artifact_name=artifact_name,
@@ -101,6 +108,7 @@ def download_all(
     unpack: bool = typer.Option(True),
     progress_bar: bool = typer.Option(True),
 ):
+    logger.info(f"Attempting to download all artifacts from {index=}")
     artf_mgr = ArtifactManager(index=index, cache=cache)
     for artf_name in artf_mgr.get_artifacts_in_index():
         artf_mgr.download_artifact_to_cache(

deepsearch/cli.py

@@ -1,22 +1,67 @@
+import logging
+from pathlib import Path
+from typing import List
+
+from deepsearch import DeepSearchConfig
 from deepsearch.artifacts.cli.main import app as artifacts_app
 from deepsearch.core.cli.main import app
 from deepsearch.core.cli.plugins import get_cli_groups
+from deepsearch.core.util.config_paths import config_file_path
 from deepsearch.cps.cli.main import app as cps_app
 from deepsearch.documents.cli.main import app as documents_app
 from deepsearch.query.cli.main import app as query_app
 
+# TODO review if unwanted information is being logged
+
+
+def setup_logger():
+    # Setting up root logger
+    config_file = config_file_path()
+
+    if not config_file.exists():
+        raise RuntimeError(
+            f"Config file {config_file} does not exist. Please configure your default authentication with `$ deepsearch login`"
+        )
+    config = DeepSearchConfig.parse_file(config_file)
+
+    p = Path(config.log_configuration.target_file)
+    if not p.parent.is_dir():
+        p.parent.mkdir(parents=True)
+
+    handlers: List[logging.Handler] = [
+        logging.FileHandler(p),
+    ]
+    if config.log_configuration.write_to_console:
+        handlers.append(logging.StreamHandler())
+    formatter = logging.Formatter(
+        "%(asctime)s %(name)s — %(levelname)s — %(module)s:%(funcName)s:%(lineno)d — %(message)s"
+    )
+    logger = logging.getLogger("root")
+    [h.setFormatter(formatter) for h in handlers]  # type: ignore
+    [logger.addHandler(h) for h in handlers]  # type: ignore
+    [e.setLevel(logging.DEBUG) for e in (logger, *handlers)]  # type: ignore
+
+    return logger
+
+
+logger = setup_logger()
+
 app.add_typer(cps_app, name="cps", help="Interact with DeepSearch CPS component")
+logger.info("Cps module initialized")
 app.add_typer(query_app, name="query", help="Interact with DeepSearch Query component")
+logger.info("Query module initialized")
 app.add_typer(
     documents_app,
     name="documents",
     help="Interact with DeepSearch Document Conversion component",
 )
+logger.info("Documents module initialized")
 app.add_typer(artifacts_app, name="artifacts", help="Manage artifacts")
+logger.info("Artifacts module initialized")
 
 for group in get_cli_groups():
     app.add_typer(group)
-
+logger.info("Root module finished initialization")
 
 if __name__ == "__main__":
     app()

deepsearch/core/cli/main.py

@@ -1,3 +1,8 @@
+import logging
+
+logger = logging.getLogger("root.core")
+
+
 import typer
 
 import deepsearch as ds
@@ -13,10 +18,11 @@
 )
 app.add_typer(profile_app, name="profile", help="Manage profile configuration")
 app.add_typer(login_app, name="login", help=MSG_LOGIN_DEPRECATION)
-
+logger.info("Core module finished initialization")
 
 @app.command(name="version", help=f"Print the client and server version")
 def get_version():
+    logger.info("Getting DeepSearch version")
     versions = ds.version()
     typer.echo(f"Client: {versions.client}")
     typer.echo(f"Server: {versions.server}")

deepsearch/core/cli/plugins.py

@@ -1,11 +1,16 @@
+import logging
 from typing import List
 
+logger = logging.getLogger("root.core.plugins")
+
 import pluggy
 import typer
 
 deepsearch_cli_hookspec = pluggy.HookspecMarker("deepsearch_cli")
 deepsearch_cli_hookimpl = pluggy.HookimplMarker("deepsearch_cli")
 
+logger.info("Plugins module initialized")
+
 
 class DeepsearchCliPlugin:
     @deepsearch_cli_hookspec
@@ -15,10 +20,12 @@ def deepsearch_cli_add_group(self) -> typer.Typer:
 
         :return: A typer.Typer instance with a name set.
         """
+        logger.error("Feature not implemented")
         raise NotImplementedError
 
 
 def get_cli_plugin_manager():
+    logger.info("getting cli plugin manager")
     manager = pluggy.PluginManager("deepsearch_cli")
 
     manager.add_hookspecs(DeepsearchCliPlugin)
@@ -34,6 +41,7 @@ def get_cli_groups() -> List[typer.Typer]:
 
     for app in apps:
         if not app.info.name:
+            logger.error(f"All registered apps must have names, but {app} doesn't")
             raise ValueError(f"All registered apps must have names, but {app} doesn't")
 
     return apps

deepsearch/core/client/config.py

@@ -1,5 +1,6 @@
 from typing import Union
 
+from platformdirs import user_log_dir
 from pydantic import BaseModel
 
 
@@ -15,7 +16,13 @@ class DeepSearchKeyAuth(BaseModel):
 DeepSearchAuth = Union[DeepSearchBearerTokenAuth, DeepSearchKeyAuth]
 
 
+class DeepSearchLogConfig(BaseModel):
+    target_file: str = user_log_dir("DeepSearch", "IBM")
+    write_to_console: bool = False
+
+
 class DeepSearchConfig(BaseModel):
     host: str
     auth: DeepSearchAuth
     verify_ssl: bool = True
+    log_configuration: DeepSearchLogConfig

deepsearch/cps/cli/data_indices_typer.py

@@ -1,3 +1,7 @@
+import logging
+
+logger = logging.getLogger("root.cps.data_indices")
+
 from enum import Enum
 from pathlib import Path
 from typing import List
@@ -38,6 +42,7 @@ def list(
     output: OutputEnum = OutputOption,
 ):
     api = CpsApi.from_env()
+    logger.info(f"Listing data indices in project {proj_key}")
 
     try:
         indices = api.data_indices.list(proj_key=proj_key)
@@ -52,6 +57,7 @@ def list(
             for index in indices
         ]
     except ValueError as e:
+        logger.error(e)
         print(f"Error occurred: {e}")
 
     cli_output(results, output, headers="keys")
@@ -72,6 +78,7 @@ def create(
     ),
 ):
     api = CpsApi.from_env()
+    logger.info(f"Create data index in project {proj_key}, {name=}, {desc=}, {type=}")
 
     try:
         api.data_indices.create(
@@ -82,6 +89,7 @@ def create(
         )
         typer.echo("Data Index Created.")
     except ValueError as e:
+        logger.error(e)
         typer.echo(f"Error occurred: {e}")
         typer.echo(ERROR_MSG)
         raise typer.Abort()
@@ -95,19 +103,23 @@ def delete_data_index(
     index_key: str = INDEX_KEY,
 ):
     api = CpsApi.from_env()
+    logger.info(f"Deleting data index from project {proj_key}, {index_key=}")
     delete = typer.confirm("Are you sure you want to delete this data index?")
 
     coords = ElasticProjectDataCollectionSource(proj_key=proj_key, index_key=index_key)
 
     if not delete:
         typer.echo("Cancelling delete operation.")
+        logger.info("Cancelling delete operation.")
         raise typer.Abort()
     elif delete:
         # get confirmation token
         try:
             api.data_indices.delete(coords)
             typer.echo("Deleted!")
+            logger.info("Index deleted")
         except ApiException as e:
+            logger.error(e)
             typer.echo(f"Error occurred: {e}")
             typer.echo(ERROR_MSG)
             raise typer.Abort()
@@ -118,7 +130,7 @@ def get_urls(path: Path) -> List[str]:
     """
     Returns list of url from input file.
     """
-
+    logger.info(f"Getting url list from {path}")
     lines = path.read_text()
     urls = [line.strip() for line in lines.split("\n") if line.strip() != ""]
     return urls
@@ -136,12 +148,17 @@ def upload_files(
     Upload pdfs, zips, or online documents to a data index in a project
     """
 
+    logger.info(
+        f"Uploading files/urls to {proj_key=} in {index_key=}. {url=} {local_file=}"
+    )
     urls = None
     if url is not None:
         p = Path(url)
         urls = get_urls(p) if p.exists() else [url]
 
     coords = ElasticProjectDataCollectionSource(proj_key=proj_key, index_key=index_key)
+    # TODO this looks bugged ? urls is never used only the unprocessed url
+    logger.info(f"Uploading to {coords=}")
     utils.upload_files(coords=coords, url=url, local_file=local_file)
     return
 
@@ -161,6 +178,9 @@ def add_attachment(
     Add attachment to a index item
     """
     api = CpsApi.from_env()
+    logger.info(
+        f"Adding attachment to index item {proj_key=} {index_key=}, {index_item_id=}, {attachment_key=} {attachment_path=}"
+    )
 
     # get indices of the project
     indices = api.data_indices.list(proj_key)
@@ -176,13 +196,16 @@ def add_attachment(
                 attachment_path=attachment_path,
                 attachment_key=attachment_key,
             )
+            logger.info(f"Attachment added successfully.")
             typer.echo("Attachment added successfully.")
         except ValueError as e:
+            logger.error(e)
             typer.echo(f"Error occurred: {e}")
             typer.echo(ERROR_MSG)
             raise typer.Abort()
         return
     else:
+        logger.info("Index key not found")
         typer.echo("Index key not found")
         raise typer.Abort()