Keep exceptions logs #898

ekatef · 2023-10-16T19:37:11Z

Closes #897

Changes proposed in this Pull Request

Add an exception hook to stream exception traceback into the logs.

Checklist

I consent to the release of this PR's code under the AGPLv3 license and non-code contributions under CC0-1.0 and CC-BY-4.0.
I tested my contribution locally and it seems to work fine.
Code and workflow changes are sufficiently documented.
Newly introduced dependencies are added to envs/environment.yaml and doc/requirements.txt.
Changes in configuration options are added in all of config.default.yaml and config.tutorial.yaml.
Add a test config or line additions to test/ (note tests are changing the config.tutorial.yaml)
Changes in configuration options are also documented in doc/configtables/*.csv and line references are adjusted in doc/configuration.rst and doc/tutorial.rst.
A note for the release notes doc/release_notes.rst is amended in the format of previous release notes, including reference to the requested PR.

for more information, see https://pre-commit.ci

davide-f

Very nice draft @ekatef :D Indeed very needed too!
I think we have all the ingredients for this cake :D

May be good to finalize it for build_shapes and then add it to all scripts :)

scripts/_helpers.py

davide-f · 2023-10-16T21:01:40Z

scripts/_helpers.py

+    tb = exc_traceback
+    while tb.tb_next:
+        tb = tb.tb_next
+    flname = tb.tb_frame.f_globals.get("__file__")
+    funcname = tb.tb_frame.f_code.co_name
+
+    logger.error(
+        "An error happened in module %r, function %r: %s",
+        flname,
+        funcname,
+        exc_value,
+        exc_info=(exc_type, exc_value, exc_traceback),
+    )


This may be simplified with something like

def handle_exception(exc_type, exc_value, tb): ... [Exclude Interrupt] ... logger.exception( "Exception {0}:{1} has occurred in the workflow.".format(exc_type, exc_value), exc_info=True, stack_info=True )

Mmm on second though, I'd log also the keyboardinterrupt so to keep track that it has been a manual action

Absolutely agree on keeping info on KeyBoardInterrupt. Added a functionality for that.

davide-f · 2023-10-16T21:07:30Z

scripts/build_shapes.py

@@ -36,8 +37,7 @@
 from shapely.validation import make_valid
 from tqdm import tqdm

-logger = logging.getLogger(__name__)
-logger.setLevel(logging.INFO)
+sys.excepthook = handle_exception


This shall be placed into the create_logger fuction but here we shall create the local logger like:
logger = create_logger(__name__, logging.INFO)

ekatef · 2023-10-23T22:47:32Z

Playing with structuring the code. It appears that python logging is a bit tricky to deal with due logger hierarchy,. The current implementation results in an empty log, but works if definition of create_logger() is moved to build_shapes module itself.

davide-f

Cool @ekatef :D
Few minor comments, I think we are almost there :D

davide-f · 2023-10-28T10:49:26Z

scripts/_helpers.py

+def create_logger(level=logging.INFO):
+    # logger = logging.getLogger('__main__.' + __name__)
+    logger = logging.getLogger("__main__")


I think we are quite close :D

I'd add a first mandatory input to this function like in the following.
Then, it can be used flexibly to create arbitrary loggers. This may solve the issue you mentioned in build shapes.
Could you test if it works?

Suggested change

def create_logger(level=logging.INFO):

# logger = logging.getLogger('__main__.' + __name__)

logger = logging.getLogger("__main__")

def create_logger(logger_name, level=logging.INFO):

logger = logging.getLogger(logger_name)

Finally, docstrings may be recommendede to add, even simple ones with no ful description of inputs.
I'd say that the create_logger shall have a proper docstring, while handle_exception can have a simpler one

I think we are quite close :D

I'd add a first mandatory input to this function like in the following. Then, it can be used flexibly to create arbitrary loggers. This may solve the issue you mentioned in build shapes. Could you test if it works?

Finally, docstrings may be recommendede to add, even simple ones with no ful description of inputs. I'd say that the create_logger shall have a proper docstring, while handle_exception can have a simpler one

It works!!!
Thank you so much :D
Adding docstrings :)

…exceptions_logs

ekatef · 2023-10-28T22:30:22Z

Cool @ekatef :D Few minor comments, I think we are almost there :D

Agree, it looks like the issue has been fixed :) Thanks a lot for support, as always.

Have added an exception hook to all the scripts, except build_test_configs.py, as it doesn't contained any logging settings. Not sure if it was intentional, and happy to fix in case it is needed.

davide-f

We are there :)
May you share few logs to me? I'd like to see a build_shapes (example) and build_renewable_profile if possible.

Many thanks!

davide-f · 2023-10-28T22:49:47Z

scripts/add_electricity.py

 from powerplantmatching.export import map_country_bus

 idx = pd.IndexSlice

-logger = logging.getLogger(__name__)
+create_logger(__name__)
+sys.excepthook = handle_exception


Just seen; can't we place this line as well into create_logger?

It appears, we perfectly can with the current logger definition. Great :D

davide-f · 2023-10-28T22:53:20Z

scripts/_helpers.py

+    """
+    Customise errors traceback.
+    """
+


Please, drop the empty line for PEP8 standard

davide-f · 2023-10-28T22:53:56Z

scripts/_helpers.py

+    """
+    Create a logger for a module and adds a handler needed to capture in logs
+    traceback from exceptions emerging during the workflow.
+    """
+


Please, drop the empty line after the """ for PEP8 standard.

ekatef · 2023-10-28T23:29:24Z

We are there :) May you share few logs to me? I'd like to see a build_shapes (example) and build_renewable_profile if possible.

Many thanks!

Have improved a definition of create_logger(), as you suggested. As the next step, I'll update logging setup in all the scripts (which now can be as short as it was initially). Thanks a lot for supervision! :)

Sharing the logs bellow.

build_shapes

WARNING:snakemake.logging:Stage 1 of 4: Create country shapes
WARNING:snakemake.logging:Stage 2 of 4: Create offshore shapes
WARNING:snakemake.logging:Stage 4/4: Creation GADM GeoDataFrame
WARNING:snakemake.logging:Stage 4/4 POP: Add population data to GADM GeoDataFrame
WARNING:snakemake.logging:Stage 4/4: Add gdp data to GADM GeoDataFrame
WARNING:snakemake.logging:Stage 4/4: Access to GDP raster data
CRITICAL:snakemake.logging:Stage 4/4: File GDP_PPP_1990_2015_5arcmin_v2.tif not found, the file will be produced by processing GDP_PPP_1990_2015_5arcmin_v2.nc
WARNING:snakemake.logging:Stage 4/4: Access to GDP raster data
CRITICAL:snakemake.logging:Stage 3/4 GDP data of year False not found, selected the most recent data (2015)

build_renewable_profiles (onwind)

INFO:distributed.http.proxy:To route to workers diagnostics web server please install jupyter-server-proxy: python -m pip install jupyter-server-proxy
INFO:distributed.scheduler:State start
INFO:distributed.scheduler:  Scheduler at:     tcp://127.0.0.1:50156
INFO:distributed.scheduler:  dashboard at:  http://127.0.0.1:8787/status
INFO:distributed.nanny:        Start Nanny at: 'tcp://127.0.0.1:50159'
INFO:distributed.scheduler:Register worker <WorkerState 'tcp://127.0.0.1:50162', name: 0, status: init, memory: 0, processing: 0>
INFO:distributed.scheduler:Starting worker compute stream, tcp://127.0.0.1:50162
INFO:distributed.core:Starting established connection to tcp://127.0.0.1:50164
INFO:distributed.scheduler:Receive client connection: Client-38bafc6c-75e8-11ee-a0a5-f64e6159bb86
INFO:distributed.core:Starting established connection to tcp://127.0.0.1:50165
WARNING:snakemake.logging:Calculate landuse availabilities...
WARNING:snakemake.logging:Completed availability calculation (22.84s)
INFO:atlite.convert:Convert and aggregate 'wind'.
INFO:atlite.convert:Convert and aggregate 'wind'.
WARNING:snakemake.logging:Calculating maximal capacity per bus (method 'simple')
WARNING:snakemake.logging:Calculate average distances.
INFO:distributed.nanny:Closing Nanny at 'tcp://127.0.0.1:50159'. Reason: nanny-close
INFO:distributed.nanny:Nanny asking worker to close. Reason: nanny-close
INFO:distributed.core:Received 'close-stream' from tcp://127.0.0.1:50164; closing.
INFO:distributed.scheduler:Remove worker <WorkerState 'tcp://127.0.0.1:50162', name: 0, status: closing, memory: 0, processing: 0> (stimulus_id='handle-worker-cleanup-1698535104.803447')
INFO:distributed.scheduler:Lost all workers
INFO:distributed.scheduler:Scheduler closing...
INFO:distributed.scheduler:Scheduler closing all comms

ekatef · 2023-10-28T23:32:42Z

Uncaught exceptions are also captured by the logs. For example, there is a log after an error provoked in build_shapes by referring to undefined variables x and y in print(x + y):

ERROR:_helpers:An error happened in module '~/_github_/pypsa-earth/scripts/build_shapes.py', function '<module>': name 'x' is not defined
Traceback (most recent call last):
  File "~/_github_/pypsa-earth/.snakemake/scripts/tmph3o6bx36.build_shapes.py", line 925, in <module>
    print(x + y)
NameError: name 'x' is not defined

davide-f

Fantastic @ekatef :D From now on, logging will be easier! :D
Ready to merge!

ekatef · 2023-10-29T19:54:41Z

Fantastic @ekatef :D From now on, logging will be easier! :D Ready to merge!

Thanks a lot for amazing support @davide-f 🙂

ekatef added 4 commits October 16, 2023 22:16

Add a function to create a logger.error for an exception

612dea7

Stream exception info into a log file

33787cc

Move logger definitions inside an exceptions hook

efeb56b

Improving an error message

01f9c41

ekatef mentioned this pull request Oct 16, 2023

Add an error message when GADM server is down #890

Merged

8 tasks

ekatef and others added 2 commits October 16, 2023 22:39

Merge branch 'main' into keep_exceptions_logs

9e9eab8

[pre-commit.ci] auto fixes from pre-commit.com hooks

2b1f73d

for more information, see https://pre-commit.ci

davide-f reviewed Oct 16, 2023

View reviewed changes

ekatef added 2 commits October 24, 2023 00:32

Add keyboard interruptions to logs

1fc05f6

Add a dedicated function to create a logger

337fd78

ekatef force-pushed the keep_exceptions_logs branch from 821c082 to 337fd78 Compare October 23, 2023 22:45

Apply log functions inside a module

5309f26

Apply log functions inside a module

785e72b

davide-f reviewed Oct 28, 2023

View reviewed changes

ekatef added 8 commits October 28, 2023 23:20

Merge remote-tracking branch 'origin/keep_exceptions_logs' into keep_…

893c386

…exceptions_logs

Fix a logger name

0dc22d7

Add docstrings

8931d5a

Update logging setup across the scripts

8e4fc80

Add a missed import

2d3907a

Add logging updates

e0d89fa

Update a release note

bad5bb9

Amend a release note

0d349f9

davide-f reviewed Oct 28, 2023

View reviewed changes

Remove empty lines

b75b1eb

Fix logger calls and imports

64388a3

ekatef force-pushed the keep_exceptions_logs branch from a4dbf5a to 64388a3 Compare October 29, 2023 18:42

davide-f approved these changes Oct 29, 2023

View reviewed changes

davide-f merged commit 418e560 into pypsa-meets-earth:main Oct 29, 2023

ekatef deleted the keep_exceptions_logs branch December 26, 2023 08:50

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Keep exceptions logs #898

Keep exceptions logs #898

ekatef commented Oct 16, 2023 •

edited

Loading

davide-f left a comment •

edited

Loading

davide-f Oct 16, 2023

davide-f Oct 17, 2023

ekatef Oct 23, 2023

davide-f Oct 16, 2023

ekatef commented Oct 23, 2023

davide-f left a comment

davide-f Oct 28, 2023

ekatef Oct 28, 2023

ekatef commented Oct 28, 2023

davide-f left a comment

davide-f Oct 28, 2023

ekatef Oct 28, 2023

davide-f Oct 28, 2023

ekatef Oct 28, 2023

davide-f Oct 28, 2023

ekatef Oct 28, 2023

ekatef commented Oct 28, 2023

ekatef commented Oct 28, 2023 •

edited

Loading

davide-f left a comment •

edited

Loading

ekatef commented Oct 29, 2023

Keep exceptions logs #898

Keep exceptions logs #898

Conversation

ekatef commented Oct 16, 2023 • edited Loading

Closes #897

Changes proposed in this Pull Request

Checklist

davide-f left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ekatef commented Oct 23, 2023

davide-f left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ekatef commented Oct 28, 2023

davide-f left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ekatef commented Oct 28, 2023

build_shapes

build_renewable_profiles (onwind)

ekatef commented Oct 28, 2023 • edited Loading

davide-f left a comment • edited Loading

Choose a reason for hiding this comment

ekatef commented Oct 29, 2023

ekatef commented Oct 16, 2023 •

edited

Loading

davide-f left a comment •

edited

Loading

ekatef commented Oct 28, 2023 •

edited

Loading

davide-f left a comment •

edited

Loading