commit aa73c12a048dd0df050d9ba20ced2d65e4620ab1 Author: Anders Roxell Date: Mon Jan 20 12:57:07 2025 +0100 plugins: lib: base_log_parser: remove seconds KFENCE has strings like "38.982847s (0.011771s ago):" and that isn't removed by the log parser. Added an extra step to remove the '.s'. From: 'freed by task 285 on cpu 0 at 38.982847s (0.011771s ago):' To: 'freed by task on cpu at ( ago):' Signed-off-by: Anders Roxell diff --git a/squad/plugins/lib/base_log_parser.py b/squad/plugins/lib/base_log_parser.py index 57288b3d8e55..e17f070b1f9b 100644 --- a/squad/plugins/lib/base_log_parser.py +++ b/squad/plugins/lib/base_log_parser.py @@ -28,10 +28,13 @@ class BaseLogParser: return re.compile(combined, re.S | re.M) def remove_numbers_and_time(self, snippet): + # allocated by task 285 on cpu 0 at 38.982743s (0.007174s ago): + # Removes [digit(s)].[digit(s)]s + cleaned_seconds = re.sub(r"\b\d+\.\d+s\b", "", snippet) # [ 92.236941] CPU: 1 PID: 191 Comm: kunit_try_catch Tainted: G W 5.15.75-rc1 #1 # <4>[ 87.925462] CPU: 0 PID: 135 Comm: (crub_all) Not tainted 6.7.0-next-20240111 #14 # Remove '(Not t|T)ainted', to the end of the line. - without_tainted = re.sub(r"(Not t|T)ainted.*", "", snippet) + without_tainted = re.sub(r"(Not t|T)ainted.*", "", cleaned_seconds) # x23: ffff9b7275bc6f90 x22: ffff9b7275bcfb50 x21: fff00000cc80ef88 # x20: 1ffff00010668fb8 x19: ffff8000800879f0 x18: 00000000805c0b5c diff --git a/test/plugins/log_parser_base/kfence-seconds-expected.log b/test/plugins/log_parser_base/kfence-seconds-expected.log new file mode 100644 index 000000000000..5c8812852215 --- /dev/null +++ b/test/plugins/log_parser_base/kfence-seconds-expected.log @@ -0,0 +1,31 @@ + ================================================================== +[ .] BUG: KFENCE: use-after-free read in test_use_after_free_read+/ +[ .] +[ .] Use-after-free read at (in kfence-#): +[ .] test_use_after_free_read+/ +[ .] kunit_try_run_case+/ +[ .] kunit_generic_run_threadfn_adapter+/ +[ .] kthread+/ +[ .] ret_from_fork+/ +[ .] +[ .] kfence-#: -, size=, cache=test +[ .] +[ .] allocated by task on cpu at ( ago): +[ .] test_alloc+/ +[ .] test_use_after_free_read+/ +[ .] kunit_try_run_case+/ +[ .] kunit_generic_run_threadfn_adapter+/ +[ .] kthread+/ +[ .] ret_from_fork+/ +[ .] +[ .] freed by task on cpu at ( ago): +[ .] test_use_after_free_read+/ +[ .] kunit_try_run_case+/ +[ .] kunit_generic_run_threadfn_adapter+/ +[ .] kthread+/ +[ .] ret_from_fork+/ +[ .] +[ .] CPU: UID: PID: Comm: kunit_try_catch +[ .] +[ .] Hardware name: linux,dummy-virt (DT) +[ .] ================================================================== diff --git a/test/plugins/log_parser_base/kfence-seconds.log b/test/plugins/log_parser_base/kfence-seconds.log new file mode 100644 index 000000000000..84f544966528 --- /dev/null +++ b/test/plugins/log_parser_base/kfence-seconds.log @@ -0,0 +1,32 @@ +[ 38.983084] ================================================================== +[ 38.983891] BUG: KFENCE: use-after-free read in test_use_after_free_read+0x114/0x248 +[ 38.983891] +[ 38.984660] Use-after-free read at 0x000000000c4e69db (in kfence-#139): +[ 38.985493] test_use_after_free_read+0x114/0x248 +[ 38.986291] kunit_try_run_case+0x14c/0x3d0 +[ 38.986852] kunit_generic_run_threadfn_adapter+0x88/0x100 +[ 38.987564] kthread+0x24c/0x2d0 +[ 38.988116] ret_from_fork+0x10/0x20 +[ 38.988694] +[ 38.989048] kfence-#139: 0x000000000c4e69db-0x00000000321ff8ff, size=32, cache=test +[ 38.989048] +[ 38.989930] allocated by task 285 on cpu 0 at 38.982743s (0.007174s ago): +[ 38.990710] test_alloc+0x22c/0x620 +[ 38.991284] test_use_after_free_read+0xd0/0x248 +[ 38.991953] kunit_try_run_case+0x14c/0x3d0 +[ 38.992471] kunit_generic_run_threadfn_adapter+0x88/0x100 +[ 38.993193] kthread+0x24c/0x2d0 +[ 38.993734] ret_from_fork+0x10/0x20 +[ 38.994274] +[ 38.994629] freed by task 285 on cpu 0 at 38.982847s (0.011771s ago): +[ 38.995567] test_use_after_free_read+0xf0/0x248 +[ 38.996133] kunit_try_run_case+0x14c/0x3d0 +[ 38.996757] kunit_generic_run_threadfn_adapter+0x88/0x100 +[ 38.997475] kthread+0x24c/0x2d0 +[ 38.997965] ret_from_fork+0x10/0x20 +[ 38.998467] +[ 38.998850] CPU: 0 UID: 0 PID: 285 Comm: kunit_try_catch Tainted: G B N 6.13.0-rc7 #1 +[ 38.999779] Tainted: [B]=BAD_PAGE, [N]=TEST +[ 39.000370] Hardware name: linux,dummy-virt (DT) +[ 39.000984] ================================================================== + diff --git a/test/plugins/test_log_parser_base.py b/test/plugins/test_log_parser_base.py index d38b0f9bbaf9..7fc87e945f47 100644 --- a/test/plugins/test_log_parser_base.py +++ b/test/plugins/test_log_parser_base.py @@ -1,3 +1,4 @@ +import os import re from collections import defaultdict @@ -5,6 +6,13 @@ from django.test import TestCase from squad.core.models import Group from squad.plugins.lib.base_log_parser import BaseLogParser +from squad.plugins.linux_log_parser import Plugin + + +def read_sample_file(name): + if not name.startswith('/'): + name = os.path.join(os.path.dirname(__file__), 'log_parser_base', name) + return open(name).read() def compile_regex(regex): @@ -22,6 +30,13 @@ class TestBaseLogParser(TestCase): self.build = self.project.builds.create(version="1") self.env = self.project.environments.create(slug="myenv") self.testrun = self.build.test_runs.create(environment=self.env, job_id="123") + self.plugin = Plugin() + + def new_testrun(self, logfile, job_id='999'): + log = read_sample_file(logfile) + testrun = self.build.test_runs.create(environment=self.env, job_id=job_id) + testrun.save_log_file(log) + return testrun def test_remove_numbers_and_time(self): """ @@ -335,3 +350,19 @@ class TestBaseLogParser(TestCase): } self.assertDictEqual(snippets, expected_snippets) + + def test_kfence_seconds(self): + """ + Test removing numbers and time from a string containing timestamp, + non-hex number and hex number + """ + testrun = self.new_testrun('kfence-seconds.log') + self.plugin.postprocess_testrun(testrun) + + tests = testrun.tests + expected_output = read_sample_file('kfence-seconds-expected.log') + + test_kfence_seconds = tests.get(suite__slug='log-parser-test', metadata__name='kfence-bug-kfence-use-after-free-read-in-test_use_after_free_read-12cdfd85b20ffda2c398b1d6f97a7d5230cd4f2caf19ef0fb38bbc98469d3bde') + numbers_and_time_removed = self.log_parser.remove_numbers_and_time(test_kfence_seconds.log) + + self.assertEqual(numbers_and_time_removed, expected_output)