Re: [PATCH v3 2/2] selftests/livepatch: filter debug messages in check_result()

[Joe Lawrence <joe.lawrence@redhat.com>]

On 8/26/26 3:54 AM, Petr Mladek wrote:
> On Fri 2026-08-21 11:16:48, Yafang Shao wrote:
>> 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>
> 
> I am not much familiar with awk. But the changes look good
> and selftests passed so:
> 

I translate the awk as:
- read through the steam, print nothing yet,
  - when the last_dmesg line is encountered, set the p variable
- continue through the stream and if p is set,
  - print a line if its initial field is "<7>" or "livepatch:"

which LGTM.


One dmesg nit: years ago someone complained about BusyBox vs. selftests
compatibility:

https://lore.kernel.org/live-patching/20200710183745.19730-1-joe.lawrence@redhat.com/

and my google-foo tells me that its dmesg only supports -r and not
--raw.  I don't know if it's worth using the short option without
testing it, but -r would also supported by util-linux's dmesg, fwiw.

-- 
Joe