McSinyx
/
pip
mirror of https://github.com/pypa/pip
1
1
Fork 0
Code Issues Releases Activity

Add milliseconds to --log entry timestamps. (#6621) 

Resolves #6587.
This commit is contained in:
Christopher Hunt 2019-06-17 17:50:41 -04:00 committed by Chris Jerdonek
parent 2e67cd17fb
commit 26cdedd618
4 changed files with 20 additions and 10 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
news/6587.feature Normal file
View File

@ -0,0 +1 @@
Update timestamps in pip's ``--log`` file to include milliseconds.

9
src/pip/_internal/utils/logging.py
View File

@ -92,6 +92,7 @@ def get_indentation():
class IndentingFormatter(logging.Formatter):
def __init__(self, *args, **kwargs):
"""
A logging.Formatter that obeys the indent_log() context manager.
@ -120,8 +121,8 @@ class IndentingFormatter(logging.Formatter):
def format(self, record):
"""
Calls the standard formatter, but will indent all of the log messages
by our current indentation level.
Calls the standard formatter, but will indent all of the log message
lines by our current indentation level.
"""
formatted = super(IndentingFormatter, self).format(record)
message_start = self.get_message_start(formatted, record.levelno)
@ -129,7 +130,9 @@ class IndentingFormatter(logging.Formatter):
prefix = ''
if self.add_timestamp:
prefix = self.formatTime(record, "%Y-%m-%dT%H:%M:%S ")
# TODO: Use Formatter.default_time_format after dropping PY2.
t = self.formatTime(record, "%Y-%m-%dT%H:%M:%S")
prefix = '%s,%03d ' % (t, record.msecs)
prefix += " " * get_indentation()
formatted = "".join([
prefix + line

8
tests/unit/test_base_command.py
View File

@ -81,7 +81,7 @@ class Test_base_command_logging(object):
def setup(self):
self.old_time = time.time
time.time = lambda: 1547704837.4
time.time = lambda: 1547704837.040001
self.old_tz = os.environ.get('TZ')
os.environ['TZ'] = 'UTC'
# time.tzset() is not implemented on some platforms (notably, Windows).
@ -105,7 +105,7 @@ class Test_base_command_logging(object):
log_path = tmpdir.join('log')
cmd.main(['fake', '--log', log_path])
with open(log_path) as f:
assert f.read().rstrip() == '2019-01-17T06:00:37 fake'
assert f.read().rstrip() == '2019-01-17T06:00:37,040 fake'
def test_log_command_error(self, tmpdir):
"""
@ -115,7 +115,7 @@ class Test_base_command_logging(object):
log_path = tmpdir.join('log')
cmd.main(['fake', '--log', log_path])
with open(log_path) as f:
assert f.read().startswith('2019-01-17T06:00:37 fake')
assert f.read().startswith('2019-01-17T06:00:37,040 fake')
def test_log_file_command_error(self, tmpdir):
"""
@ -125,7 +125,7 @@ class Test_base_command_logging(object):
log_file_path = tmpdir.join('log_file')
cmd.main(['fake', '--log-file', log_file_path])
with open(log_file_path) as f:
assert f.read().startswith('2019-01-17T06:00:37 fake')
assert f.read().startswith('2019-01-17T06:00:37,040 fake')
def test_unicode_messages(self, tmpdir):
"""

12
tests/unit/test_logging.py
View File

@ -51,7 +51,10 @@ class TestIndentingFormatter(object):
def make_record(self, msg, level_name):
level_number = getattr(logging, level_name)
attrs = dict(
msg=msg, created=1547704837.4, levelname=level_name,
msg=msg,
created=1547704837.040001,
msecs=40,
levelname=level_name,
levelno=level_number,
)
record = logging.makeLogRecord(attrs)
@ -75,9 +78,12 @@ class TestIndentingFormatter(object):
assert f.format(record) == expected
@pytest.mark.parametrize('level_name, expected', [
('INFO', '2019-01-17T06:00:37 hello\n2019-01-17T06:00:37 world'),
('INFO',
'2019-01-17T06:00:37,040 hello\n'
'2019-01-17T06:00:37,040 world'),
('WARNING',
'2019-01-17T06:00:37 WARNING: hello\n2019-01-17T06:00:37 world'),
'2019-01-17T06:00:37,040 WARNING: hello\n'
'2019-01-17T06:00:37,040 world'),
])
def test_format_with_timestamp(self, level_name, expected):
record = self.make_record('hello\nworld', level_name=level_name)