def test_formatter_with_exception():
fmt = logs.StructuredFormatter()
try:
e = Exception()
e.errno = 101
e.strerror = 'some error'
raise e
except Exception:
record = make_record({})
record.exc_info = sys.exc_info()
log = fmt.format(record)
assert '\n' in log
output = log.splitlines()
timestamp, level, name, msg, structured = parse_logfmt(output[0])
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
assert msg == "msg here"
if platform.system() == 'Darwin':
assert structured == {
'errno': 'ETIME',
'strerror': 'some error',
}
else:
assert structured == {
'errno': 'ENETUNREACH',
'strerror': 'some error',
}
assert 'Traceback' in output[1]
assert 'Exception' in output[-1]
def test_logger_collects_raven_breadcrumbs():
try:
import raven.context
except ImportError:
pytest.skip('need raven installed')
fmt = logs.StructuredFormatter()
with raven.context.Context() as ctx:
record = make_record(
{
'foo': 'bar',
'number': 1,
},
'msg',
)
record.levelno = logging.INFO
record.levelname = 'info'
record.funcName = 'func'
fmt.format(record)
breadcrumbs = ctx.breadcrumbs.get_buffer()
assert len(breadcrumbs) == 1
assert breadcrumbs[0]['message'] == 'msg'
assert breadcrumbs[0]['level'] == 'info'
assert breadcrumbs[0]['category'] == 'name'
assert breadcrumbs[0]['data'] == {
'foo': 'bar',
'location': 'fn:lno:func',
'number': '1',
}
def test_logfmt_atoms_subdict(monkeypatch, context):
fmt = logs.StructuredFormatter()
# dicts
subdict = OrderedDict()
subdict['int'] = 1
subdict['intstr'] = "1"
subdict['bool'] = True
subdict['string'] = 'string'
subdict['long'] = '12345678901234567890'
subdict['dict'] = {'key': 'value'}
subdict['list'] = [1, 2, 3]
subdict[2] = 'int key'
subdict[(3, )] = 'bad key'
expected = [
('foo_int', '1'),
('foo_intstr', '"1"'),
('foo_bool', 'true'),
('foo_string', 'string'),
('foo_long', '1234567890...'),
('foo_dict', '"' + str(type({})) + '"'),
('foo_list', '"' + str(type([])) + '"'),
('foo_2', '"int key"'),
]
monkeypatch.setattr(fmt, 'MAX_VALUE_SIZE', 10)
input = {
'foo': subdict,
(4, ): 'bad_key',
}
assert list(fmt.logfmt_atoms(input)) == expected
assert 'could not parse logfmt' in context.logs[-1].msg
assert '(3,)' in context.logs[-1].msg
assert '(4,)' in context.logs[-1].msg
def test_formatter_no_args():
fmt = logs.StructuredFormatter()
log = fmt.format(make_record({}))
timestamp, level, name, msg, structured = parse_logfmt(log)
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
assert msg == "msg here"
assert structured == {}
def test_formatter_escapes_quotes():
fmt = logs.StructuredFormatter()
log = fmt.format(make_record({'a': 'b'}, msg='some " quotes'))
timestamp, level, name, msg, structured = parse_logfmt(log)
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
# check quotes doesn't break parsing
assert msg == 'some " quotes'
assert structured == {'a': 'b'}
def test_formatter_large_msg(monkeypatch):
monkeypatch.setattr(logs.StructuredFormatter, 'MAX_MSG_SIZE', 5)
fmt = logs.StructuredFormatter()
log = fmt.format(make_record({}, msg='1234567890'))
timestamp, level, name, msg, structured = parse_logfmt(log)
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
assert msg == "12345..."
assert structured == {}
def test_logfmt():
fmt = logs.StructuredFormatter()
assert fmt.logfmt('foo', 'bar') == 'foo=bar'
assert fmt.logfmt('foo', 'bar baz') == 'foo="bar baz"'
assert fmt.logfmt('foo', '"baz"') == r'foo=baz'
assert fmt.logfmt('foo', 'bar "baz"') == r'foo="bar baz"'
assert fmt.logfmt('foo', b'bar') == r'foo=bar'
assert fmt.logfmt(b'foo', 'bar') == r'foo=bar'
assert fmt.logfmt('foo foo', 'bar') == r'foo_foo=bar'
assert fmt.logfmt('foo"', 'bar') == r'foo=bar'
assert fmt.logfmt('foo"', 1) == r'foo=1'
def test_formatter_with_extra():
fmt = logs.StructuredFormatter()
log = fmt.format(make_record({'foo': 'bar', 'baz': 'with spaces'}))
timestamp, level, name, msg, structured = parse_logfmt(log)
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
assert msg == "msg here"
assert structured == {
'foo': 'bar',
'baz': 'with spaces',
}
def test_formatter_protected(monkeypatch):
fmt = logs.StructuredFormatter()
# make this formatter error
def error(*args, **kwargs):
raise Exception()
fmt.clean_message = error
record = make_record({})
log = fmt.format(record)
# falls back to default formatter
assert log == '2016-01-17 12:30:10.123Z INFO name "msg here"'
def test_logfmt_atom():
fmt = logs.StructuredFormatter()
assert fmt.logfmt_atom('foo', 'bar') == 'foo=bar'
# quoting
assert fmt.logfmt_atom('foo', 'bar baz') == 'foo="bar baz"'
assert fmt.logfmt_atom('foo', 'bar\tbaz') == 'foo="bar\tbaz"'
assert fmt.logfmt_atom('foo', 'bar=baz') == r'foo="bar=baz"'
# strip quotes
assert fmt.logfmt_atom('foo', '"baz"') == r'foo=baz'
assert fmt.logfmt_atom('foo', 'bar "baz"') == r'foo="bar baz"'
assert fmt.logfmt_atom('foo"', 'bar') == r'foo=bar'
# encoding
assert fmt.logfmt_atom('foo', b'bar') == r'foo=bar'
assert fmt.logfmt_atom(b'foo', 'bar') == r'foo=bar'
# key replacement
assert fmt.logfmt_atom('foo bar', 'baz') == r'foo_bar=baz'
assert fmt.logfmt_atom('foo=bar', 'baz') == r'foo_bar=baz'
assert fmt.logfmt_atom('foo.bar', 'baz') == r'foo_bar=baz'
def test_formatter_with_exception():
fmt = logs.StructuredFormatter()
try:
raise Exception()
except:
record = make_record({})
record.exc_info = sys.exc_info()
log = fmt.format(record)
assert '\n' in log
output = log.splitlines()
timestamp, level, name, msg, structured = parse_logfmt(output[0])
assert timestamp == TIMESTAMP
assert level == 'INFO'
assert name == 'name'
assert msg == "msg here"
assert structured == {}
assert 'Traceback' in output[1]
assert 'Exception' in output[-1]
def test_logger_collects_raven_breadcrumbs():
fmt = logs.StructuredFormatter()
with raven.context.Context() as ctx:
fmt.format(make_record({'foo': 'bar'}, 'info'))
record = make_record({'foo': 'bar'}, 'info')
record.levelno = logging.DEBUG
record.levelname = 'debug'
fmt.format(record)
breadcrumbs = ctx.breadcrumbs.get_buffer()
assert len(breadcrumbs) == 1
assert breadcrumbs[0]['message'] == 'info'
assert breadcrumbs[0]['level'] == 'info'
assert breadcrumbs[0]['category'] == 'name'
assert breadcrumbs[0]['data'] == {
'foo': 'bar',
'lineno': 'lno',
'path': 'fn',
}
def test_logfmt_atoms(input, expected):
fmt = logs.StructuredFormatter()
assert list(fmt.logfmt_atoms(input)) == expected
def test_escape_quotes():
fmt = logs.StructuredFormatter()
assert fmt.escape_quotes('foo') == 'foo'
assert fmt.escape_quotes('foo "bar"') == r'foo \"bar\"'
def test_clean_message():
fmt = logs.StructuredFormatter()
assert fmt.clean_message('foo') == 'foo'
assert fmt.clean_message('foo "bar"') == r'foo \"bar\"'
assert fmt.clean_message('foo "bar"') == r'foo \"bar\"'
assert fmt.clean_message('foo\nbar') == r'foo\nbar'
def test_logfmt_key_truncate():
fmt = logs.StructuredFormatter()
fmt.MAX_KEY_SIZE = 5
assert fmt.logfmt_key('1234567890') == '12345___'
# check newlines and max length
assert fmt.logfmt_key('123\n456\n789\n0') == '123___'
def test_logfmt_value(input, expected):
fmt = logs.StructuredFormatter()
assert fmt.logfmt_value(input) == expected
def test_safe_string(input, expected):
fmt = logs.StructuredFormatter()
assert fmt.safe_string(input, 7, '...') == expected
def test_string_needs_quoting(input, expected):
fmt = logs.StructuredFormatter()
assert fmt.string_needs_quoting(input) == expected
def test_logfmt_value_truncate():
fmt = logs.StructuredFormatter()
fmt.MAX_VALUE_SIZE = 5
assert fmt.logfmt_value('1234567890') == '12345...'
# check newlines and max length
assert fmt.logfmt_value('123\n456\n789\n0') == '123...'
