Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix duplicate console logging bug / properly configure logging #5509

Merged
merged 24 commits into from
Jan 25, 2021

Conversation

awaelchli
Copy link
Contributor

@awaelchli awaelchli commented Jan 14, 2021

What does this PR do?

Fixes #4621

Current Behavior

The following code snippet reproduces the duplicate logs shown in the console:

import pytorch_lightning as pl
import logging
logging.info("I should not get logged, because logging is not configured!")
pl.seed_everything(1234)  # this gets logged twice

# console output:
# Global seed set to 1234
# INFO:lightning:Global seed set to 1234

Expected Behavior

We expect the following behaviors:

Scenario 1: User did not configure logging, we provide a default StreamHandler to stderr that does not propagate

import pytorch_lightning as pl
pl.seed_everything(1234)
# console output:
# Global seed set to 1234

Scenario 2: User configures logging, expects Lightning logs to propagate

# logging configuration
import logging
logging.basicConfig(level=logging.DEBUG)  # custom formatting etc.
import pytorch_lightning as pl
logging.info("hello!")
pl.seed_everything(1234)
# console output:
# INFO:root:hello!
# INFO:pytorch_lightning.utilities.seed:Global seed set to 1234

This PR will properly configure python logging for the library. The messages get all propagated in the module hierarchy as it is recommended by python logging best practice. This gives the user the most flexibility, they can now configure logging on a module level, see the updated docs for an example.

Correct Logging Usage

In the future, if you want to use logging as part of the Lightning library, please do:

import logging
logger = logging.getLogger(__name__)    # <-- good!

from pytorch_lightning import _logger   # <-- bad!
logger =logging.getLogger("lightning")  # <-- bad!

NOTE: This PR has many files changed, however the changes are small and only in the header the files. Most important changes can be found in these files:

pytorch_lightning/__init__.py 
docs/source/logging.rst
tests/test_profiler.py

works fine in colab too
https://colab.research.google.com/drive/1pgKFHcPkSxCRydp84PPunHQibNB-fZLq?usp=sharing

@awaelchli awaelchli added logging Related to the `LoggerConnector` and `log()` bug Something isn't working labels Jan 14, 2021
@awaelchli awaelchli added this to the 1.1.x milestone Jan 14, 2021
@codecov
Copy link

codecov bot commented Jan 18, 2021

Codecov Report

Merging #5509 (6a500f9) into master (f094e10) will decrease coverage by 0%.
The diff coverage is 96%.

@@          Coverage Diff           @@
##           master   #5509   +/-   ##
======================================
- Coverage      93%     93%   -0%     
======================================
  Files         135     135           
  Lines       10005   10023   +18     
======================================
+ Hits         9340    9356   +16     
- Misses        665     667    +2     

@awaelchli awaelchli changed the title logger propagate fix duplicate console logging bug / properly configure python logging in lightning Jan 18, 2021
@awaelchli awaelchli changed the title fix duplicate console logging bug / properly configure python logging in lightning fix duplicate console logging bug / properly configure logging Jan 18, 2021
@awaelchli awaelchli marked this pull request as ready for review January 18, 2021 02:34
pytorch_lightning/__init__.py Outdated Show resolved Hide resolved
@Borda
Copy link
Member

Borda commented Jan 18, 2021

43 files changed is a bit scary :D

@awaelchli
Copy link
Contributor Author

@Borda the change in each file is minor, just in the header of the file I replace

from pytorch_lightning import _logger

with

import logging
_logger = logging.getLogger(__name__)

I see no other way. To do the logging properly we want to respect the module hierarchy and this requires changing all occurences of logging.

@SeanNaren SeanNaren enabled auto-merge (squash) January 19, 2021 12:09
Copy link
Contributor

@carmocca carmocca left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

See comments, also, all these logs will not be filtered to appear just on rank zero, right?

docs/source/logging.rst Show resolved Hide resolved
pytorch_lightning/__init__.py Outdated Show resolved Hide resolved
@justusschock
Copy link
Member

@carmocca They weren't filtered before and they shouldn't be, since these are logs intended to be displayed on each node for investigation purposes.

@Borda Borda requested a review from s-rog January 24, 2021 08:37
@Borda
Copy link
Member

Borda commented Jan 24, 2021

@carmocca mind re-review?

@@ -28,6 +29,8 @@
if HOROVOD_AVAILABLE:
import horovod.torch as hvd

log = logging.getLogger(__name__)
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

lets be consistent and use the same name as you defined in __init__:

_logger = python_logging.getLogger(__name__)

@Borda Borda added the ready PRs ready to be merged label Jan 24, 2021
@SeanNaren SeanNaren merged commit 0346b63 into master Jan 25, 2021
@SeanNaren SeanNaren deleted the bugfix/duplicate-logs2 branch January 25, 2021 05:31
@awaelchli awaelchli restored the bugfix/duplicate-logs2 branch March 1, 2021 18:35
@awaelchli awaelchli deleted the bugfix/duplicate-logs2 branch March 1, 2021 18:36
awaelchli added a commit that referenced this pull request Mar 1, 2021
* duplicate logs

* remove unused

* configure basic logging

* missing import

* update docs for logging

* import order

* flake8

* test

* fix test

* flake8

* import warning

* add changelog

* isort

* stderr

Co-authored-by: chaton <thomas@grid.ai>
@awaelchli awaelchli mentioned this pull request Mar 1, 2021
11 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working logging Related to the `LoggerConnector` and `log()` ready PRs ready to be merged
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Weird logging to console behavior.
7 participants