Skip to content
This repository has been archived by the owner on Jul 25, 2024. It is now read-only.

Commit

Permalink
Merge pull request #1142 from katieworton/update-naming-log-parser
Browse files Browse the repository at this point in the history 
plugins/linux_log_parser: Add support for test name regex
  • Loading branch information
@chaws
chaws authored Jul 25, 2024
2 parents 5efd81f + 98e3120 commit 84e9230
Show file tree
Hide file tree
Showing 2 changed files with 141 additions and 51 deletions.
111 changes: 79 additions & 32 deletions squad/plugins/linux_log_parser.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,26 +4,28 @@
from collections import defaultdict
from squad.plugins import Plugin as BasePlugin
from squad.core.models import SuiteMetadata
from django.template.defaultfilters import slugify


logger = logging.getLogger()

REGEX_NAME = 0
REGEX_BODY = 1
REGEX_EXTRACT_NAME = 2

MULTILINERS = [
('check-kernel-exception', r'-+\[? cut here \]?-+.*?-+\[? end trace \w* \]?-+'),
('check-kernel-kasan', r'=+\n\[[\s\.\d]+\]\s+BUG: KASAN:.*?=+'),
('check-kernel-kfence', r'=+\n\[[\s\.\d]+\]\s+BUG: KFENCE:.*?=+'),
('check-kernel-exception', r'-+\[? cut here \]?-+.*?-+\[? end trace \w* \]?-+', r"\d][^\+\n]*"),
('check-kernel-kasan', r'=+\n\[[\s\.\d]+\]\s+BUG: KASAN:.*?=+', r"BUG: KASAN:[^\+\n]*"),
('check-kernel-kfence', r'=+\n\[[\s\.\d]+\]\s+BUG: KFENCE:.*?=+', r"BUG: KFENCE:[^\+\n]*"),
]

ONELINERS = [
('check-kernel-oops', r'^[^\n]+Oops(?: -|:).*?$'),
('check-kernel-fault', r'^[^\n]+Unhandled fault.*?$'),
('check-kernel-warning', r'^[^\n]+WARNING:.*?$'),
('check-kernel-bug', r'^[^\n]+(?: kernel BUG at|BUG:).*?$'),
('check-kernel-invalid-opcode', r'^[^\n]+invalid opcode:.*?$'),
('check-kernel-panic', r'Kernel panic - not syncing.*?$'),
('check-kernel-oops', r'^[^\n]+Oops(?: -|:).*?$', r"Oops[^\+\n]*"),
('check-kernel-fault', r'^[^\n]+Unhandled fault.*?$', r"Unhandled [^\+\n]*"),
('check-kernel-warning', r'^[^\n]+WARNING:.*?$', r"WARNING: [^\+\n]*"),
('check-kernel-bug', r'^[^\n]+(?: kernel BUG at|BUG:).*?$', r"BUG[^\+\n]*"),
('check-kernel-invalid-opcode', r'^[^\n]+invalid opcode:.*?$', r"invalid opcode: [^\+\n]*"),
('check-kernel-panic', r'Kernel panic - not syncing.*?$', r"Kernel [^\+\n]*"),
]

# Tip: broader regexes should come first
Expand Down Expand Up @@ -70,33 +72,55 @@ def __join_matches(self, matches, regexes):
snippets[regex_id].append(match[regex_id])
return snippets

def __create_tests(self, testrun, suite, test_name, lines):
def __create_tests(self, testrun, suite, test_name, lines, test_regex=None):
"""
There will be at least one test per regex. If there were any match for a given
regex, then a new test will be generated using test_name + shasum. This helps
comparing kernel logs accross different builds
"""
metadata, _ = SuiteMetadata.objects.get_or_create(suite=suite.slug, name=test_name, kind='test')
testrun.tests.create(
suite=suite,
result=(len(lines) == 0),
log='\n'.join(lines),
metadata=metadata,
build=testrun.build,
environment=testrun.environment,
)

# Some lines of the matched regex might be the same, and we don't want to create
# multiple tests like test1-sha1, test1-sha1, etc, so we'll create a set of sha1sums
# then create only new tests for unique sha's
# Run the REGEX_EXTRACT_NAME regex over the log lines to sort them by
# extracted name. If no name is extracted or the log parser did not
# have any output for a particular regex, just use the default name
# (for example "check-kernel-oops").
tests_to_create = defaultdict(set)
shas = defaultdict(set)
for line in lines:
sha = self.__create_shasum(line)
shas[sha].add(line)

for sha, lines in shas.items():
name = f'{test_name}-{sha}'
# If there are no lines, use the default name and create a passing
# test. For example "check-kernel-oops"
if not lines:
tests_to_create[test_name] = []

# If there are lines, then create the tests for these.
for line in lines:
extracted_name = self.__create_name(line, test_regex)
if extracted_name:
extended_test_name = f"{test_name}-{extracted_name}"
else:
extended_test_name = test_name
tests_to_create[extended_test_name].add(line)

for name, lines in tests_to_create.items():
metadata, _ = SuiteMetadata.objects.get_or_create(suite=suite.slug, name=name, kind='test')
testrun.tests.create(
suite=suite,
result=(len(lines) == 0),
log='\n'.join(lines),
metadata=metadata,
build=testrun.build,
environment=testrun.environment,
)

# Some lines of the matched regex might be the same, and we don't want to create
# multiple tests like test1-sha1, test1-sha1, etc, so we'll create a set of sha1sums
# then create only new tests for unique sha's

for line in lines:
sha = self.__create_shasum(line)
name_with_sha = f"{name}-{sha}"
shas[name_with_sha].add(line)

for name_with_sha, lines in shas.items():
metadata, _ = SuiteMetadata.objects.get_or_create(suite=suite.slug, name=name_with_sha, kind='test')
testrun.tests.create(
suite=suite,
result=False,
Expand All @@ -106,11 +130,30 @@ def __create_tests(self, testrun, suite, test_name, lines):
environment=testrun.environment,
)

def __remove_numbers_and_time(self, snippet):
without_numbers = re.sub(r"(0x[a-f0-9]+|[<\[][0-9a-f]+?[>\]]|\d+)", "", snippet)
without_time = re.sub(r"^\[[^\]]+\]", "", without_numbers)

return without_time

def __create_name(self, snippet, regex=None):
matches = None
if regex:
matches = regex.findall(snippet)
if not matches:
return None
snippet = matches[0]
without_numbers_and_time = self.__remove_numbers_and_time(snippet)

# Limit the name length to 191 characters, since the max name length
# for SuiteMetadata in SQUAD is 256 characters. The SHA and "-" take 65
# characters: 256-65=191
return slugify(without_numbers_and_time)[:191]

def __create_shasum(self, snippet):
sha = hashlib.sha256()
without_numbers = re.sub(r'(0x[a-f0-9]+|[<\[][0-9a-f]+?[>\]]|\d+)', '', snippet)
without_time = re.sub(r'^\[[^\]]+\]', '', without_numbers)
sha.update(without_time.encode())
without_numbers_and_time = self.__remove_numbers_and_time(snippet)
sha.update(without_numbers_and_time.encode())
return sha.hexdigest()

def postprocess_testrun(self, testrun):
Expand All @@ -133,4 +176,8 @@ def postprocess_testrun(self, testrun):

for regex_id in range(len(REGEXES)):
test_name = REGEXES[regex_id][REGEX_NAME]
self.__create_tests(testrun, suite, test_name, snippets[regex_id])
regex_pattern = REGEXES[regex_id][REGEX_EXTRACT_NAME]
test_name_regex = None
if regex_pattern:
test_name_regex = re.compile(regex_pattern, re.S | re.M)
self.__create_tests(testrun, suite, test_name, snippets[regex_id], test_name_regex)
81 changes: 62 additions & 19 deletions test/plugins/test_linux_log_parser.py
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ def test_detects_oops(self):
testrun = self.new_testrun('oops.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops-oops-bug-preempt-smp')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Linux version 4.4.89-01529-gb29bace', test.log)
Expand All @@ -40,19 +40,19 @@ def test_detects_kernel_panic(self):
testrun = self.new_testrun('kernelpanic.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic-kernel-panic-not-syncing-attempted-to-kill-the-idle-task')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
self.assertIn('Kernel panic - not syncing', test.log)
self.assertIn('Attempted to kill init! exitcode=0x00000009', test.log)
self.assertNotIn('Attempted to kill init! exitcode=0x00000009', test.log)
self.assertNotIn('Internal error: Oops', test.log)

def test_detects_kernel_exception(self):
testrun = self.new_testrun('kernelexceptiontrace.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception-warning-cpu-pid-at-kernelsmpc-smp_call_function_many_cond')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -64,7 +64,7 @@ def test_detects_kernel_exception_without_square_braces(self):
testrun = self.new_testrun('kernelexceptiontrace_without_squarebraces.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception-warning-cpu-pid-at-kernelsmpc-smp_call_function_many_cond')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -76,7 +76,7 @@ def test_detects_kernel_kasan(self):
testrun = self.new_testrun('kasan.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-kasan')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-kasan-bug-kasan-slab-out-of-bounds-in-kmalloc_oob_right')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -89,7 +89,7 @@ def test_detects_kernel_kfence(self):
testrun = self.new_testrun('kfence.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-kfence')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-kfence-bug-kfence-memory-corruption-in-kfree')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -102,7 +102,7 @@ def test_detects_kernel_bug(self):
testrun = self.new_testrun('oops.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-bug')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-bug-bug-spinlock-lockup-suspected-on-cpu-gdbus')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -112,7 +112,7 @@ def test_detects_kernel_bug(self):
testrun = self.new_testrun('kernel_bug_and_invalid_opcode.log', job_id='1000')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-bug')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception-kernel-bug-at-usrsrckernelarchxkvmmmummuc')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -124,7 +124,7 @@ def test_detects_kernel_invalid_opcode(self):
testrun = self.new_testrun('kernel_bug_and_invalid_opcode.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-invalid-opcode')
test = testrun.tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-invalid-opcode-invalid-opcode-smp-pti')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Booting Linux', test.log)
Expand All @@ -137,11 +137,11 @@ def test_detects_multiple(self):
self.plugin.postprocess_testrun(testrun)

tests = testrun.tests
test_panic = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic')
test_exception = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception')
test_warning = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-warning')
test_oops = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops')
test_fault = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-fault')
test_panic = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic-kernel-panic-not-syncing-stack-protector-kernel-stack-is-corrupted-in-ffffffffcc')
test_exception = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception-warning-cpu-pid-at-driversgpudrmradeonradeon_objectc-radeon_ttm_bo_destroy')
test_warning = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-warning-warning-cpu-pid-at-driversregulatorcorec-_regulator_putpart')
test_oops = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops-oops-preempt-smp')
test_fault = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-fault-unhandled-fault-external-abort-on-non-linefetch-at')

self.assertFalse(test_panic.result)
self.assertNotIn('Boot CPU', test_panic.log)
Expand Down Expand Up @@ -208,7 +208,7 @@ def test_rcu_warning(self):
tests = testrun.tests
test_panic = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic')
test_exception = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception')
test_warning = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-warning')
test_warning = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-warning-warning-suspicious-rcu-usage')
test_oops = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops')
test_fault = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-fault')

Expand Down Expand Up @@ -240,7 +240,7 @@ def test_boot_log(self):
testrun = self.new_testrun('oops.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops')
test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops-oops-bug-preempt-smp')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Linux version 4.4.89-01529-gb29bace', test.log)
Expand All @@ -251,16 +251,59 @@ def test_sha_name(self):
testrun = self.new_testrun('oops.log')
self.plugin.postprocess_testrun(testrun)

test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops')
test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops-oops-bug-preempt-smp')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertNotIn('Linux version 4.4.89-01529-gb29bace', test.log)
self.assertIn('Internal error: Oops - BUG: 0 [#0] PREEMPT SMP', test.log)
self.assertNotIn('Kernel panic', test.log)

# Now check if a test with sha digest in the name
test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops-a1acf2f0467782c9c2f6aeadb1d1d3cec136642b13d7231824a66ef63ee62220')
test = testrun.tests.get(suite__slug='log-parser-boot', metadata__name='check-kernel-oops-oops-bug-preempt-smp-a1acf2f0467782c9c2f6aeadb1d1d3cec136642b13d7231824a66ef63ee62220')
self.assertFalse(test.result)
self.assertIsNotNone(test.log)
self.assertIn('Internal error: Oops - BUG: 0 [#0] PREEMPT SMP', test.log)
self.assertNotIn('Internal error: Oops - BUG: 99 [#1] PREEMPT SMP', test.log)

def test_sha_name_multiple(self):
testrun = self.new_testrun('multiple_issues_dmesg.log')
self.plugin.postprocess_testrun(testrun)

tests = testrun.tests
test_panic = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-panic-kernel-panic-not-syncing-stack-protector-kernel-stack-is-corrupted-in-ffffffffcc-ab2f1708a36efc4f90943d58fb240d435fcb3d05f7fac9b00163483fe77209eb')
test_exception = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-exception-warning-cpu-pid-at-driversgpudrmradeonradeon_objectc-radeon_ttm_bo_destroy-77251099bfa081e5c942070a569fe31163336e61a80bda7304cd59f0f4b82080')
test_warning = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-warning-warning-cpu-pid-at-driversregulatorcorec-_regulator_putpart-d44949024d5373185a7381cb9dd291b13c117d6b93feb576a431e5376025004f')
test_oops = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-oops-oops-preempt-smp-4e1ddddb2c142178a8977e7d973c2a13db2bb978aa471c0049ee39fe3fe4d74c')
test_fault = tests.get(suite__slug='log-parser-test', metadata__name='check-kernel-fault-unhandled-fault-external-abort-on-non-linefetch-at-6f9e3ab8f97e35c1e9167fed1e01c6149986819c54451064322b7d4208528e07')

self.assertFalse(test_panic.result)
self.assertNotIn('Boot CPU', test_panic.log)
self.assertIn('Kernel panic - not syncing', test_panic.log)

self.assertFalse(test_exception.result)
self.assertNotIn('Boot CPU', test_exception.log)
self.assertIn('------------[ cut here ]------------', test_exception.log)

self.assertFalse(test_warning.result)
self.assertNotIn('Boot CPU', test_warning.log)
self.assertNotIn('Kernel panic - not syncing', test_warning.log)
self.assertNotIn('------------[ cut here ]------------', test_warning.log)
self.assertNotIn('Unhandled fault:', test_warning.log)
self.assertNotIn('Oops', test_warning.log)
self.assertIn('WARNING: CPU', test_warning.log)

self.assertFalse(test_oops.result)
self.assertNotIn('Boot CPU', test_oops.log)
self.assertNotIn('Kernel panic - not syncing', test_oops.log)
self.assertNotIn('------------[ cut here ]------------', test_oops.log)
self.assertNotIn('WARNING: CPU', test_oops.log)
self.assertNotIn('Unhandled fault:', test_oops.log)
self.assertIn('Oops', test_oops.log)

self.assertFalse(test_fault.result)
self.assertNotIn('Boot CPU', test_fault.log)
self.assertNotIn('Kernel panic - not syncing', test_fault.log)
self.assertNotIn('------------[ cut here ]------------', test_fault.log)
self.assertNotIn('WARNING: CPU', test_fault.log)
self.assertNotIn('Oops', test_fault.log)
self.assertIn('Unhandled fault:', test_fault.log)

0 comments on commit 84e9230

Please sign in to comment.