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

Do not log caller for INFO messages #418

Merged
merged 2 commits into from
Dec 4, 2021
Merged

Conversation

borzunov
Copy link
Member

@borzunov borzunov commented Dec 2, 2021

The caller info for INFO log messages is often long but rarely useful. Such long lines confuse new users.

This PR hides the caller info for INFO messages only, unless a user specifies env variable HIVEMIND_ALWAYS_LOG_CALLER=True (True is case-insensitive).

I think it is important that this behavior does not depend on HIVEMIND_LOGLEVEL. Example: a user could create a Colab notebook parsing the logs and change the HIVEMIND_LOGLEVEL in the last minute, thus breaking the parser (since the INFO messages start to have the other format).

Before:

Screenshot 2021-12-02 at 13 22 53

After:

Screenshot 2021-12-02 at 13 22 30

@codecov
Copy link

codecov bot commented Dec 2, 2021

Codecov Report

Merging #418 (b1fce7a) into master (12099ce) will increase coverage by 0.25%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master     #418      +/-   ##
==========================================
+ Coverage   83.42%   83.68%   +0.25%     
==========================================
  Files          77       77              
  Lines        7790     7795       +5     
==========================================
+ Hits         6499     6523      +24     
+ Misses       1291     1272      -19     
Impacted Files Coverage Δ
hivemind/utils/logging.py 87.75% <100.00%> (+0.65%) ⬆️
hivemind/utils/mpfuture.py 95.00% <0.00%> (+0.90%) ⬆️
hivemind/dht/node.py 92.63% <0.00%> (+1.18%) ⬆️
hivemind/averaging/matchmaking.py 88.48% <0.00%> (+3.63%) ⬆️

@borzunov borzunov force-pushed the hide-caller-for-info branch from db0ae23 to ea40b98 Compare December 2, 2021 11:32
@@ -461,7 +461,7 @@ def _update_global_epoch(self, grad_scaler: Optional[GradScaler]) -> None:
if not self.client_mode:
self.grad_averager.state_sharing_priority = self.local_epoch

logger.log(self.status_loglevel, f"Transitioning to epoch {self.local_epoch}.")
logger.debug(f"Transitioning to epoch {self.local_epoch}")
Copy link
Member Author

@borzunov borzunov Dec 2, 2021

Choose a reason for hiding this comment

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

This duplicates the Step N message (see the "After" screenshot).

Copy link
Member

Choose a reason for hiding this comment

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

This message is useful because

  • it signifies when a (potentially long) optimizer step is finished
  • it is the only message that will be printed when use_local_updates=True (i.e. there is no global step)

Copy link
Member

@justheuristic justheuristic left a comment

Choose a reason for hiding this comment

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

Good job!

Please revert the epoch message though (or continue the discussion)

@borzunov borzunov merged commit 249be7c into master Dec 4, 2021
@borzunov borzunov deleted the hide-caller-for-info branch December 4, 2021 22:00
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants