[tune] refactor verbosity levels #11767
Conversation
# Conflicts: # python/ray/tune/trial.py
# Conflicts: # python/ray/tune/logger.py
# Conflicts: # python/ray/tune/utils/callback.py
# Conflicts: # python/ray/tune/callback.py # python/ray/tune/logger.py # python/ray/tune/tests/test_cluster.py
|
I'll update this PR once #11749 is merged. |
# Conflicts: # python/ray/tune/logger.py # python/ray/tune/syncer.py # python/ray/tune/trial.py # python/ray/tune/tune.py # python/ray/tune/utils/callback.py
There was a problem hiding this comment.
(sorry for the late review!) Thanks for opening this PR; the callback is great.
The only main concern for me is that the verbosity enum does not suggest any form of ordering (high verbosity or low verbosity); as a result, it's a bit hard to parse. Can we go with some other enumeration wording?
python/ray/tune/utils/log.py
Outdated
| def verbose_log(logger: Callable[[str], Any], level: Union[int, Verbosity], | ||
| message: str): | ||
| """Log `message` if specified level exceeds global verbosity level. | ||
|
|
||
| `logger` should be a Callable, e.g. `logger.info`. It can also be | ||
| `print` or a logger method of any other level - or any callable that | ||
| accepts a string. | ||
| """ | ||
| if has_verbosity(level): | ||
| logger(message) |
There was a problem hiding this comment.
Hmm, doesn't this ruin the file trace? i.e.
2020-11-06 22:38:34,948 DEBUG trial_runner.py:557 -- Waiting for redis server at 172.31.48.39:6379 to respond...
will now show up as:
2020-11-06 22:38:34,948 DEBUG log.py:557 -- Waiting for redis server at 172.31.48.39:6379 to respond...
There was a problem hiding this comment.
should we instead just configure the python logging system correctly?
There was a problem hiding this comment.
By passing the logger this should not happen, right? I.e. in one.py I instantiate a logger, which will log as DEBUG one.py ... - and if I call verbose_log(logger.info, ...) it will use the same logger and thus print the correct file. Right?
I thought about using custom loglevels for this but it seems to be much overhead and might interfere with other parts of Ray. Overall it seems introducing custom log levels is considered bad practice.
There was a problem hiding this comment.
Hmm, I think verbose_log will not use the same logger:
2020-11-09 20:05:56,650 INFO log.py:36 -- Total run time: 2.39 seconds (2.35 seconds for the tuning loop).
There was a problem hiding this comment.
(which instead should show tune.py)
There was a problem hiding this comment.
I ran: python examples/async_hyperband_example.py --smoke-test
There was a problem hiding this comment.
Sorry, this almost slipped. You're right, and that's because of our logger format "%(asctime)s\t%(levelname)s %(filename)s:%(lineno)s -- %(message)s" - I thought it was name instead of filename.
Since we currently used it only in one location anyway I removed that utility function. It should be fine now.
Co-authored-by: Richard Liaw <rliaw@berkeley.edu>
|
Thanks for the comments! |
|
I added more thorough (end to end) output testing |
| | train_xxxxx_00000 | RUNNING | | complete | | ||
| +-------------------+----------+-------+----------+""" | ||
|
|
||
| VERBOSE_CMD = """from ray import tune |
There was a problem hiding this comment.
nit: I've been saving these as separate py files
This reverts commit 8609e2d. Signed-off-by: Richard Liaw <rliaw@berkeley.edu>
Why are these changes needed?
Adds a new verbosity level, so we now have four levels:
0No reporting1Experiment-level updates2Brief trial-level updates3Detailed trial-level updates (like current default, stays the default).Todo:
This PR depends on #11748.
Checks
scripts/format.shto lint the changes in this PR.