selftests/livepatch: filter debug messages in check_result()

CONFIG_DEBUG_KOBJECT makes kobject_add_internal(), kobject_uevent_env(),
fill_kobj_path() and friends emit pr_debug() messages, and
CONFIG_DEBUG_KOBJECT_RELEASE makes kobject_release() emit a pr_info()
for every delayed kobject free.  All of these carry the "kobject:" prefix
via pr_fmt(), e.g.:

 # --- expected
 # +++ result
 # @@ -1,7 +1,13 @@
 #  % insmod test_modules/test_klp_livepatch.ko
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): kobject_add_internal: parent: 'module', set: 'module'
 # +kobject: 'holders' (000000002856f0ae): kobject_add_internal: parent: 'test_klp_livepatch', set: '<NULL>'
 # +kobject: 'test_klp_livepatch' (00000000dcae1113): kobject_add_internal: parent: 'livepatch', set: '<NULL>'
 # +kobject: 'vmlinux' (000000007b8837e6): kobject_add_internal: parent: 'test_klp_livepatch', set: '<NULL>'
 #  livepatch: enabling patch 'test_klp_livepatch'
 #  livepatch: 'test_klp_livepatch': initializing patching transition
 #  livepatch: 'test_klp_livepatch': starting patching transition
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): kobject_uevent_env
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): fill_kobj_path: path = '/module/test_klp_livepatch'
 #  livepatch: 'test_klp_livepatch': completing patching transition
 #  livepatch: 'test_klp_livepatch': patching complete
 #  % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
 # @@ -9,4 +15,17 @@ livepatch: 'test_klp_livepatch': initial
 #  livepatch: 'test_klp_livepatch': starting unpatching transition
 #  livepatch: 'test_klp_livepatch': completing unpatching transition
 #  livepatch: 'test_klp_livepatch': unpatching complete
 # +kobject: 'test_klp_livepatch' (00000000dcae1113): kobject_release, parent 00000000f8785d63 (delayed 2000)
 # +kobject: 'test_klp_livepatch' (00000000dcae1113): kobject_cleanup, parent 00000000f8785d63
 # +kobject: 'test_klp_livepatch' (00000000dcae1113): auto cleanup kobject_del
 # +kobject: 'test_klp_livepatch' (00000000dcae1113): calling ktype release
 # +kobject: 'test_klp_livepatch': free name
 #  % rmmod test_klp_livepatch
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): kobject_release, parent 0000000052e5c022 (delayed 3000)
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): kobject_cleanup, parent 0000000052e5c022
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): auto cleanup kobject_del
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): auto cleanup 'remove' event
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): kobject_uevent_env
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): fill_kobj_path: path = '/module/test_klp_livepatch'
 # +kobject: 'test_klp_livepatch' (000000009dbf565e): calling ktype release
 # +kobject: 'test_klp_livepatch': free name
 #
 # ERROR: livepatch kselftest(s) failed
 not ok 1 selftests: livepatch: test-livepatch.sh # exit=1

The livepatch test modules' kobjects are named "test_klp_*", so these
lines match the check_result() grep for "test_klp" and leak into the
result.  The extra lines no longer match the expected output, so the
selftests fail when either debug config is enabled.

Filtering out every "kobject:" line also hides real WARN()s, e.g. the
one kobject_get() emits for an object whose refcount was not
initialized.  Filtering with "dmesg --level=..." is not enough either,
since the tests enable livepatch pr_debug() through dynamic_debug/control
and expect its messages.  Read the log with "dmesg --raw" and drop only
the debug-level messages without the "livepatch:" prefix, plus the
specific delayed-release info message.

Suggested-by: Petr Mladek <pmladek@suse.com>
Signed-off-by: Yafang Shao <laoar.shao@gmail.com>
Acked-by: Song Liu <song@kernel.org>
Reviewed-by: Petr Mladek <pmladek@suse.com>
Tested-by: Petr Mladek <pmladek@suse.com>
Link: https://patch.msgid.link/20260830054857.64758-3-laoar.shao@gmail.com
Signed-off-by: Petr Mladek <pmladek@suse.com>
1 file changed