From 1e53ae75cd0b38908434fb1f114e4aa3c8dc1676 Mon Sep 17 00:00:00 2001
From: Johannes Nussbaum <39048939+jnussbaum@users.noreply.github.com>
Date: Tue, 26 Mar 2024 08:19:17 +0100
Subject: [PATCH] chore: better structure of logfile for easier understandig
 (#77)

---
 dsp_permissions_scripts/ap/ap_delete.py        |  5 +----
 dsp_permissions_scripts/ap/ap_get.py           |  4 ++--
 dsp_permissions_scripts/ap/ap_serialize.py     |  1 -
 dsp_permissions_scripts/ap/ap_set.py           |  7 ++-----
 dsp_permissions_scripts/doap/doap_get.py       |  4 ++--
 dsp_permissions_scripts/doap/doap_serialize.py |  1 -
 dsp_permissions_scripts/doap/doap_set.py       |  7 ++-----
 dsp_permissions_scripts/oap/oap_get.py         |  9 ++-------
 dsp_permissions_scripts/oap/oap_serialize.py   |  2 --
 dsp_permissions_scripts/oap/oap_set.py         | 12 ++----------
 dsp_permissions_scripts/template.py            |  4 ++++
 dsp_permissions_scripts/utils/get_logger.py    | 17 +++++++++++++++++
 dsp_permissions_scripts/utils/project.py       |  1 -
 dsp_permissions_scripts/utils/try_request.py   |  4 +---
 14 files changed, 35 insertions(+), 43 deletions(-)

diff --git a/dsp_permissions_scripts/ap/ap_delete.py b/dsp_permissions_scripts/ap/ap_delete.py
index 61d6cddd..9e8575a2 100644
--- a/dsp_permissions_scripts/ap/ap_delete.py
+++ b/dsp_permissions_scripts/ap/ap_delete.py
@@ -1,4 +1,3 @@
-import warnings
 from urllib.parse import quote_plus
 
 import requests
@@ -38,9 +37,7 @@ def delete_ap_of_group_on_server(
     aps_to_delete = [ap for ap in existing_aps if ap.forGroup == forGroup]
     if not aps_to_delete:
         logger.warning(f"There are no APs to delete on {host} for group {forGroup}")
-        warnings.warn(f"There are no APs to delete on {host} for group {forGroup}")
         return existing_aps
-    print(f"Deleting the Administrative Permissions for group {forGroup} on server {host}")
     logger.info(f"Deleting the Administrative Permissions for group {forGroup} on server {host}")
     for ap in aps_to_delete:
         _delete_ap_on_server(
@@ -49,5 +46,5 @@ def delete_ap_of_group_on_server(
             token=token,
         )
         existing_aps.remove(ap)
-        logger.info(f"Deleted Administrative Permission {ap.iri} on host {host}")
+        logger.info(f"Deleted Administrative Permission {ap.iri}")
     return existing_aps
diff --git a/dsp_permissions_scripts/ap/ap_get.py b/dsp_permissions_scripts/ap/ap_get.py
index 4f17b884..6d3376db 100644
--- a/dsp_permissions_scripts/ap/ap_get.py
+++ b/dsp_permissions_scripts/ap/ap_get.py
@@ -64,6 +64,7 @@ def get_aps_of_project(
     token: str,
 ) -> list[Ap]:
     """Returns the Administrative Permissions for a project."""
+    logger.info("****** Retrieving all Administrative Permissions... ******")
     project_iri = get_project_iri_by_shortcode(
         shortcode=shortcode,
         host=host,
@@ -73,6 +74,5 @@ def get_aps_of_project(
         host=host,
         token=token,
     )
-    print(f"Retrieved {len(aps)} Administrative Permissions of project {shortcode} on server {host}")
-    logger.info(f"Retrieved {len(aps)} Administrative Permissions of project {shortcode} on server {host}")
+    logger.info(f"Retrieved {len(aps)} Administrative Permissions")
     return aps
diff --git a/dsp_permissions_scripts/ap/ap_serialize.py b/dsp_permissions_scripts/ap/ap_serialize.py
index 2f2cc701..8dfcb104 100644
--- a/dsp_permissions_scripts/ap/ap_serialize.py
+++ b/dsp_permissions_scripts/ap/ap_serialize.py
@@ -26,7 +26,6 @@ def serialize_aps_of_project(
     aps_as_dict = {explanation_string: aps_as_dicts}
     with open(filepath, mode="w", encoding="utf-8") as f:
         f.write(json.dumps(aps_as_dict, ensure_ascii=False, indent=2))
-    print(f"{len(project_aps)} APs have been written to file {str(filepath)}")
     logger.info(f"{len(project_aps)} APs have been written to file {str(filepath)}")
 
 
diff --git a/dsp_permissions_scripts/ap/ap_set.py b/dsp_permissions_scripts/ap/ap_set.py
index bbe6b210..f5aace9c 100644
--- a/dsp_permissions_scripts/ap/ap_set.py
+++ b/dsp_permissions_scripts/ap/ap_set.py
@@ -1,4 +1,3 @@
-import warnings
 from typing import Any
 from urllib.parse import quote_plus
 
@@ -50,10 +49,8 @@ def apply_updated_aps_on_server(
 ) -> None:
     if not aps:
         logger.warning(f"There are no APs to update on {host}")
-        warnings.warn(f"There are no APs to update on {host}")
         return
-    logger.info(f"Updating {len(aps)} APs on {host}...")
-    print(f"Updating {len(aps)} APs on {host}...")
+    logger.info(f"****** Updating {len(aps)} Administrative Permissions on {host}... ******")
     for ap in aps:
         try:
             _ = _update_ap_on_server(
@@ -64,4 +61,4 @@ def apply_updated_aps_on_server(
             logger.info(f"Successfully updated AP {ap.iri}")
         except ApiError as err:
             logger.error(err)
-            warnings.warn(err.message)
+    logger.info(f"Finished updating {len(aps)} Administrative Permissions on {host}")
diff --git a/dsp_permissions_scripts/doap/doap_get.py b/dsp_permissions_scripts/doap/doap_get.py
index e73cdfd4..bac1de15 100644
--- a/dsp_permissions_scripts/doap/doap_get.py
+++ b/dsp_permissions_scripts/doap/doap_get.py
@@ -83,6 +83,7 @@ def get_doaps_of_project(
     Optionally, select only the DOAPs that are related to either a group, or a resource class, or a property.
     By default, all DOAPs are returned, regardless of their target (target=all).
     """
+    logger.info("****** Retrieving all DOAPs... ******")
     project_iri = get_project_iri_by_shortcode(
         shortcode=shortcode,
         host=host,
@@ -96,9 +97,8 @@ def get_doaps_of_project(
         doaps=doaps,
         target=target_type,
     )
-    msg = f"Retrieved {len(doaps)} DOAPs of project {shortcode} on server {host}"
+    msg = f"Retrieved {len(doaps)} DOAPs"
     if target_type != DoapTargetType.ALL:
         msg += f", {len(filtered_doaps)} of which are related to {target_type}."
-    print(msg)
     logger.info(msg)
     return filtered_doaps
diff --git a/dsp_permissions_scripts/doap/doap_serialize.py b/dsp_permissions_scripts/doap/doap_serialize.py
index faa4355e..22179f23 100644
--- a/dsp_permissions_scripts/doap/doap_serialize.py
+++ b/dsp_permissions_scripts/doap/doap_serialize.py
@@ -29,7 +29,6 @@ def serialize_doaps_of_project(
     doaps_as_dict = {explanation_string: doaps_as_dicts}
     with open(filepath, mode="w", encoding="utf-8") as f:
         f.write(json.dumps(doaps_as_dict, ensure_ascii=False, indent=2))
-    print(f"{len(project_doaps)} DOAPs have been written to file {str(filepath)}")
     logger.info(f"{len(project_doaps)} DOAPs have been written to file {str(filepath)}")
 
 
diff --git a/dsp_permissions_scripts/doap/doap_set.py b/dsp_permissions_scripts/doap/doap_set.py
index 07cc8c60..54e93145 100644
--- a/dsp_permissions_scripts/doap/doap_set.py
+++ b/dsp_permissions_scripts/doap/doap_set.py
@@ -1,4 +1,3 @@
-import warnings
 from urllib.parse import quote_plus
 
 import requests
@@ -45,10 +44,8 @@ def apply_updated_doaps_on_server(
 ) -> None:
     if not doaps:
         logger.warning(f"There are no DOAPs to update on {host}")
-        warnings.warn(f"There are no DOAPs to update on {host}")
         return
-    logger.info(f"Updating {len(doaps)} DOAPs on {host}...")
-    print(f"Updating {len(doaps)} DOAPs on {host}...")
+    logger.info(f"****** Updating {len(doaps)} DOAPs on {host}... ******")
     for d in doaps:
         try:
             _ = _update_doap_scope_on_server(
@@ -60,4 +57,4 @@ def apply_updated_doaps_on_server(
             logger.info(f"Successfully updated DOAP {d.doap_iri}")
         except ApiError as err:
             logger.error(err)
-            warnings.warn(err.message)
+    logger.info(f"Finished updating {len(doaps)} DOAPs on {host}")
diff --git a/dsp_permissions_scripts/oap/oap_get.py b/dsp_permissions_scripts/oap/oap_get.py
index 22d504ce..bb69ef9d 100644
--- a/dsp_permissions_scripts/oap/oap_get.py
+++ b/dsp_permissions_scripts/oap/oap_get.py
@@ -1,4 +1,3 @@
-import warnings
 from typing import Any, Iterable
 from urllib.parse import quote_plus
 
@@ -44,9 +43,7 @@ def _get_all_resource_oaps_of_resclass(
             page += 1
         except ApiError as err:
             logger.error(f"{err}\nStop getting more pages, return what has been retrieved so far.")
-            warnings.warn(f"{err.message}\nStop getting more pages, return what has been retrieved so far.")
             more = False
-    print(f"Retrieved {len(resources)} resource OAPs of class {resclass_iri}")
     logger.info(f"Retrieved {len(resources)} resource OAPs of class {resclass_iri}")
     return resources
 
@@ -133,8 +130,7 @@ def get_all_resource_oaps_of_project(
     token: str,
     excluded_class_iris: Iterable[str] = (),
 ) -> list[Oap]:
-    logger.info(f"******* Getting all resource OAPs of project {shortcode} *******")
-    print(f"******* Getting all resource OAPs of project {shortcode} *******")
+    logger.info("******* Retrieving all resource OAPs... *******")
     project_iri = get_project_iri_by_shortcode(
         shortcode=shortcode,
         host=host,
@@ -154,6 +150,5 @@ def get_all_resource_oaps_of_project(
             token=token,
         )
         all_resource_oaps.extend(resource_oaps)
-    logger.info(f"Retrieved a TOTAL of {len(all_resource_oaps)} resource OAPs of project {shortcode}.")
-    print(f"Retrieved a TOTAL of {len(all_resource_oaps)} resource OAPs of project {shortcode}.")
+    logger.info(f"Retrieved a TOTAL of {len(all_resource_oaps)} resource OAPs")
     return all_resource_oaps
diff --git a/dsp_permissions_scripts/oap/oap_serialize.py b/dsp_permissions_scripts/oap/oap_serialize.py
index 43b34568..0a8b10d8 100644
--- a/dsp_permissions_scripts/oap/oap_serialize.py
+++ b/dsp_permissions_scripts/oap/oap_serialize.py
@@ -20,13 +20,11 @@ def serialize_resource_oaps(
     """Serialize the resource OAPs to JSON files."""
     folder = _get_project_data_path(shortcode, mode)
     folder.mkdir(parents=True, exist_ok=True)
-    print(f"Writing {len(resource_oaps)} OAPs into {str(folder)}")
     logger.info(f"Writing {len(resource_oaps)} OAPs into {str(folder)}")
     for res_oap in resource_oaps:
         filename = re.sub(r"http://rdfh\.ch/[^/]+/", "resource_", res_oap.object_iri)
         with open(folder / f"{filename}.json", mode="w", encoding="utf-8") as f:
             f.write(res_oap.model_dump_json(indent=2))
-    print(f"Successfully wrote {len(resource_oaps)} OAPs into {str(folder)}")
     logger.info(f"Successfully wrote {len(resource_oaps)} OAPs into {str(folder)}")
 
 
diff --git a/dsp_permissions_scripts/oap/oap_set.py b/dsp_permissions_scripts/oap/oap_set.py
index 418d152d..51f95e04 100644
--- a/dsp_permissions_scripts/oap/oap_set.py
+++ b/dsp_permissions_scripts/oap/oap_set.py
@@ -1,6 +1,5 @@
 # pylint: disable=too-many-arguments
 
-import warnings
 from concurrent.futures import ThreadPoolExecutor, as_completed
 from datetime import datetime
 from typing import Any
@@ -127,7 +126,6 @@ def _update_permissions_for_resource_and_values(
         resource = get_resource(resource_iri, host, token)
     except Exception as exc:  # pylint: disable=broad-exception-caught
         logger.error(f"Cannot update resource {resource_iri}: {exc}")
-        warnings.warn(f"Cannot update resource {resource_iri}: {exc}")
         return resource_iri, False
     values = _get_values_to_update(resource)
     
@@ -144,7 +142,6 @@ def _update_permissions_for_resource_and_values(
         )
     except ApiError as err:
         logger.error(err)
-        warnings.warn(err.message)
         success = False
     
     for v in values:
@@ -160,7 +157,6 @@ def _update_permissions_for_resource_and_values(
             )
         except ApiError as err:
             logger.error(err)
-            warnings.warn(err.message)
             success = False
     
     return resource_iri, success
@@ -202,10 +198,8 @@ def _launch_thread_pool(
             if not success:
                 failed_res_iris.append(resource_iri)
                 logger.info(f"Failed updating resource {counter}/{total} ({resource_iri}) and its values.")
-                print(f"Failed updating resource {counter}/{total} ({resource_iri}) and its values.")
             else:
                 logger.info(f"Updated resource {counter}/{total} ({resource_iri}) and its values.")
-                print(f"Updated resource {counter}/{total} ({resource_iri}) and its values.")
     return failed_res_iris
 
 
@@ -222,10 +216,8 @@ def apply_updated_oaps_on_server(
     """
     if not resource_oaps:
         logger.warning(f"There are no OAPs to update on {host}")
-        warnings.warn(f"There are no OAPs to update on {host}")
         return
-    logger.info(f"******* Updating OAPs of {len(resource_oaps)} resources on {host} *******")
-    print(f"******* Updating OAPs of {len(resource_oaps)} resources on {host} *******")
+    logger.info(f"******* Updating OAPs of {len(resource_oaps)} resources on {host}... *******")
 
     failed_res_iris = _launch_thread_pool(resource_oaps, host, token, nthreads)
 
@@ -243,4 +235,4 @@ def apply_updated_oaps_on_server(
             f"They were written to {filename}."
         )
         logger.error(msg)
-        warnings.warn(msg)
+    logger.info(f"Updated OAPs of {len(resource_oaps)} resources on {host}")
diff --git a/dsp_permissions_scripts/template.py b/dsp_permissions_scripts/template.py
index 1c6939c6..b87f5cbd 100644
--- a/dsp_permissions_scripts/template.py
+++ b/dsp_permissions_scripts/template.py
@@ -17,6 +17,9 @@
 from dsp_permissions_scripts.oap.oap_serialize import serialize_resource_oaps
 from dsp_permissions_scripts.oap.oap_set import apply_updated_oaps_on_server
 from dsp_permissions_scripts.utils.authentication import login
+from dsp_permissions_scripts.utils.get_logger import get_logger, log_start_of_script
+
+logger = get_logger(__name__)
 
 
 def modify_aps(aps: list[Ap]) -> list[Ap]:
@@ -176,6 +179,7 @@ def main() -> None:
     host = Hosts.get_host("test")
     shortcode = "F18E"
     token = login(host)
+    log_start_of_script(logger, host, shortcode)
 
     update_aps(
         host=host,
diff --git a/dsp_permissions_scripts/utils/get_logger.py b/dsp_permissions_scripts/utils/get_logger.py
index c611ca70..f28b4be6 100644
--- a/dsp_permissions_scripts/utils/get_logger.py
+++ b/dsp_permissions_scripts/utils/get_logger.py
@@ -29,3 +29,20 @@ def get_logger(name: str) -> logging.Logger:
 
 def get_timestamp() -> str:
     return datetime.now().strftime("%Y-%m-%d %H:%M:%S")
+
+
+def log_start_of_script(logger: logging.Logger, host: str, shortcode: str) -> None:
+    """
+    Make a log entry to make it clear that a new run begins.
+    """
+    msg = f"Start script for project {shortcode} on server {host}"
+    logger.info("")
+    logger.info("*" * len(msg))
+    logger.info("DSP-PERMISSIONS-SCRIPTS")
+    logger.info(msg)
+    logger.info("*" * len(msg))
+    logger.info("")
+
+    print(f"\n{msg}")
+    logfile = [handler.baseFilename for handler in logger.handlers if isinstance(handler, logging.FileHandler)][0]
+    print(f"There will be no print output, only logging to file {logfile}")
diff --git a/dsp_permissions_scripts/utils/project.py b/dsp_permissions_scripts/utils/project.py
index 9df8ebd6..5d1f29b0 100644
--- a/dsp_permissions_scripts/utils/project.py
+++ b/dsp_permissions_scripts/utils/project.py
@@ -56,7 +56,6 @@ def get_all_resource_class_iris_of_project(
     host: str,
     token: str,
 ) -> list[str]:
-    logger.info(f"Getting all resource class IRIs of project {project_iri}...")
     project_onto_iris = _get_onto_iris_of_project(
         project_iri=project_iri,
         host=host,
diff --git a/dsp_permissions_scripts/utils/try_request.py b/dsp_permissions_scripts/utils/try_request.py
index eaa4c071..e60b2109 100644
--- a/dsp_permissions_scripts/utils/try_request.py
+++ b/dsp_permissions_scripts/utils/try_request.py
@@ -5,7 +5,7 @@
 from requests import ReadTimeout, RequestException
 from urllib3.exceptions import ReadTimeoutError
 
-from dsp_permissions_scripts.utils.get_logger import get_logger, get_timestamp
+from dsp_permissions_scripts.utils.get_logger import get_logger
 
 logger = get_logger(__name__)
 
@@ -45,14 +45,12 @@ def http_call_with_retry(action: Callable[..., requests.Response], err_msg: str)
                     f"SERVER ERROR: {err_msg}. Retry request in {2 ** i} seconds... "
                     f"({response.status_code}: {response.text})"
                 )
-                print(f"{get_timestamp()}: {msg}")
                 logger.error(msg)
                 time.sleep(2**i)
                 continue
             return response
         except (TimeoutError, ReadTimeout, ReadTimeoutError, RequestException, ConnectionError):
             msg = f"REQUESTS LIBRARY ERROR: {err_msg}. Retry request in {2 ** i} seconds..."
-            print(f"{get_timestamp()}: {msg}")
             logger.error(msg, exc_info=True)
             time.sleep(2**i)
             continue