-
Notifications
You must be signed in to change notification settings - Fork 1.2k
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
logger: log datetime when on debug mode #3325
Merged
Merged
Changes from all commits
Commits
File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Original file line number | Diff line number | Diff line change |
---|---|---|
|
@@ -4,25 +4,40 @@ | |
import colorama | ||
|
||
import dvc.logger | ||
import time | ||
from datetime import datetime | ||
import pytest | ||
|
||
from dvc.exceptions import DvcException | ||
|
||
|
||
logger = logging.getLogger("dvc") | ||
formatter = dvc.logger.ColorFormatter() | ||
colors = { | ||
"blue": colorama.Fore.BLUE, | ||
"green": colorama.Fore.GREEN, | ||
"red": colorama.Fore.RED, | ||
"yellow": colorama.Fore.YELLOW, | ||
"nc": colorama.Fore.RESET, | ||
} | ||
|
||
|
||
@pytest.fixture() | ||
def dt(mocker): | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. π |
||
with mocker.patch( | ||
"time.time", return_value=time.mktime(datetime(2020, 2, 2).timetuple()) | ||
): | ||
yield "2020-02-02 00:00:00,000" | ||
|
||
|
||
class TestColorFormatter: | ||
def test_debug(self, caplog): | ||
def test_debug(self, caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
logger.debug("message") | ||
|
||
expected = "{blue}DEBUG{nc}: message".format(**colors) | ||
expected = "{green}{datetime}{nc} {blue}DEBUG{nc}: message".format( | ||
**colors, datetime=dt | ||
) | ||
|
||
assert expected == formatter.format(caplog.records[0]) | ||
|
||
|
@@ -81,7 +96,7 @@ def test_exception_with_description_and_message(self, caplog): | |
|
||
assert expected == formatter.format(caplog.records[0]) | ||
|
||
def test_exception_under_verbose(self, caplog): | ||
def test_exception_under_verbose(self, caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
try: | ||
raise Exception("description") | ||
|
@@ -90,17 +105,21 @@ def test_exception_under_verbose(self, caplog): | |
logger.exception("") | ||
|
||
expected = ( | ||
"{green}{datetime}{nc} " | ||
"{red}ERROR{nc}: description\n" | ||
"{red}{line}{nc}\n" | ||
"{stack_trace}" | ||
"{red}{line}{nc}".format( | ||
line="-" * 60, stack_trace=stack_trace, **colors | ||
line="-" * 60, | ||
stack_trace=stack_trace, | ||
**colors, | ||
datetime=dt | ||
) | ||
) | ||
|
||
assert expected == formatter.format(caplog.records[0]) | ||
|
||
def test_tb_only(self, caplog): | ||
def test_tb_only(self, caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
try: | ||
raise Exception("description") | ||
|
@@ -109,17 +128,21 @@ def test_tb_only(self, caplog): | |
logger.exception("something", extra={"tb_only": True}) | ||
|
||
expected = ( | ||
"{green}{datetime}{nc} " | ||
"{red}ERROR{nc}: something\n" | ||
"{red}{line}{nc}\n" | ||
"{stack_trace}" | ||
"{red}{line}{nc}".format( | ||
line="-" * 60, stack_trace=stack_trace, **colors | ||
line="-" * 60, | ||
stack_trace=stack_trace, | ||
**colors, | ||
datetime=dt | ||
) | ||
) | ||
|
||
assert expected == formatter.format(caplog.records[0]) | ||
|
||
def test_nested_exceptions(self, caplog): | ||
def test_nested_exceptions(self, caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
try: | ||
raise Exception("first") | ||
|
@@ -131,11 +154,15 @@ def test_nested_exceptions(self, caplog): | |
logger.exception("message") | ||
|
||
expected = ( | ||
"{green}{datetime}{nc} " | ||
"{red}ERROR{nc}: message - second: first\n" | ||
"{red}{line}{nc}\n" | ||
"{stack_trace}" | ||
"{red}{line}{nc}".format( | ||
line="-" * 60, stack_trace=stack_trace, **colors | ||
line="-" * 60, | ||
stack_trace=stack_trace, | ||
**colors, | ||
datetime=dt | ||
) | ||
) | ||
assert expected == formatter.format(caplog.records[0]) | ||
|
@@ -179,3 +206,21 @@ def test_handlers(): | |
assert out.level == logging.INFO | ||
assert deb.level == logging.DEBUG | ||
assert err.level == logging.WARNING | ||
|
||
|
||
def test_logging_debug_with_datetime(caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
logger.warning("WARNING") | ||
logger.debug("DEBUG") | ||
logger.error("ERROR") | ||
|
||
for record in caplog.records: | ||
assert dt in formatter.format(record) | ||
assert record.levelname == record.message | ||
|
||
|
||
def test_info_with_debug_loglevel_shows_no_datetime(caplog, dt): | ||
with caplog.at_level(logging.DEBUG, logger="dvc"): | ||
logger.info("message") | ||
|
||
assert "message" == formatter.format(caplog.records[0]) |
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The default output looks like
2020-02-14 17:13:44,627
. I did not really tried fighting with the format and went with default one. Plus, this supports settingdatefmt
from dictConfig.There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
If we need a different format later on, we can just change in the
dictConfig
anyway. πThere was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Yeah, a bit long for my taste. We could shorten stuff like year (cut it off or shorten to "20"), but it won't make a big deal. I'm ok with leaving it as is. π
Also, really like the implementation π