def test_200_log_writer_uses_new_log_file(self):
"""Test switching LogWriterProcess to use new log file specified."""
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.txt")
new_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.txt")
self.uut = log_process.LogWriterProcess("fake_device",
self.exception_queue,
self.command_queue,
self.log_queue, old_log_path)
switchboard_process.put_message(
self.command_queue, (log_process.CMD_NEW_LOG_FILE, new_log_path))
wait_for_queue_writes(self.command_queue)
self.uut._pre_run_hook() # Open old log file
self.uut._do_work(
) # Process new log file command and opens new log file
switchboard_process.put_message(self.log_queue, _FULL_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._do_work() # Writes full log message to new log file
self.uut._post_run_hook()
old_lines = self._verify_log_file_and_lines(old_log_path, 1)
new_lines = self._verify_log_file_and_lines(new_log_path, 1)
self.assertNotEqual(
old_lines, new_lines,
"Expected {!r} == {!r}".format(old_lines, new_lines))
def test_013_switchboard_process_put_message_closed_queue(self):
out_queue = multiprocessing_utils.get_context().Queue()
out_queue.close()
with self.assertRaisesRegex((AssertionError, ValueError),
"Queue.*closed"):
switchboard_process.put_message(out_queue,
_ECHO_MESSAGE,
timeout=0)
def test_012_switchboard_process_put_message_full_queue(self):
"""Test putting message into an full queue."""
out_queue = multiprocessing_utils.get_context().Queue(maxsize=1)
switchboard_process.put_message(out_queue, _ECHO_MESSAGE)
with self.assertRaises(queue.Full):
switchboard_process.put_message(out_queue,
_ECHO_MESSAGE,
timeout=0)
def log_message(log_queue, raw_log_line, port):
"""Add host system timestamp to log_line and add result to log_queue.
Args:
log_queue (Queue): to send final log message to
raw_log_line (str): to add system timestamp and GDM log header to
port (int or str): to identify as source for log line
"""
switchboard_process.put_message(log_queue,
_add_log_header(raw_log_line, port))
def test_010_log_writer_writes_full_log_line(self):
"""Test writing full log line to file."""
log_file_name = self._testMethodName + ".txt"
log_path = os.path.join(self.artifacts_directory, log_file_name)
self.uut = log_process.LogWriterProcess("fake_device",
self.exception_queue,
self.command_queue,
self.log_queue, log_path)
switchboard_process.put_message(self.log_queue, _FULL_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._pre_run_hook()
self.uut._do_work()
self.uut._post_run_hook()
self._verify_log_file_and_lines(log_path, 1)
def test_011_log_writer_writes_partial_log_line(self):
"""Test writing partial log lines with unicode characters to file."""
log_file_name = self._testMethodName + ".txt"
log_path = os.path.join(self.artifacts_directory, log_file_name)
self.uut = log_process.LogWriterProcess("fake_device",
self.exception_queue,
self.command_queue,
self.log_queue, log_path)
switchboard_process.put_message(self.log_queue, _PARTIAL_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._pre_run_hook()
self.uut._do_work()
self.uut._post_run_hook()
lines = self._verify_log_file_and_lines(log_path, 1)
self.assertIn(
"[NO EOL]", lines[0],
"Expected '[NO EOL]' at end of partial line found {!r}".format(
lines[0]))
def test_211_log_writer_new_log_command_handled_before_log_rotate(self):
"""Test new log message could but doesn't trigger rotate log."""
max_log_size = len(_NEW_LOG_FILE_MESSAGE)
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.txt")
new_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.txt")
next_log_path1 = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.00001.txt")
next_log_path2 = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.00001.txt")
self.uut = log_process.LogWriterProcess("fake_device",
self.exception_queue,
self.command_queue,
self.log_queue,
old_log_path,
max_log_size=max_log_size)
switchboard_process.put_message(
self.command_queue, (log_process.CMD_NEW_LOG_FILE, new_log_path))
wait_for_queue_writes(self.command_queue)
self.uut._pre_run_hook() # Opens old log file
self.uut._do_work(
) # Process new log file command and opens new log file
self.uut._do_work() # Allows for possible log rotation issue
self.uut._post_run_hook()
old_lines = self._verify_log_file_and_lines(old_log_path, 1)
self._verify_log_file_and_lines(new_log_path, 0)
self.assertIn(
log_process.NEW_LOG_FILE_MESSAGE, old_lines[0],
"Expected {} log message in old log file found {!r}".format(
log_process.NEW_LOG_FILE_MESSAGE, old_lines))
self.assertTrue(os.path.exists(new_log_path),
"Expected new log file of {}".format(new_log_path))
self.assertFalse(
os.path.exists(next_log_path1),
"Expected no log rotation to {}".format(next_log_path1))
self.assertFalse(
os.path.exists(next_log_path2),
"Expected no log rotation to {}".format(next_log_path2))
def test_201_log_filter_ignores_extra_new_log_file_message(self):
"""Test LogFilterProcess ignores spurious new log file message."""
filters = []
parser_obj = event_parser_default.EventParserDefault(
filters, event_file_path="/foo.txt", device_name="device-1234")
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.txt")
new_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.txt")
old_event_path = log_process.get_event_filename(old_log_path)
new_event_path = log_process.get_event_filename(new_log_path)
self.uut = log_process.LogFilterProcess("fake_device",
self.exception_queue,
self.command_queue, parser_obj,
old_log_path)
self._append_to_log_file(old_log_path)
self._append_to_log_file(new_log_path)
self.uut._pre_run_hook()
self.uut._do_work(
) # Opens old log and event files and processes first line
self._append_to_log_file(old_log_path, log_line=_NEW_LOG_FILE_MESSAGE)
self.uut._do_work(
) # Process next line in and tries to switch to next log
self.assertTrue(os.path.exists(old_event_path),
"Expected {} to exist".format(old_event_path))
self.assertFalse(os.path.exists(new_event_path),
"Expected {} to not exist".format(new_event_path))
switchboard_process.put_message(
self.command_queue, (log_process.CMD_NEW_LOG_FILE, new_log_path))
wait_for_queue_writes(self.command_queue)
self._append_to_log_file(old_log_path, log_line=_NEW_LOG_FILE_MESSAGE)
self.uut._do_work() # Process next line in old log file and closes it
self.uut._do_work(
) # Opens new log and event files and processes first line
self.assertTrue(os.path.exists(old_event_path),
"Expected {} to exist".format(old_event_path))
self.assertTrue(os.path.exists(new_event_path),
"Expected {} to exist".format(new_event_path))
self.uut._post_run_hook()
def test_212_log_writer_can_change_max_log_size(self):
"""Test LogWriterProcess can change max_log_size."""
max_log_size = 0
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.txt")
next_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.00001.txt")
self.uut = log_process.LogWriterProcess(
"fake_device",
self.exception_queue,
self.command_queue,
self.log_queue,
old_log_path,
max_log_size=len(_FULL_LOG_MESSAGE))
switchboard_process.put_message(
self.command_queue, (log_process.CMD_MAX_LOG_SIZE, max_log_size))
wait_for_queue_writes(self.command_queue)
self.uut._pre_run_hook() # Opens old log file
self.uut._do_work(
) # Process max_log_size command and opens new log file
switchboard_process.put_message(self.log_queue, _FULL_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._do_work() # Allows for possible log rotation issue
self.uut._post_run_hook()
old_lines = self._verify_log_file_and_lines(old_log_path, 2)
self.assertIn(
log_process.CHANGE_MAX_LOG_SIZE, old_lines[0],
"Expected {} log message in old log file found {!r}".format(
log_process.CHANGE_MAX_LOG_SIZE, old_lines))
self.assertIn(
_FULL_LOG_MESSAGE, old_lines[1],
"Expected {} log message in old log file found {!r}".format(
_FULL_LOG_MESSAGE, old_lines))
self.assertFalse(
os.path.exists(next_log_path),
"Expected no log rotation to {}".format(next_log_path))
def test_210_log_writer_rotates_log_file(self):
"""Test LogWriterProcess rotating to new log file."""
max_log_size = len(_FULL_LOG_MESSAGE)
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName, "fake-device.txt")
new_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device.00001.txt")
next_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device.00002.txt")
self.uut = log_process.LogWriterProcess("fake_device",
self.exception_queue,
self.command_queue,
self.log_queue,
old_log_path,
max_log_size=max_log_size)
switchboard_process.put_message(self.log_queue, _FULL_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._pre_run_hook()
self.uut._do_work()
switchboard_process.put_message(self.log_queue, _SHORT_LOG_MESSAGE)
wait_for_queue_writes(self.log_queue)
self.uut._do_work()
self.uut._post_run_hook()
old_lines = self._verify_log_file_and_lines(old_log_path, 2)
self._verify_log_file_and_lines(new_log_path, 1)
self.assertIn(
log_process.ROTATE_LOG_MESSAGE, old_lines[1],
"Expected {} log message in old log file found {!r}".format(
log_process.ROTATE_LOG_MESSAGE, old_lines))
self.assertTrue(os.path.exists(new_log_path),
"Expected log rotation to {}".format(new_log_path))
self.assertFalse(
os.path.exists(next_log_path),
"Expected no log rotation to {}".format(next_log_path))
def test_211_log_filter_new_log_message_doesnt_trigger_rotate(self):
"""Test rotate log message appears after new log file command."""
filters = []
parser_obj = event_parser_default.EventParserDefault(
filters, event_file_path="/foo.txt", device_name="device-1234")
old_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.txt")
old_event_path = log_process.get_event_filename(old_log_path)
new_log_path = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.txt")
new_event_path = log_process.get_event_filename(new_log_path)
next_log_path1 = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-old.00001.txt")
next_event_path1 = log_process.get_event_filename(next_log_path1)
next_log_path2 = os.path.join(self.artifacts_directory,
self._testMethodName,
"fake-device-new.00001.txt")
next_event_path2 = log_process.get_event_filename(next_log_path2)
self.uut = log_process.LogFilterProcess("fake_device",
self.exception_queue,
self.command_queue, parser_obj,
old_log_path)
self._append_to_log_file(old_log_path)
self._append_to_log_file(next_log_path1)
self._append_to_log_file(new_log_path)
self.uut._pre_run_hook()
self.uut._do_work(
) # Opens old log and event files and processes first line
switchboard_process.put_message(
self.command_queue, (log_process.CMD_NEW_LOG_FILE, new_log_path))
wait_for_queue_writes(self.command_queue)
self._append_to_log_file(old_log_path, log_line=_ROTATE_LOG_MESSAGE)
self.uut._do_work(
) # Process next line in old log file and rotates log file
self.assertTrue(os.path.exists(old_event_path),
"Expected {} to exist".format(old_event_path))
self.assertFalse(os.path.exists(new_event_path),
"Expected {} to not exist".format(new_event_path))
self.assertFalse(os.path.exists(next_event_path1),
"Expected {} to not exist".format(next_event_path1))
self.assertFalse(os.path.exists(next_event_path2),
"Expected {} to not exist".format(next_event_path2))
self._append_to_log_file(next_log_path1,
log_line=_NEW_LOG_FILE_MESSAGE)
self.uut._do_work(
) # Process next line in next log file 1 and opens new log file
self.assertTrue(os.path.exists(old_event_path),
"Expected {} to exist".format(old_event_path))
self.assertFalse(os.path.exists(new_event_path),
"Expected {} to not exist".format(new_event_path))
self.assertFalse(os.path.exists(next_event_path1),
"Expected {} to not exist".format(next_event_path1))
self.assertFalse(os.path.exists(next_event_path2),
"Expected {} to not exist".format(next_event_path2))
self.uut._do_work() # Keeps reading from new log file
self.assertTrue(os.path.exists(old_event_path),
"Expected {} to exist".format(old_event_path))
self.assertTrue(os.path.exists(new_event_path),
"Expected {} to exist".format(new_event_path))
self.assertFalse(os.path.exists(next_event_path1),
"Expected {} to not exist".format(next_event_path1))
self.assertFalse(os.path.exists(next_event_path2),
"Expected {} to not exist".format(next_event_path2))
self.uut._post_run_hook()
def test_011_switchboard_process_put_message_bad_queue(self):
"""Test putting message into a bad queue."""
with self.assertRaisesRegex(ValueError, "Invalid queue of"):
switchboard_process.put_message(BadQueue(), _ECHO_MESSAGE)
def test_010_switchboard_process_put_message_no_queue(self):
"""Test putting message into no queue."""
with self.assertRaisesRegex(ValueError, "Invalid queue of"):
switchboard_process.put_message(None, _ECHO_MESSAGE)
def _publish_line(self, line):
if self._raw_data_enabled.is_set():
switchboard_process.put_message(self._raw_data_queue,
(self._raw_data_id, line),
timeout=0)
log_process.log_message(self._log_queue, line, self._raw_data_id)