From f3850c97d1e3e1dd693c596b658a9a1e69cf5347 Mon Sep 17 00:00:00 2001 From: Guilherme Gallo Date: Wed, 10 Jan 2024 18:18:42 -0300 Subject: [PATCH] ci/lava: Fix the integration test During the development of this fix, I utilized the `test_full_yaml_log` test, which is marked as slow. This test is excellent for reproducing past job submissions. It can be executed using the following commands: ``` lavacli jobs logs --raw 12496073 > /tmp/log.yaml pytest .gitlab-ci/tests/test_lava_job_submitter.py -m slow -s ``` Here, `12496073` is the LAVA job ID from this specific job: https://gitlab.freedesktop.org/mesa/mesa/-/jobs/53546660 The logs were not functioning as expected due to a few mistakes I made with generators, such as: - Not reusing the `time_traveller_gen` generator to call `next` more than once. - Forgetting to parse the YAML inside `time_travel_from_log_chunk`. Additionally: - Added some statistics at the end of the test to aid in diagnosing whether the test was reproduced accurately. - Renamed some variables for clarity. Signed-off-by: Guilherme Gallo Part-of: --- .gitlab-ci/tests/test_lava_job_submitter.py | 48 +++++++++++++++------ 1 file changed, 35 insertions(+), 13 deletions(-) diff --git a/.gitlab-ci/tests/test_lava_job_submitter.py b/.gitlab-ci/tests/test_lava_job_submitter.py index 6e6a520192c..3f78ba73309 100644 --- a/.gitlab-ci/tests/test_lava_job_submitter.py +++ b/.gitlab-ci/tests/test_lava_job_submitter.py @@ -9,8 +9,9 @@ import os import xmlrpc.client from contextlib import nullcontext as does_not_raise from datetime import datetime -from itertools import chain, repeat +from itertools import islice, repeat from pathlib import Path +from typing import Generator from unittest.mock import MagicMock, patch import pytest @@ -341,13 +342,15 @@ def test_full_yaml_log(mock_proxy, frozen_time, lava_job_submitter): if not data_chunk: return - first_log_time = data_chunk[0]["dt"] + first_log = lava_yaml.load(data_chunk[0])[0] + first_log_time = first_log["dt"] frozen_time.move_to(first_log_time) yield - last_log_time = data_chunk[-1]["dt"] + last_log = lava_yaml.load(data_chunk[-1])[0] + last_log_time = last_log["dt"] frozen_time.move_to(last_log_time) - return + yield def time_travel_to_test_time(): # Suppose that the first message timestamp of the entire LAVA job log is @@ -357,22 +360,31 @@ def test_full_yaml_log(mock_proxy, frozen_time, lava_job_submitter): first_log_time = lava_yaml.load(first_log)[0]["dt"] frozen_time.move_to(first_log_time) - def load_lines() -> list: + def load_lines() -> Generator[tuple[bool, str], None, None]: with open("/tmp/log.yaml", "r") as f: # data = yaml.safe_load(f) - data = f.readlines() - stream = chain(data) + log_lines = f.readlines() + serial_message: str = "" + chunk_start_line = 0 + chunk_end_line = 0 + chunk_max_size = 100 try: while True: - data_chunk = [next(stream) for _ in range(random.randint(0, 50))] - serial_message = "".join(data_chunk) + chunk_end_line = chunk_start_line + random.randint(1, chunk_max_size) + # split the log in chunks of random size + log_chunk = list(islice(log_lines, chunk_start_line, chunk_end_line)) + chunk_start_line = chunk_end_line + 1 + serial_message = "".join(log_chunk) + # time_traveller_gen will make the time trave according to the timestamp from + # the message + time_traveller_gen = time_travel_from_log_chunk(log_chunk) # Suppose that the first message timestamp is the same of # log fetch RPC call - time_travel_from_log_chunk(data_chunk) + next(time_traveller_gen) yield False, "[]" # Travel to the same datetime of the last fetched log line # in the chunk - time_travel_from_log_chunk(data_chunk) + next(time_traveller_gen) yield False, serial_message except StopIteration: yield True, serial_message @@ -384,10 +396,20 @@ def test_full_yaml_log(mock_proxy, frozen_time, lava_job_submitter): proxy.scheduler.jobs.logs.side_effect = load_lines() proxy.scheduler.jobs.submit = reset_logs - with pytest.raises(MesaCIRetryError): + start_time = datetime.now() + try: time_travel_to_test_time() retriable_follow_job(proxy, "") - print(lava_job_submitter.structured_log_file.read_text()) + finally: + try: + # If the job fails, maybe there will be no structured log + print(lava_job_submitter.structured_log_file.read_text()) + finally: + end_time = datetime.now() + print("---- Reproduction log stats ----") + print(f"Start time: {start_time}") + print(f"End time: {end_time}") + print(f"Duration: {end_time - start_time}") @pytest.mark.parametrize(