diff --git a/.gitlab-ci/lava/utils/log_follower.py b/.gitlab-ci/lava/utils/log_follower.py index e842acc4505..b2bfcf36c90 100644 --- a/.gitlab-ci/lava/utils/log_follower.py +++ b/.gitlab-ci/lava/utils/log_follower.py @@ -40,6 +40,7 @@ class LogFollower: _buffer: list[str] = field(default_factory=list, init=False) log_hints: LAVALogHints = field(init=False) lava_farm: LavaFarm = field(init=False, default=get_lava_farm()) + _merge_next_line: str = field(default_factory=str, init=False) def __post_init__(self): section_is_created = bool(self.current_section) @@ -127,15 +128,50 @@ class LogFollower: return False def remove_trailing_whitespace(self, line: dict[str, str]) -> None: + """ + Removes trailing whitespace from the end of the `msg` value in the log line dictionary. + + Args: + line: A dictionary representing a single log line. + + Note: + LAVA treats carriage return characters as a line break, so each carriage return in an output console + is mapped to a console line in LAVA. This method removes trailing `\r\n` characters from log lines. + """ msg: Optional[str] = line.get("msg") if not msg: - return + return False messages = [msg] if isinstance(msg, str) else msg for message in messages: - # LAVA logs brings raw messages, which includes newlines characters. - line["msg"]: str = message.rstrip("\n") + # LAVA logs brings raw messages, which includes newlines characters as \r\n. + line["msg"]: str = re.sub(r"\r\n$", "", message) + + def merge_carriage_return_lines(self, line: dict[str, str]) -> bool: + """ + Merges lines that end with a carriage return character into a single line. + + Args: + line: A dictionary representing a single log line. + + Returns: + A boolean indicating whether the current line has been merged with the next line. + + Note: + LAVA treats carriage return characters as a line break, so each carriage return in an output console + is mapped to a console line in LAVA. + """ + if line["msg"].endswith("\r"): + self._merge_next_line += line["msg"] + return True + + if self._merge_next_line: + line["msg"] = self._merge_next_line + line["msg"] + self._merge_next_line = "" + + return False + def feed(self, new_lines: list[dict[str, str]]) -> bool: """Input data to be processed by LogFollower instance @@ -153,6 +189,9 @@ class LogFollower: if self.detect_kernel_dump_line(line): continue + if self.merge_carriage_return_lines(line): + continue + # At least we are fed with a non-kernel dump log, it seems that the # job is progressing is_job_healthy = True diff --git a/.gitlab-ci/tests/utils/test_lava_log.py b/.gitlab-ci/tests/utils/test_lava_log.py index 416f3724526..882d33f6607 100644 --- a/.gitlab-ci/tests/utils/test_lava_log.py +++ b/.gitlab-ci/tests/utils/test_lava_log.py @@ -217,6 +217,36 @@ def test_lava_gitlab_section_log_collabora(expected_message, messages, monkeypat assert new_messages == expected_message +CARRIAGE_RETURN_SCENARIOS = { + "Carriage return at the end of the previous line": ( + ( + "\x1b[0Ksection_start:1677609903:test_setup[collapsed=true]\r\x1b[0K\x1b[0;36m[303:44] deqp: preparing test setup\x1b[0m", + ), + ( + "\x1b[0Ksection_start:1677609903:test_setup[collapsed=true]\r", + "\x1b[0K\x1b[0;36m[303:44] deqp: preparing test setup\x1b[0m\r\n", + ), + ), + "Newline at the end of the line": ( + ("\x1b[0K\x1b[0;36m[303:44] deqp: preparing test setup\x1b[0m", "log"), + ("\x1b[0K\x1b[0;36m[303:44] deqp: preparing test setup\x1b[0m\r\n", "log"), + ), +} + + +@pytest.mark.parametrize( + "expected_message, messages", + CARRIAGE_RETURN_SCENARIOS.values(), + ids=CARRIAGE_RETURN_SCENARIOS.keys(), +) +def test_lava_log_merge_carriage_return_lines(expected_message, messages): + lf = LogFollower() + for message in messages: + lf.feed([create_lava_yaml_msg(msg=message)]) + new_messages = tuple(lf.flush()) + assert new_messages == expected_message + + WATCHDOG_SCENARIOS = { "1 second before timeout": ({"seconds": -1}, does_not_raise()), "1 second after timeout": ({"seconds": 1}, pytest.raises(MesaCITimeoutError)),