chore: add more logs and timestamps (#627)

src/dsp_tools/cli.py

@@ -609,11 +609,13 @@ def run(args: list[str]) -> None:
         )
         success = _call_requested_action(parsed_arguments)
     except UserError as err:
+        logger.error(f"Terminate because of this UserError: {err.message}")
         print(err.message)
         sys.exit(1)
     # let BaseError and all unexpected errors escalate, so that a stack trace is printed
 
     if not success:
+        logger.error("Terminate without success")
         sys.exit(1)
 
 

src/dsp_tools/fast_xmlupload/process_files.py

@@ -278,7 +278,7 @@ def _stop_and_remove_sipi_container() -> None:
         print(f"{datetime.now()}: Stopped and removed Sipi container.")
         logger.info("Stopped and removed Sipi container.")
     except docker.errors.APIError:
-        print("WARNING: It was not possible to stop and remove the Sipi container.")
+        print(f"{datetime.now()}: WARNING: It was not possible to stop and remove the Sipi container.")
         logger.warning("It was not possible to stop and remove the Sipi container.")
 
 

src/dsp_tools/utils/excel2json/lists.py

@@ -371,6 +371,6 @@ def excel2lists(
     if path_to_output_file:
         with open(path_to_output_file, "w", encoding="utf-8") as fp:
             json.dump(finished_lists, fp, indent=4, ensure_ascii=False)
-            print('"lists" section was created successfully and written to file:', path_to_output_file)
+            print(f"lists section was created successfully and written to file '{path_to_output_file}'")
 
     return finished_lists, True

src/dsp_tools/utils/excel2json/properties.py

@@ -465,6 +465,6 @@ def excel2properties(
     if path_to_output_file:
         with open(file=path_to_output_file, mode="w", encoding="utf-8") as file:
             json.dump(props, file, indent=4, ensure_ascii=False)
-            print('"properties" section was created successfully and written to file:', path_to_output_file)
+            print(f"properties section was created successfully and written to file '{path_to_output_file}'")
 
     return props, True

src/dsp_tools/utils/excel2json/resources.py

@@ -224,6 +224,6 @@ def excel2resources(
     if path_to_output_file:
         with open(file=path_to_output_file, mode="w", encoding="utf-8") as file:
             json.dump(resources, file, indent=4, ensure_ascii=False)
-            print('"resources" section was created successfully and written to file:', path_to_output_file)
+            print(f"resources section was created successfully and written to file '{path_to_output_file}'")
 
     return resources, True

src/dsp_tools/utils/shared.py

@@ -237,7 +237,7 @@ def validate_xml_against_schema(input_file: Union[str, Path, etree._ElementTree[
     _validate_xml_tags_in_text_properties(doc)
 
     logger.info("The XML file is syntactically correct and passed validation.")
-    print("The XML file is syntactically correct and passed validation.")
+    print(f"{datetime.now()}: The XML file is syntactically correct and passed validation.")
     return True
 
 

src/dsp_tools/utils/xmlupload/resource_multimedia.py

@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+from datetime import datetime
 from pathlib import Path
 from typing import Any, Optional
 
@@ -78,12 +79,12 @@ def handle_bitstream(
                 permissions_lookup=permissions_lookup,
             )
             msg = f"Uploaded file '{bitstream.value}'"
-            print(msg)
+            print(f"{datetime.now()}: {msg}")
             logger.info(msg)
         return resource_bitstream
     except BaseError as err:
         err_msg = err.orig_err_msg_from_api or err.message
         msg = f"Unable to upload file '{bitstream.value}' of resource '{resource.label}' ({resource.id})"
-        print(f"WARNING: {msg}: {err_msg}")
+        print(f"{datetime.now()}: WARNING: {msg}: {err_msg}")
         logger.warning(msg, exc_info=True)
         return None

src/dsp_tools/utils/xmlupload/upload_stashed_resptr_props.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import json
+from datetime import datetime
 
 from dsp_tools.connection.connection import Connection
 from dsp_tools.models.exceptions import BaseError
@@ -33,7 +34,7 @@ def upload_stashed_resptr_props(
         nonapplied_resptr_props: the resptr props that could not be uploaded
     """
 
-    print("Upload the stashed resptrs...")
+    print(f"{datetime.now()}: Upload the stashed resptrs...")
     logger.info("Upload the stashed resptrs...")
     not_uploaded: list[LinkValueStashItem] = []
     for res_id, stash_items in stashed_resptr_props.res_2_stash_items.items():
@@ -44,8 +45,8 @@ def upload_stashed_resptr_props(
             # which will be handled by the caller
             continue
         if verbose:
-            print(f'  Upload resptrs of resource "{res_id}"...')
-        logger.info(f'  Upload resptrs of resource "{res_id}"...')
+            print(f"{datetime.now()}:   Upload resptrs of resource '{res_id}''...")
+        logger.info(f"  Upload resptrs of resource '{res_id}'...")
         for stash_item in stash_items:
             target_iri = iri_resolver.get(stash_item.target_id)
             if not target_iri:
@@ -88,7 +89,7 @@ def _upload_stash_item(
 
 def _log_unable_to_upload_link_value(msg: str, res_id: str, prop_name: str) -> None:
     err_msg = f"Unable to upload the resptr prop of '{prop_name}' of resource '{res_id}'."
-    print(f"    WARNING: {err_msg} Original error message: {msg}")
+    print(f"{datetime.now()}:     WARNING: {err_msg} Original error message: {msg}")
     logger.warning(err_msg, exc_info=True)
 
 

src/dsp_tools/utils/xmlupload/upload_stashed_xml_texts.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import json
+from datetime import datetime
 from typing import Any
 from urllib.parse import quote_plus
 
@@ -34,7 +35,7 @@ def _log_unable_to_retrieve_resource(
         f"Unable to upload XML texts of resource '{resource}', "
         "because the resource cannot be retrieved from the DSP server."
     )
-    print(f"  WARNING: {err_msg} Original error message: {orig_err_msg}")
+    print(f"{datetime.now()}:   WARNING: {err_msg} Original error message: {orig_err_msg}")
     logger.warning(err_msg, exc_info=True)
 
 
@@ -56,7 +57,7 @@ def _log_unable_to_upload_xml_resource(
     # this resource will remain in nonapplied_xml_texts, which will be handled by the caller
     orig_err_msg = received_error.orig_err_msg_from_api or received_error.message
     err_msg = f"Unable to upload the xml text of '{prop_name}' of resource '{stashed_resource_id}'."
-    print(f"    WARNING: {err_msg} Original error message: {orig_err_msg}")
+    print(f"{datetime.now()}:     WARNING: {err_msg} Original error message: {orig_err_msg}")
     logger.warning(err_msg, exc_info=True)
 
 
@@ -115,7 +116,7 @@ def upload_stashed_xml_texts(
         nonapplied_xml_texts: the xml texts that could not be uploaded
     """
 
-    print("Upload the stashed XML texts...")
+    print(f"{datetime.now()}: Upload the stashed XML texts...")
     logger.info("Upload the stashed XML texts...")
     not_uploaded: list[StandoffStashItem] = []
     for res_id, stash_items in stashed_xml_texts.res_2_stash_items.items():
@@ -132,8 +133,8 @@ def upload_stashed_xml_texts(
             _log_unable_to_retrieve_resource(resource=res_id, received_error=err)
             continue
         if verbose:
-            print(f'  Upload XML text(s) of resource "{res_id}"...')
-        logger.info(f'  Upload XML text(s) of resource "{res_id}"...')
+            print(f"{datetime.now()}:   Upload XML text(s) of resource '{res_id}'...")
+        logger.info(f"  Upload XML text(s) of resource '{res_id}'...")
         context = resource_in_triplestore["@context"]
         for stash_item in stash_items:
             value_iri = _get_value_iri(stash_item.prop_name, resource_in_triplestore, stash_item.uuid)

src/dsp_tools/utils/xmlupload/write_diagnostic_info.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import json
+from datetime import datetime
 from pathlib import Path
 from typing import Any
 
@@ -24,5 +25,5 @@ def write_id2iri_mapping(
             id2iri_filename = f"{timestamp_str}_id2iri_mapping.json"
     with open(id2iri_filename, "x", encoding="utf-8") as f:
         json.dump(id2iri_mapping, f, ensure_ascii=False, indent=4)
-        print(f"The mapping of internal IDs to IRIs was written to {id2iri_filename}")
+        print(f"{datetime.now()}: The mapping of internal IDs to IRIs was written to {id2iri_filename}")
         logger.info(f"The mapping of internal IDs to IRIs was written to {id2iri_filename}")

src/dsp_tools/utils/xmlupload/xmlupload.py

@@ -1,11 +1,9 @@
-"""
-This module handles the import of XML data into the DSP platform.
-"""
 from __future__ import annotations
 
 import json
 import sys
 from dataclasses import asdict
+from datetime import datetime
 from logging import FileHandler
 from pathlib import Path
 from typing import Any, Union
@@ -113,10 +111,10 @@ def xmlupload(
     write_id2iri_mapping(iri_resolver.lookup, input_file, config.diagnostics.timestamp_str)
     success = not failed_uploads
     if success:
-        print("All resources have successfully been uploaded.")
+        print(f"{datetime.now()}: All resources have successfully been uploaded.")
         logger.info("All resources have successfully been uploaded.")
     else:
-        print(f"\nWARNING: Could not upload the following resources: {failed_uploads}\n")
+        print(f"\n{datetime.now()}: WARNING: Could not upload the following resources: {failed_uploads}\n")
         logger.warning(f"Could not upload the following resources: {failed_uploads}")
     return success
 
@@ -129,7 +127,7 @@ def _prepare_upload(
 ) -> tuple[list[XMLResource], dict[str, Permissions], Stash | None]:
     logger.info("Checking resources for circular references...")
     if verbose:
-        print("Checking resources for circular references...")
+        print(f"{datetime.now()}: Checking resources for circular references...")
     stash_lookup, upload_order = identify_circular_references(root)
     logger.info("Get data from XML...")
     resources, permissions_lookup = _get_data_from_xml(
@@ -141,7 +139,7 @@ def _prepare_upload(
     resources = [sorting_lookup[res_id] for res_id in upload_order]
     logger.info("Stashing circular references...")
     if verbose:
-        print("Stashing circular references...")
+        print(f"{datetime.now()}: Stashing circular references...")
     stash = stash_circular_references(resources, stash_lookup, permissions_lookup)
     return resources, permissions_lookup, stash
 
@@ -344,7 +342,7 @@ def _upload_resources(
         id_to_iri_resolver.update(resource.id, iri)
 
         resource_designation = f"'{label}' (ID: '{resource.id}', IRI: '{iri}')"
-        print(f"Created resource {i+1}/{len(resources)}: {resource_designation}")
+        print(f"{datetime.now()}: Created resource {i+1}/{len(resources)}: {resource_designation}")
         logger.info(f"Created resource {i+1}/{len(resources)}: {resource_designation}")
 
     return id_to_iri_resolver, failed_uploads
@@ -359,7 +357,7 @@ def _create_resource(
         return resource_create_client.create_resource(resource, bitstream_information)
     except BaseError as err:
         err_msg = err.orig_err_msg_from_api or err.message
-        print(f"WARNING: Unable to create resource '{resource.label}' ({resource.id}): {err_msg}")
+        print(f"{datetime.now()}: WARNING: Unable to create resource '{resource.label}' ({resource.id}): {err_msg}")
         log_msg = (
             f"Unable to create resource '{resource.label}' ({resource.id})\n"
             f"Resource details:\n{vars(resource)}\n"
@@ -369,8 +367,13 @@ def _create_resource(
         return None
     except Exception as err:  # pylint: disable=broad-except
         msg = f"Unable to create resource '{resource.label}' ({resource.id})"
-        print(f"WARNING: {msg}: {err}")
-        logger.exception(msg)
+        print(f"{datetime.now()}: WARNING: {msg}: {err}")
+        log_msg = (
+            f"Unable to create resource '{resource.label}' ({resource.id})\n"
+            f"Resource details:\n{vars(resource)}\n"
+            f"Property details:\n" + "\n".join([str(vars(prop)) for prop in resource.properties])
+        )
+        logger.exception(log_msg)
         return None
 
 
@@ -401,7 +404,7 @@ def _handle_upload_error(
     logfiles = ", ".join([handler.baseFilename for handler in logger.handlers if isinstance(handler, FileHandler)])
     print(
         f"\n==========================================\n"
-        f"xmlupload must be aborted because of an error.\n"
+        f"{datetime.now()}: xmlupload must be aborted because of an error.\n"
         f"Error message: '{err}'\n"
         f"For more information, see the log file: {logfiles}\n"
     )