Centralize logging #6434

LysandreJik · 2020-08-12T09:31:53Z

The goal of this PR is to offer a better way to manage logging to the HuggingFace/transformers users. It's a very simple proposal: implement a single logger that is shared across all files, and implement three helper methods that can be used across the library and by users:

def get_logger():
    '''
    Returns the logger instance for the library, that can be managed as a traditional `logging` logger.
    '''

def get_verbosity():
    '''
    Returns the logger instance verbosity level. Used to manage what is printed, for example with tqdm loading bars.
    Same as doing:
        hf_logging.get_logger().getEffectiveLevel()
    '''

def set_verbosity(level: int):
    '''
    Sets the logger instance verbosity level. Used to set the desired verbosity level across the library.
    Same as doing:
        hf_logging.get_logger().setLevel(level)
    '''

Users can use these methods as such:

from transformers import hf_logging

logger = hf_logging.get_logger()

hf_logging.set_verbosity(hf_logging.INFO)
# same as doing
logger.setLevel(hf_logging.INFO)

The noteworthy additions/changes are shown below.

LysandreJik · 2020-08-12T09:33:09Z

src/transformers/hf_logging.py

+def get_verbosity() -> int:
+    _configure_library_logger()
+    return _get_library_logger().getEffectiveLevel()
+
+
+def set_verbosity(verbosity: int) -> None:
+    _configure_library_logger()
+    _get_library_logger().setLevel(verbosity)
+
+
+def get_logger():
+    _configure_library_logger()
+    return _get_library_logger()


Three helper methods

LysandreJik · 2020-08-12T09:33:35Z

src/transformers/data/processors/squad.py

+    if tqdm_enabled is None:
+        tqdm_enabled = hf_logging.get_verbosity() <= hf_logging.INFO
+


tqdm can be enabled/disabled like so.

codecov · 2020-08-12T09:46:16Z

Codecov Report

Merging #6434 into master will increase coverage by 0.46%.
The diff coverage is 91.58%.

@@            Coverage Diff             @@
##           master    #6434      +/-   ##
==========================================
+ Coverage   79.63%   80.09%   +0.46%     
==========================================
  Files         156      157       +1     
  Lines       28420    28471      +51     
==========================================
+ Hits        22631    22805     +174     
+ Misses       5789     5666     -123

Impacted Files	Coverage Δ
src/transformers/commands/convert.py	`0.00% <0.00%> (ø)`
src/transformers/commands/run.py	`0.00% <0.00%> (ø)`
src/transformers/commands/serving.py	`0.00% <0.00%> (ø)`
src/transformers/commands/train.py	`0.00% <0.00%> (ø)`
src/transformers/configuration_auto.py	`93.18% <ø> (-0.30%)`	⬇️
src/transformers/data/metrics/squad_metrics.py	`0.00% <0.00%> (ø)`
src/transformers/benchmark/benchmark_utils.py	`69.50% <66.66%> (ø)`
src/transformers/utils/logging.py	`75.00% <75.00%> (ø)`
src/transformers/__init__.py	`99.28% <100.00%> (ø)`
src/transformers/activations.py	`90.00% <100.00%> (ø)`
... and 132 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 461ae86...c81c035. Read the comment docs.

sgugger

I'm all for centralization. This looks like a nice improvement for the user, great work!
Didn't read the full diff, just a bit, since there is POC in the title :-) Ping me when it's the right time to do so.

patrickvonplaten · 2020-08-14T07:33:04Z

Looks good to me as well! I'm thinking that it might be a good idea to create one helper function for each verbosity level:

hf_logger.set_info_verbosity()
hf_logger.set_warning_verbosity()
hf_logger.set_debug_verbosity()

These functions might be easier to remember...what do you think @LysandreJik ?

thomwolf

I like it but I think we should follow a bit more the example of optuna and have a 'root logger' (they have a MIT licence so feel free borrow (and credit!) their logging code).

Also we can add a few utilities to easily disable tqdm bar I think.

thomwolf · 2020-08-24T09:40:57Z

src/transformers/file_utils.py



-logger = logging.getLogger(__name__)  # pylint: disable=invalid-name
+logger = hf_logging.get_logger()  # pylint: disable=invalid-name


It would be nice to keep some detail of the filename in which the log happened (cc @lhoestq).
Can we keep __name__ as an argument here?

thomwolf · 2020-08-24T09:45:28Z

src/transformers/file_utils.py

@@ -733,7 +732,7 @@ def http_get(url, temp_file, proxies=None, resume_size=0, user_agent: Union[Dict
        total=total,
        initial=resume_size,
        desc="Downloading",
-        disable=bool(logger.getEffectiveLevel() == logging.NOTSET),
+        disable=bool(logger.getEffectiveLevel() == hf_logging.NOTSET),


This is a bit mouthful in my opinion.
Following @patrickvonplaten suggestion to had

hf_logger.set_verbosity_info() hf_logger.set_verbosity_warning() hf_logger.set_verbosity_debug() hf_logger.set_verbosity_error()

Could we maybe expose utilities like:

hf_logger.is_verbosity_at_least_info() hf_logger.is_verbosity_at_least_warning() hf_logger.is_verbosity_at_least_debug() hf_logger.is_verbosity_at_least_error()

?

thomwolf · 2020-08-24T09:49:51Z

src/transformers/hf_logging.py

+_default_handler: Optional[logging.Handler] = None
+
+
+def _get_library_logger() -> logging.Logger:


As mentioned above, can we still accept a name argument here and set the logger formatting to display it in addition to the name transformers?

I think we will probably need to follow more the approach of optuna (have a root logger etc)

thomwolf · 2020-08-24T09:54:16Z

Looks good to me as well! I'm thinking that it might be a good idea to create one helper function for each verbosity level:
hf_logger.set_info_verbosity()
hf_logger.set_warning_verbosity()
hf_logger.set_debug_verbosity()
These functions might be easier to remember...what do you think @LysandreJik ?

For a simpler completion, I would rather call these:

hf_logger.set_verbosity_info()
hf_logger.set_verbosity_warning()
hf_logger.set_verbosity_debug()
hf_logger.set_verbosity_error()  # This one is important as well, to basically disactivate all infos/warnings

jplu

Awesome!! This new feature is more than welcome!

LysandreJik

Following @thomwolf and @patrickvonplaten's reviews, added some helper methods and updated to be more similar to Optuna.

There is now a root logger with separate loggers for each file.

LysandreJik · 2020-08-25T15:41:57Z

src/transformers/convert_roberta_original_pytorch_checkpoint_to_pytorch.py

-logging.basicConfig(level=logging.INFO)
-logger = logging.getLogger(__name__)
+hf_logging.set_verbosity_info()
+logger = hf_logging.get_logger(__name__)


Example of helper method

thomwolf · 2020-08-25T20:33:35Z

src/transformers/file_utils.py

@@ -757,7 +756,7 @@ def http_get(url, temp_file, proxies=None, resume_size=0, user_agent: Union[Dict
        total=total,
        initial=resume_size,
        desc="Downloading",
-        disable=bool(logger.getEffectiveLevel() == logging.NOTSET),
+        disable=hf_logging.get_verbosity() == hf_logging.NOTSET,


disable=bool(hf_logging.get_verbosity() > hf_logging.INFO)?

thomwolf · 2020-08-25T20:34:36Z

src/transformers/hf_logging.py

+def is_verbosity_at_least_info():
+    return get_verbosity() <= INFO
+
+
+def is_verbosity_at_least_warning():
+    return get_verbosity() <= WARNING
+
+
+def is_verbosity_at_least_debug():
+    return get_verbosity() <= DEBUG
+
+
+def is_verbosity_at_least_error():
+    return get_verbosity() <= ERROR


Ok actually I think these ones will be not very useful (cf the tqdm in file_utils). Sorry for proposing them.

thomwolf

Awesome!

src/transformers/benchmark/benchmark_utils.py

sgugger · 2020-08-26T12:37:15Z

src/transformers/training_args.py

@@ -247,7 +247,7 @@ class TrainingArguments:

    def __post_init__(self):
        if self.disable_tqdm is None:
-            self.disable_tqdm = logger.getEffectiveLevel() > logging.WARN
+            self.disable_tqdm = logging.get_verbosity() <= logging.INFO


I don't understand this change. Is the order different from logging? Also I'm pretty sure we want the progress bars at the info level.

Ah yes, this was a mistake. Reverting.

Co-authored-by: Sylvain Gugger <35901082+sgugger@users.noreply.github.com>

@thomwolf

* Logging * Style * hf_logging > utils.logging * Address @thomwolf's comments * Update test * Update src/transformers/benchmark/benchmark_utils.py Co-authored-by: Sylvain Gugger <35901082+sgugger@users.noreply.github.com> * Revert bad change Co-authored-by: Sylvain Gugger <35901082+sgugger@users.noreply.github.com>

LysandreJik requested review from julien-c, jplu, mfuntowicz, sshleifer, thomwolf, patrickvonplaten and sgugger August 12, 2020 09:31

LysandreJik commented Aug 12, 2020

View reviewed changes

sgugger approved these changes Aug 12, 2020

View reviewed changes

patrickvonplaten approved these changes Aug 14, 2020

View reviewed changes

thomwolf approved these changes Aug 24, 2020

View reviewed changes

jplu approved these changes Aug 25, 2020

View reviewed changes

Logging

a931df8

LysandreJik force-pushed the hf-logging branch from 863af96 to a931df8 Compare August 25, 2020 15:40

LysandreJik commented Aug 25, 2020

View reviewed changes

This comment was marked as spam.

Sign in to view

huggingface blocked hamad8395 Aug 25, 2020

Style

8153a14

LysandreJik marked this pull request as ready for review August 25, 2020 16:02

LysandreJik changed the title ~~[POC] Centralize logging~~ Centralize logging Aug 25, 2020

thomwolf approved these changes Aug 25, 2020

View reviewed changes

LysandreJik added 3 commits August 26, 2020 10:43

hf_logging > utils.logging

6f8314f

Address @thomwolf's comments

08272fe

Update test

e956b93

thomwolf approved these changes Aug 26, 2020

View reviewed changes

sgugger approved these changes Aug 26, 2020

View reviewed changes

LysandreJik and others added 3 commits August 26, 2020 08:40

Update src/transformers/benchmark/benchmark_utils.py

93aca99

Co-authored-by: Sylvain Gugger <35901082+sgugger@users.noreply.github.com>

Revert bad change

a0a2f16

Merge branch 'master' into hf-logging

c81c035

LysandreJik merged commit 77abd1e into master Aug 26, 2020

LysandreJik deleted the hf-logging branch August 26, 2020 15:10

joeddav mentioned this pull request Aug 26, 2020

add __init__.py to utils #6754

Merged

thomwolf mentioned this pull request Sep 4, 2020

control framework loglevel in scripts and tests #6816

Closed

LysandreJik mentioned this pull request Nov 2, 2020

Should be able to turn off logging #3050

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Centralize logging #6434

Centralize logging #6434

LysandreJik commented Aug 12, 2020

LysandreJik Aug 12, 2020

LysandreJik Aug 12, 2020

codecov bot commented Aug 12, 2020 •

edited

Loading

sgugger left a comment

patrickvonplaten commented Aug 14, 2020

thomwolf left a comment

thomwolf Aug 24, 2020

thomwolf Aug 24, 2020 •

edited

Loading

thomwolf Aug 24, 2020

thomwolf commented Aug 24, 2020

jplu left a comment

LysandreJik left a comment

LysandreJik Aug 25, 2020

This comment was marked as spam.

thomwolf Aug 25, 2020

thomwolf Aug 25, 2020

thomwolf left a comment

sgugger Aug 26, 2020

LysandreJik Aug 26, 2020

		if tqdm_enabled is None:
		tqdm_enabled = hf_logging.get_verbosity() <= hf_logging.INFO



		logger = logging.getLogger(__name__) # pylint: disable=invalid-name
		logger = hf_logging.get_logger() # pylint: disable=invalid-name

		_default_handler: Optional[logging.Handler] = None


		def _get_library_logger() -> logging.Logger:

Centralize logging #6434

Centralize logging #6434

Conversation

LysandreJik commented Aug 12, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

codecov bot commented Aug 12, 2020 • edited Loading

Codecov Report

sgugger left a comment

Choose a reason for hiding this comment

patrickvonplaten commented Aug 14, 2020

thomwolf left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thomwolf Aug 24, 2020 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thomwolf commented Aug 24, 2020

jplu left a comment

Choose a reason for hiding this comment

LysandreJik left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

This comment was marked as spam.

Choose a reason for hiding this comment

Choose a reason for hiding this comment

thomwolf left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

codecov bot commented Aug 12, 2020 •

edited

Loading

thomwolf Aug 24, 2020 •

edited

Loading