def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest-1").get_initialized_logger(logtarget=dst)
ok_(exists(dst)) # nothing was logged -- no file created
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_(not '\033[' in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
# .* is added to swallow possible traceback logs
if EnsureBool()(cfg.get('datalad.log.timestamp', False)):
ok_(re.match("\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \[ERROR\](\s+\S+\s*)? %s" % msg,
line))
else:
ok_(re.match("\[ERROR\](\s+\S+\s*)? %s" % msg,
line))
def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest-1").get_initialized_logger(logtarget=dst)
ok_(exists(dst)) # nothing was logged -- no file created
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_('\033[' not in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
# (...)? is added to swallow possible traceback logs
regex = "\[ERROR\]"
if EnsureBool()(dl_cfg.get('datalad.log.timestamp', False)):
regex = "\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} " + regex
if EnsureBool()(dl_cfg.get('datalad.log.vmem', False)):
regex += ' RSS/VMS: \S+/\S+( \S+)?\s*'
regex += "(\s+\S+\s*)? " + msg
assert_re_in(regex, line, match=True)
# Close all handlers so windows is happy -- apparently not closed fast enough
for handler in lgr.handlers:
handler.close()
def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest-1").get_initialized_logger(logtarget=dst)
ok_(exists(dst)) # nothing was logged -- no file created
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_(not '\033[' in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
# .* is added to swallow possible traceback logs
if EnsureBool()(cfg.get('datalad.log.timestamp', False)):
ok_(
re.match(
"\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \[ERROR\](\s+\S+\s*)? %s"
% msg, line))
else:
ok_(re.match("\[ERROR\](\s+\S+\s*)? %s" % msg, line))
def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest-1").get_initialized_logger(logtarget=dst)
ok_(exists(dst)) # nothing was logged -- no file created
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_('\033[' not in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
# (...)? is added to swallow possible traceback logs
regex = "\[ERROR\]"
if EnsureBool()(cfg.get('datalad.log.timestamp', False)):
regex = "\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} " + regex
if EnsureBool()(cfg.get('datalad.log.vmem', False)):
regex += ' RSS/VMS: \S+/\S+( \S+)?\s*'
regex += "(\s+\S+\s*)? " + msg
assert_re_in(regex, line, match=True)
# Close all handlers so windows is happy -- apparently not closed fast enough
for handler in lgr.handlers:
handler.close()
def test_filters():
def _mock_names(self, v, d=None):
return 'datalad1.goodone,datalad1.anotherone' if v == 'names' else d
with patch.object(LoggerHelper, '_get_config', _mock_names):
LoggerHelper('datalad1').get_initialized_logger()
check_filters('datalad1')
def _mock_namesre(self, v, d=None):
return 'datalad.*one' if v == 'namesre' else d
with patch.object(LoggerHelper, '_get_config', _mock_namesre):
LoggerHelper('datalad2').get_initialized_logger()
check_filters('datalad2')
def test_mutliple_targets(dst1, dst2):
ok_(not exists(dst1))
ok_(not exists(dst2))
lgr = LoggerHelper("dataladtest-3").get_initialized_logger(
logtarget="%s,%s" % (dst1, dst2))
ok_(exists(dst1))
ok_(exists(dst2))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
for dst in (dst1, dst2):
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
ok_(msg in lines[0])
def test_logtarget_via_env_variable(dst=None):
with patch.dict('os.environ', {'DATALADTEST_LOG_TARGET': dst}):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest-2").get_initialized_logger()
ok_(not exists(dst))
# just to see that mocking patch worked
ok_('DATALADTEST_LOG_TARGET' not in os.environ)
def test_mutliple_targets(dst1, dst2):
ok_(not exists(dst1))
ok_(not exists(dst2))
lgr = LoggerHelper("dataladtest-3").get_initialized_logger(
logtarget="%s,%s" % (dst1, dst2))
ok_(exists(dst1))
ok_(exists(dst2))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
for dst in (dst1, dst2):
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1,
"Read more than a single log line: %s" % lines)
ok_(msg in lines[0])
def test_mutliple_targets(dst1=None, dst2=None):
ok_(not exists(dst1))
ok_(not exists(dst2))
lgr = LoggerHelper("dataladtest-3").get_initialized_logger(
logtarget="%s,%s" % (dst1, dst2))
ok_(exists(dst1))
ok_(exists(dst2))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
for dst in (dst1, dst2):
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
ok_(msg in lines[0])
# Close all handlers so windows is happy -- apparently not closed fast enough
for handler in lgr.handlers:
handler.close()
def test_mutliple_targets(dst1, dst2):
ok_(not exists(dst1))
ok_(not exists(dst2))
lgr = LoggerHelper("dataladtest-3").get_initialized_logger(
logtarget="%s,%s" % (dst1, dst2))
ok_(exists(dst1))
ok_(exists(dst2))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
for dst in (dst1, dst2):
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
ok_(msg in lines[0])
# Close all handlers so windows is happy -- apparently not closed fast enough
for handler in lgr.handlers:
handler.close()
def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest").get_initialized_logger(logtarget=dst)
ok_(exists(dst))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_(not '\033[' in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
ok_(re.match("\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \[ERROR\] %s" % msg,
line))
def test_logging_to_a_file(dst):
ok_(not exists(dst))
lgr = LoggerHelper("dataladtest").get_initialized_logger(logtarget=dst)
ok_(exists(dst))
msg = "Oh my god, they killed Kenny"
lgr.error(msg)
with open(dst) as f:
lines = f.readlines()
assert_equal(len(lines), 1, "Read more than a single log line: %s" % lines)
line = lines[0]
ok_(msg in line)
ok_(not '\033[' in line,
msg="There should be no color formatting in log files. Got: %s" % line)
# verify that time stamp and level are present in the log line
# do not want to rely on not having race conditions around date/time changes
# so matching just with regexp
ok_(
re.match(
"\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2},\d{3} \[ERROR\] %s" % msg,
line))
def test_log_progress_noninteractive_filter():
name = "dl-test"
lgr = LoggerHelper(name).get_initialized_logger()
pbar_id = "lp_test"
with swallow_logs(new_level=logging.INFO, name=name) as cml:
log_progress(lgr.info, pbar_id, "Start", label="testing", total=3)
log_progress(lgr.info, pbar_id, "THERE0", update=1)
log_progress(lgr.info, pbar_id, "NOT", update=1,
noninteractive_level=logging.DEBUG)
log_progress(lgr.info, pbar_id, "THERE1", update=1,
noninteractive_level=logging.INFO)
log_progress(lgr.info, pbar_id, "Done")
for present in ["Start", "THERE0", "THERE1", "Done"]:
assert_in(present, cml.out)
assert_not_in("NOT", cml.out)
def test_message_pbar_state_logging_is_demoted():
from datalad.log import LoggerHelper
name = "dl-test"
lgr = LoggerHelper(name).get_initialized_logger()
ui = ConsoleLog()
with patch("datalad.ui.dialog.lgr", lgr):
with swallow_logs(name=name, new_level=20) as cml:
ui.message("testing 0")
assert_not_in("Clear progress bars", cml.out)
assert_not_in("Refresh progress bars", cml.out)
with swallow_logs(name=name, new_level=5) as cml:
ui.message("testing 1")
assert_in("Clear progress bars", cml.out)
assert_in("Refresh progress bars", cml.out)
def __call__(self, parser, namespace, values, option_string=None):
from datalad.log import LoggerHelper
LoggerHelper().set_level(level=values)
