Taskgraph can log messages in subprocesses that have a lower priority than the parent log level
Opened this issue · 0 comments
richpsharp commented
To observe this, update the test that tests for multiprocesssed logging to this and watch it fail:
def test_multiprocessed_logging(self):
"""TaskGraph: ensure tasks can log from multiple processes."""
logger_name = 'test.task.queuelogger'
log_message = 'This is coming from another process'
logger = logging.getLogger(logger_name)
file_log_path = os.path.join(
self.workspace_dir, 'test_multiprocessed_logging.log')
file_handler = logging.FileHandler(file_log_path)
file_handler.setFormatter(
logging.Formatter(fmt=':%(processName)s:%(message)s:'))
logger.addHandler(file_handler)
task_graph = taskgraph.TaskGraph(self.workspace_dir, 1)
# this first message shouldn't print because logger level is a warning
# and _log_from_another_process is info level
logger.setLevel(logging.WARNING)
log_task = task_graph.add_task(
func=_log_from_another_process,
args=(logger_name, 'YOU WILL NOT SEE THIS'))
log_task.join()
# second should log because logger level is set to info
logger.setLevel(logging.INFO)
log_task = task_graph.add_task(
func=_log_from_another_process,
args=(logger_name, log_message))
log_task.join()
task_graph.close()
task_graph.join()
file_handler.flush()
file_handler.close()
@retrying.retry(wait_exponential_multiplier=100,
wait_exponential_max=1000,
stop_max_attempt_number=5)
def get_name_and_message():
with open(file_log_path, 'r') as log_file:
message = log_file.read().rstrip()
process_name, logged_message = re.match(
':([^:]*):([^:]*):', message).groups()
return process_name, logged_message
process_name, logged_message = get_name_and_message()
self.assertEqual(logged_message, log_message)
self.assertNotEqual(
process_name, multiprocessing.current_process().name)