Skip to content

Commit

Permalink
update statshandler logging message (#6051)
Browse files Browse the repository at this point in the history
### Description

The recommendation in `StatsHandler` of setting the global logging
config may not work in some cases (e.g. google colab and
#5960)
https://docs.python.org/3/library/logging.html#logging.basicConfig


https://github.com/Project-MONAI/MONAI/blob/3eef61e82883e9bc6c08d26954fc86286df7d1b3/monai/handlers/stats_handler.py#L55

in general we shouldn't recommend changing the root logger directly.

This PR changes the message to tune the module level loggers, updated
example message will be:
```
.the effective log level of ignite.engine.engine.Engine higher than INFO, StatsHandler may not generate logs,
please use the following code before running the engine to enable it: 
                                                                                
import logging                                                              
logging.getLogger('ignite.engine.engine.Engine').setLevel(logging.INFO) 
```

the updated commands are tested in the colab example:

https://colab.research.google.com/drive/1boqy7ENpKrqaJoxFlbHIBnIODAs1Ih1T

### Types of changes
<!--- Put an `x` in all the boxes that apply, and remove the not
applicable items -->
- [x] Non-breaking change (fix or new feature that would not break
existing functionality).
- [ ] Breaking change (fix or new feature that would cause existing
functionality to change).
- [x] New tests added to cover the changes.
- [ ] Integration tests passed locally by running `./runtests.sh -f -u
--net --coverage`.
- [x] Quick tests passed locally by running `./runtests.sh --quick
--unittests --disttests`.
- [x] In-line docstrings updated.
- [ ] Documentation updated, tested `make html` command in the `docs/`
folder.

---------

Signed-off-by: Wenqi Li <wenqil@nvidia.com>
  • Loading branch information
wyli authored Feb 25, 2023
1 parent c731aaa commit f519699
Show file tree
Hide file tree
Showing 3 changed files with 30 additions and 19 deletions.
10 changes: 6 additions & 4 deletions monai/apps/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -58,13 +58,15 @@ def get_logger(
(https://docs.python.org/3/library/logging.html#formatter-objects).
`logger_handler` can be used to add an additional handler.
"""
adds_stdout_handler = module_name is not None and module_name not in logging.root.manager.loggerDict
logger = logging.getLogger(module_name)
logger.propagate = False
logger.setLevel(logging.INFO)
handler = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter(fmt=fmt, datefmt=datefmt)
handler.setFormatter(formatter)
logger.addHandler(handler)
if adds_stdout_handler: # don't add multiple stdout or add to the root
handler = logging.StreamHandler(sys.stdout)
formatter = logging.Formatter(fmt=fmt, datefmt=datefmt)
handler.setFormatter(formatter)
logger.addHandler(handler)
if logger_handler is not None:
logger.addHandler(logger_handler)
return logger
Expand Down
35 changes: 21 additions & 14 deletions monai/handlers/stats_handler.py
Original file line number Diff line number Diff line change
Expand Up @@ -18,8 +18,9 @@

import torch

from monai.apps import get_logger
from monai.config import IgniteInfo
from monai.utils import is_scalar, min_version, optional_import
from monai.utils import deprecated_arg_default, is_scalar, min_version, optional_import

Events, _ = optional_import("ignite.engine", IgniteInfo.OPT_IMPORT_VERSION, min_version, "Events")
if TYPE_CHECKING:
Expand All @@ -39,11 +40,11 @@ class StatsHandler:
It can be used for any Ignite Engine(trainer, validator and evaluator).
And it can support logging for epoch level and iteration level with pre-defined loggers.
Note that if `name` arg is None, will leverage `engine.logger` as default logger directly, otherwise,
get logger from `logging.getLogger(name)`, we can setup a logger outside first with the same `name`.
As the default log level of `RootLogger` is `WARNING`, may need to call
`logging.basicConfig(stream=sys.stdout, level=logging.INFO)` before running this handler to enable
the stats logging.
Note that if ``name`` is None, this class will leverage `engine.logger` as the logger, otherwise,
``logging.getLogger(name)`` is used. In both cases, it's important to make sure that the logging level is at least
``INFO``. To change the level of logging, please call ``import ignite; ignite.utils.setup_logger(name)``
(when ``name`` is not None) or ``engine.logger = ignite.utils.setup_logger(engine.logger.name, reset=True)``
(when ``name`` is None) before running the engine with this handler attached.
Default behaviors:
- When EPOCH_COMPLETED, logs ``engine.state.metrics`` using ``self.logger``.
Expand All @@ -52,18 +53,20 @@ class StatsHandler:
Usage example::
logging.basicConfig(stream=sys.stdout, level=logging.INFO)
import ignite
import monai
trainer = SupervisedTrainer(...)
StatsHandler(name="train_stats").attach(trainer)
trainer = ignite.engine.Engine(lambda x, y: [0.0]) # an example trainer
monai.handlers.StatsHandler(name="train_stats").attach(trainer)
trainer.run()
trainer.run(range(3), max_epochs=4)
More details of example is available in the tutorial:
https://github.com/Project-MONAI/tutorials/blob/master/modules/engines/unet_training_dict.py.
"""

@deprecated_arg_default("name", old_default=None, new_default="StatsHandler", since="1.1", replaced="1.3")
def __init__(
self,
iteration_log: bool | Callable[[Engine, int], bool] = True,
Expand Down Expand Up @@ -122,7 +125,7 @@ def __init__(
self.state_attributes = state_attributes
self.tag_name = tag_name
self.key_var_format = key_var_format
self.logger = logging.getLogger(name) # if `name` is None, will default to `engine.logger` when attached
self.logger = get_logger(name) # type: ignore
self.name = name

def attach(self, engine: Engine) -> None:
Expand All @@ -135,10 +138,14 @@ def attach(self, engine: Engine) -> None:
"""
if self.name is None:
self.logger = engine.logger
if self.logger.getEffectiveLevel() > logging.INFO or logging.root.getEffectiveLevel() > logging.INFO:
if self.logger.getEffectiveLevel() > logging.INFO:
suggested = f"\n\nimport ignite\nignite.utils.setup_logger('{self.logger.name}', reset=True)"
if self.logger.name != engine.logger.name:
suggested += f"\nignite.utils.setup_logger('{engine.logger.name}', reset=True)"
suggested += "\n\n"
warnings.warn(
"the effective log level of engine logger or RootLogger is higher than INFO, may not record log,"
" please call `logging.basicConfig(stream=sys.stdout, level=logging.INFO)` to enable it."
f"the effective log level of {self.logger.name} is higher than INFO, StatsHandler may not output logs,"
f"\nplease use the following code before running the engine to enable it: {suggested}"
)
if self.iteration_log and not engine.has_event_handler(self.iteration_completed, Events.ITERATION_COMPLETED):
event = Events.ITERATION_COMPLETED
Expand Down
4 changes: 3 additions & 1 deletion tests/test_handler_stats.py
Original file line number Diff line number Diff line change
Expand Up @@ -254,7 +254,9 @@ def _train_func(engine, batch):

# set up testing handler
stats_handler = StatsHandler(name=None, tag_name=key_to_print)
stats_handler.attach(engine)
engine.logger.setLevel(logging.WARNING)
with self.assertWarns(Warning): # engine logging level warn
stats_handler.attach(engine)
# leverage `engine.logger` to print info
engine.logger.setLevel(logging.INFO)
level = logging.root.getEffectiveLevel()
Expand Down

0 comments on commit f519699

Please sign in to comment.