Merge pull request #666 from OpenEnergyPlatform/feature-657-664-improve-logging

Improve logging

Author: nesnoj

CHANGELOG.md

@@ -17,6 +17,8 @@ and the versioning aims to respect [Semantic Versioning](http://semver.org/spec/
   [#636](https://github.com/OpenEnergyPlatform/open-MaStR/pull/636)
 - Change print statement about data cleansing
   [#650](https://github.com/OpenEnergyPlatform/open-MaStR/pull/650)
+- Improve logging
+  [#666](https://github.com/OpenEnergyPlatform/open-MaStR/pull/666)
 - Limit number of parallel CI jobs
   [#669](https://github.com/OpenEnergyPlatform/open-MaStR/pull/669)
 ### Removed

docs/advanced.md

@@ -63,7 +63,7 @@ The project home directory is structured as follows (files and folders below `da
         File names are defined here.
      * `logging.yml` <br>
         Logging configuration. For changing the log level to increase or decrease details of log
-        messages, edit the level of the handlers.
+        messages, edit the level of the handlers. See below for details on logging.
 * **data**
      * `dataversion-<date>` <br>
         Contains exported data as csv files from method [`to_csv`][open_mastr.Mastr.to_csv]
@@ -83,6 +83,19 @@ The project home directory is structured as follows (files and folders below `da
 For the download via the API, logs are stored in a single file in `/$HOME/<user>/.open-MaStR/logs/open_mastr.log`.
 New logging messages are appended. It is recommended to delete the log file from time to time because of its required disk space.
 
+By default, the log level is set to `INFO`. You can increase or decrease the verbosity by either changing `logging.yml` (see above)
+or adjusting it manually in your code. E.g. to enable `DEBUG` messages in `open_mastr.log` you can use the following snippet:
+
+```python
+
+  import logging
+  from open_mastr import Mastr
+
+  # Increase to DEBUG to show more details in open_mastr.log
+  # Must be called after importing open_mastr to have the open-MaStR logger imported
+  logging.getLogger("open-MaStR").setLevel(logging.DEBUG)
+```
+
 
 ### Data
 

open_mastr/mastr.py

@@ -92,7 +92,10 @@ def __init__(self, engine="sqlite", connect_to_translated_db=False) -> None:
         else:
             self.engine = create_database_engine(engine, self._sqlite_folder_path)
 
-        print(
+        log.info(
+            "\n==================================================\n"
+            "--------->      open-MaStR started      <---------\n"
+            "==================================================\n"
             f"Data will be written to the following database: {self.engine.url}\n"
             "If you run into problems, try to "
             "delete the database and update the package by running "
@@ -239,7 +242,7 @@ def download(
 
             download_xml_Mastr(zipped_xml_file_path, date, data, xml_folder_path)
 
-            print(
+            log.info(
                 "\nWould you like to speed up the creation of your MaStR database?\n"
                 "Try our new parallelized processing by setting os.environ['USE_RECOMMENDED_NUMBER_OF_PROCESSES'] = True "
                 "or configure your own number of processes via os.environ['NUMBER_OF_PROCESSES'] = your_number\n"
@@ -259,8 +262,8 @@ def download(
             # Set api_processes to None in order to avoid the malfunctioning usage
             if api_processes:
                 api_processes = None
-                print(
-                    "Warning: The implementation of parallel processes "
+                log.warning(
+                    "The implementation of parallel processes "
                     "is currently under construction. Please let "
                     "the argument api_processes at the default value None."
                 )
@@ -429,9 +432,11 @@ def translate(self) -> None:
             try:
                 os.remove(new_path)
             except Exception as e:
-                print(f"An error occurred: {e}")
+                log.error(
+                    f"An error occurred while removing old translated database: {e}"
+                )
 
-            print("Replacing previous version of the translated database...")
+            log.info("Replacing previous version of the translated database...")
 
         for table in inspector.get_table_names():
             rename_table(table, inspector.get_columns(table), self.engine)
@@ -440,9 +445,9 @@ def translate(self) -> None:
 
         try:
             os.rename(old_path, new_path)
-            print(f"Database '{old_path}' changed to '{new_path}'")
+            log.info(f"Database '{old_path}' changed to '{new_path}'")
         except Exception as e:
-            print(f"An error occurred: {e}")
+            log.error(f"An error occurred while renaming database: {e}")
 
         self.engine = create_engine(f"sqlite:///{new_path}")
         self.is_translated = True

open_mastr/soap_api/metadata/description.py

@@ -1,10 +1,13 @@
 from io import BytesIO
+import logging
 import re
 from urllib.request import urlopen
 from zipfile import ZipFile
 import xmltodict
 from collections import OrderedDict
 
+log = logging.getLogger(__name__)
+
 
 class DataDescription(object):
     """
@@ -150,9 +153,11 @@ def functions_data_documentation(self):
                             fcn["sequence"]["element"]["@type"].split(":")[1]
                         ]["sequence"]["element"]
                 else:
-                    print(type(fcn["sequence"]))
-                    print(fcn["sequence"])
-                    raise ValueError
+                    log.error(f"Unexpected sequence type: {type(fcn['sequence'])}")
+                    log.error(f"Sequence content: {fcn['sequence']}")
+                    raise ValueError(
+                        f"Unexpected sequence structure in function metadata"
+                    )
 
                 # Add data for inherited columns from base types
                 if "@base" in fcn:

open_mastr/utils/config/logging.yml

@@ -4,6 +4,8 @@ disable_existing_loggers: False
 formatters:
   standard:
     format: "%(asctime)s [%(levelname)s] %(message)s"
+  debug:
+    format: "%(asctime)s [%(levelname)s] %(name)s:%(funcName)s:%(lineno)d - %(message)s"
 
 handlers:
   console:
@@ -12,14 +14,13 @@ handlers:
     class: "logging.StreamHandler"
     stream: "ext://sys.stdout"
   file:
-    class: "logging.FileHandler"
     level: "DEBUG"
-    formatter: "standard"
+    formatter: "debug"
+    class: "logging.FileHandler"
     mode: "a"
 
-root:
-    level: "DEBUG"
-
 loggers:
   open-MaStR:
+    level: "INFO"
     handlers: ["console", "file"]
+    propagate: no

open_mastr/utils/helpers.py

@@ -343,37 +343,32 @@ def print_api_settings(
     api_processes,
     api_location_types,
 ):
-    print(
+    log.info(
         f"Downloading with soap_API.\n\n   -- API settings --  \nunits after date: "
         f"{date}\nunit download limit per data: "
         f"{api_limit}\nparallel_processes: {api_processes}\nchunksize: "
         f"{api_chunksize}\ndata_api: {data}"
     )
     if "permit" in harmonisation_log:
-        print(
-            f"data_types: {api_data_types}\033[31m",
+        log.warning(
+            f"data_types: {api_data_types} - "
             "Attention, 'permit_data' was automatically set in api_data_types, "
-            "as you defined 'permit' in parameter data_api.",
-            "\033[m",
+            "as you defined 'permit' in parameter data_api."
         )
 
     else:
-        print(f"data_types: {api_data_types}")
+        log.info(f"data_types: {api_data_types}")
 
     if "location" in harmonisation_log:
-        print(
-            "location_types:",
-            "\033[31m",
-            "Attention, 'location' is in parameter data. location_types are set to",
-            "\033[m",
-            f"{api_location_types}"
-            "\n                 If you want to change location_types, please remove 'location' "
+        log.warning(
+            f"location_types: {api_location_types} - "
+            "Attention, 'location' is in parameter data. location_types are set accordingly. "
+            "If you want to change location_types, please remove 'location' "
             "from data_api and specify api_location_types."
-            "\n   ------------------  \n",
         )
 
     else:
-        print(
+        log.info(
             f"location_types: {api_location_types}",
             "\n   ------------------  \n",
         )