1#!/usr/bin/env python3 2# 3# Copyright (C) 2022 Collabora Limited 4# Author: Guilherme Gallo <guilherme.gallo@collabora.com> 5# 6# SPDX-License-Identifier: MIT 7 8from datetime import datetime, timedelta 9 10import pytest 11import yaml 12from lava.exceptions import MesaCIKnownIssueException, MesaCITimeoutError 13from lava.utils import ( 14 GitlabSection, 15 LogFollower, 16 LogSectionType, 17 fix_lava_color_log, 18 fix_lava_gitlab_section_log, 19 hide_sensitive_data, 20) 21 22from ..lava.helpers import create_lava_yaml_msg, does_not_raise 23 24GITLAB_SECTION_SCENARIOS = { 25 "start collapsed": ( 26 "start", 27 True, 28 f"\x1b[0Ksection_start:mock_date:my_first_section[collapsed=true]\r\x1b[0K{GitlabSection.colour}my_header\x1b[0m", 29 ), 30 "start non_collapsed": ( 31 "start", 32 False, 33 f"\x1b[0Ksection_start:mock_date:my_first_section\r\x1b[0K{GitlabSection.colour}my_header\x1b[0m", 34 ), 35 "end collapsed": ( 36 "end", 37 True, 38 "\x1b[0Ksection_end:mock_date:my_first_section\r\x1b[0K", 39 ), 40 "end non_collapsed": ( 41 "end", 42 False, 43 "\x1b[0Ksection_end:mock_date:my_first_section\r\x1b[0K", 44 ), 45} 46 47@pytest.mark.parametrize( 48 "method, collapsed, expectation", 49 GITLAB_SECTION_SCENARIOS.values(), 50 ids=GITLAB_SECTION_SCENARIOS.keys(), 51) 52def test_gitlab_section(method, collapsed, expectation): 53 gs = GitlabSection( 54 id="my_first_section", 55 header="my_header", 56 type=LogSectionType.TEST_CASE, 57 start_collapsed=collapsed, 58 ) 59 gs.get_timestamp = lambda x: "mock_date" 60 gs.start() 61 result = getattr(gs, method)() 62 assert result == expectation 63 64 65def test_gl_sections(): 66 lines = [ 67 { 68 "dt": datetime.now(), 69 "lvl": "debug", 70 "msg": "Received signal: <STARTRUN> 0_mesa 5971831_1.3.2.3.1", 71 }, 72 # Redundant log message which triggers the same Gitlab Section, it 73 # should be ignored, unless the id is different 74 { 75 "dt": datetime.now(), 76 "lvl": "target", 77 "msg": "[ 7.778836] <LAVA_SIGNAL_STARTRUN 0_mesa 5971831_1.3.2.3.1>", 78 }, 79 { 80 "dt": datetime.now(), 81 "lvl": "debug", 82 "msg": "Received signal: <STARTTC> mesa-ci_iris-kbl-traces", 83 }, 84 # Another redundant log message 85 { 86 "dt": datetime.now(), 87 "lvl": "target", 88 "msg": "[ 16.997829] <LAVA_SIGNAL_STARTTC mesa-ci_iris-kbl-traces>", 89 }, 90 { 91 "dt": datetime.now(), 92 "lvl": "target", 93 "msg": "<LAVA_SIGNAL_ENDTC mesa-ci_iris-kbl-traces>", 94 }, 95 ] 96 lf = LogFollower() 97 for line in lines: 98 lf.manage_gl_sections(line) 99 100 parsed_lines = lf.flush() 101 assert "section_start" in parsed_lines[0] 102 assert "collapsed=true" not in parsed_lines[0] 103 assert "section_end" in parsed_lines[1] 104 assert "section_start" in parsed_lines[2] 105 assert "collapsed=true" not in parsed_lines[2] 106 assert "section_end" in parsed_lines[3] 107 assert "section_start" in parsed_lines[4] 108 assert "collapsed=true" in parsed_lines[4] 109 110 111def test_log_follower_flush(): 112 lines = [ 113 { 114 "dt": datetime.now(), 115 "lvl": "debug", 116 "msg": "Received signal: <STARTTC> mesa-ci_iris-kbl-traces", 117 }, 118 { 119 "dt": datetime.now(), 120 "lvl": "target", 121 "msg": "<LAVA_SIGNAL_ENDTC mesa-ci_iris-kbl-traces>", 122 }, 123 ] 124 lf = LogFollower() 125 lf.feed(lines) 126 parsed_lines = lf.flush() 127 empty = lf.flush() 128 lf.feed(lines) 129 repeated_parsed_lines = lf.flush() 130 131 assert parsed_lines 132 assert not empty 133 assert repeated_parsed_lines 134 135 136SENSITIVE_DATA_SCENARIOS = { 137 "no sensitive data tagged": ( 138 ["bla bla", "mytoken: asdkfjsde1341=="], 139 ["bla bla", "mytoken: asdkfjsde1341=="], 140 "HIDEME", 141 ), 142 "sensitive data tagged": ( 143 ["bla bla", "mytoken: asdkfjsde1341== # HIDEME"], 144 ["bla bla"], 145 "HIDEME", 146 ), 147 "sensitive data tagged with custom word": ( 148 ["bla bla", "mytoken: asdkfjsde1341== # DELETETHISLINE", "third line"], 149 ["bla bla", "third line"], 150 "DELETETHISLINE", 151 ), 152} 153 154 155@pytest.mark.parametrize( 156 "input, expectation, tag", 157 SENSITIVE_DATA_SCENARIOS.values(), 158 ids=SENSITIVE_DATA_SCENARIOS.keys(), 159) 160def test_hide_sensitive_data(input, expectation, tag): 161 yaml_data = yaml.safe_dump(input) 162 yaml_result = hide_sensitive_data(yaml_data, tag) 163 result = yaml.safe_load(yaml_result) 164 165 assert result == expectation 166 167 168COLOR_MANGLED_SCENARIOS = { 169 "Mangled error message at target level": ( 170 create_lava_yaml_msg(msg="[0m[0m[31mERROR - dEQP error: ", lvl="target"), 171 "\x1b[0m\x1b[0m\x1b[31mERROR - dEQP error: ", 172 ), 173 "Mangled pass message at target level": ( 174 create_lava_yaml_msg( 175 msg="[0mPass: 26718, ExpectedFail: 95, Skip: 25187, Duration: 8:18, Remaining: 13", 176 lvl="target", 177 ), 178 "\x1b[0mPass: 26718, ExpectedFail: 95, Skip: 25187, Duration: 8:18, Remaining: 13", 179 ), 180 "Mangled error message with bold formatting at target level": ( 181 create_lava_yaml_msg(msg="[1;31mReview the image changes...", lvl="target"), 182 "\x1b[1;31mReview the image changes...", 183 ), 184 "Mangled error message with high intensity background at target level": ( 185 create_lava_yaml_msg(msg="[100mReview the image changes...", lvl="target"), 186 "\x1b[100mReview the image changes...", 187 ), 188 "Mangled error message with underline+bg color+fg color at target level": ( 189 create_lava_yaml_msg(msg="[4;41;97mReview the image changes...", lvl="target"), 190 "\x1b[4;41;97mReview the image changes...", 191 ), 192 "Bad input for color code.": ( 193 create_lava_yaml_msg( 194 msg="[4;97 This message is missing the `m`.", lvl="target" 195 ), 196 "[4;97 This message is missing the `m`.", 197 ), 198} 199 200 201@pytest.mark.parametrize( 202 "message, fixed_message", 203 COLOR_MANGLED_SCENARIOS.values(), 204 ids=COLOR_MANGLED_SCENARIOS.keys(), 205) 206def test_fix_lava_color_log(message, fixed_message): 207 fix_lava_color_log(message) 208 209 assert message["msg"] == fixed_message 210 211 212GITLAB_SECTION_MANGLED_SCENARIOS = { 213 "Mangled section_start at target level": ( 214 create_lava_yaml_msg( 215 msg="[0Ksection_start:1652658415:deqp[collapsed=false][0Kdeqp-runner", 216 lvl="target", 217 ), 218 "\x1b[0Ksection_start:1652658415:deqp[collapsed=false]\r\x1b[0Kdeqp-runner", 219 ), 220 "Mangled section_start at target level with header with spaces": ( 221 create_lava_yaml_msg( 222 msg="[0Ksection_start:1652658415:deqp[collapsed=false][0Kdeqp runner stats", 223 lvl="target", 224 ), 225 "\x1b[0Ksection_start:1652658415:deqp[collapsed=false]\r\x1b[0Kdeqp runner stats", 226 ), 227 "Mangled section_end at target level": ( 228 create_lava_yaml_msg( 229 msg="[0Ksection_end:1652658415:test_setup[0K", 230 lvl="target", 231 ), 232 "\x1b[0Ksection_end:1652658415:test_setup\r\x1b[0K", 233 ), 234} 235 236 237@pytest.mark.parametrize( 238 "message, fixed_message", 239 GITLAB_SECTION_MANGLED_SCENARIOS.values(), 240 ids=GITLAB_SECTION_MANGLED_SCENARIOS.keys(), 241) 242def test_fix_lava_gitlab_section_log(message, fixed_message): 243 fix_lava_gitlab_section_log(message) 244 245 assert message["msg"] == fixed_message 246 247 248WATCHDOG_SCENARIOS = { 249 "1 second before timeout": ({"seconds": -1}, does_not_raise()), 250 "1 second after timeout": ({"seconds": 1}, pytest.raises(MesaCITimeoutError)), 251} 252 253 254@pytest.mark.parametrize( 255 "timedelta_kwargs, exception", 256 WATCHDOG_SCENARIOS.values(), 257 ids=WATCHDOG_SCENARIOS.keys(), 258) 259def test_log_follower_watchdog(frozen_time, timedelta_kwargs, exception): 260 lines = [ 261 { 262 "dt": datetime.now(), 263 "lvl": "debug", 264 "msg": "Received signal: <STARTTC> mesa-ci_iris-kbl-traces", 265 }, 266 ] 267 td = {LogSectionType.TEST_CASE: timedelta(minutes=1)} 268 lf = LogFollower(timeout_durations=td) 269 lf.feed(lines) 270 frozen_time.tick( 271 lf.timeout_durations[LogSectionType.TEST_CASE] + timedelta(**timedelta_kwargs) 272 ) 273 lines = [create_lava_yaml_msg()] 274 with exception: 275 lf.feed(lines) 276 277 278GITLAB_SECTION_ID_SCENARIOS = [ 279 ("a-good_name", "a-good_name"), 280 ("spaces are not welcome", "spaces-are-not-welcome"), 281 ("abc:amd64 1/3", "abc-amd64-1-3"), 282] 283 284 285@pytest.mark.parametrize("case_name, expected_id", GITLAB_SECTION_ID_SCENARIOS) 286def test_gitlab_section_id(case_name, expected_id): 287 gl = GitlabSection( 288 id=case_name, header=case_name, type=LogSectionType.LAVA_POST_PROCESSING 289 ) 290 291 assert gl.id == expected_id 292 293 294A618_NETWORK_ISSUE_LOGS = [ 295 create_lava_yaml_msg( 296 msg="[ 1733.599402] r8152 2-1.3:1.0 eth0: Tx status -71", lvl="target" 297 ), 298 create_lava_yaml_msg( 299 msg="[ 1733.604506] nfs: server 192.168.201.1 not responding, still trying", 300 lvl="target", 301 ), 302] 303TEST_PHASE_LAVA_SIGNAL = create_lava_yaml_msg( 304 msg="Received signal: <STARTTC> mesa-ci_a618_vk", lvl="debug" 305) 306 307 308A618_NETWORK_ISSUE_SCENARIOS = { 309 "Pass - R8152 kmsg during boot": (A618_NETWORK_ISSUE_LOGS, does_not_raise()), 310 "Fail - R8152 kmsg during test phase": ( 311 [TEST_PHASE_LAVA_SIGNAL, *A618_NETWORK_ISSUE_LOGS], 312 pytest.raises(MesaCIKnownIssueException), 313 ), 314 "Pass - Partial (1) R8152 kmsg during test phase": ( 315 [TEST_PHASE_LAVA_SIGNAL, A618_NETWORK_ISSUE_LOGS[0]], 316 does_not_raise(), 317 ), 318 "Pass - Partial (2) R8152 kmsg during test phase": ( 319 [TEST_PHASE_LAVA_SIGNAL, A618_NETWORK_ISSUE_LOGS[1]], 320 does_not_raise(), 321 ), 322 "Pass - Partial subsequent (3) R8152 kmsg during test phase": ( 323 [ 324 TEST_PHASE_LAVA_SIGNAL, 325 A618_NETWORK_ISSUE_LOGS[0], 326 A618_NETWORK_ISSUE_LOGS[0], 327 ], 328 does_not_raise(), 329 ), 330 "Pass - Partial subsequent (4) R8152 kmsg during test phase": ( 331 [ 332 TEST_PHASE_LAVA_SIGNAL, 333 A618_NETWORK_ISSUE_LOGS[1], 334 A618_NETWORK_ISSUE_LOGS[1], 335 ], 336 does_not_raise(), 337 ), 338} 339 340 341@pytest.mark.parametrize( 342 "messages, expectation", 343 A618_NETWORK_ISSUE_SCENARIOS.values(), 344 ids=A618_NETWORK_ISSUE_SCENARIOS.keys(), 345) 346def test_detect_failure(messages, expectation): 347 lf = LogFollower() 348 with expectation: 349 lf.feed(messages) 350