[PATCH] selftests: livepatch: handle PRINTK_CALLER in check_result()

[Madhavan Srinivasan]

On 1/15/25 11:40 PM, Joe Lawrence wrote:
> On Tue, Jan 14, 2025 at 08:01:44PM +0530, Madhavan Srinivasan wrote:
>> Some arch configs (like ppc64) enable CONFIG_PRINTK_CALLER, which
>> adds the caller id as part of the dmesg. Due to this, even though
>> the expected vs observed are same, end testcase results are failed.
>>
>>  -% insmod test_modules/test_klp_livepatch.ko
>>  -livepatch: enabling patch 'test_klp_livepatch'
>>  -livepatch: 'test_klp_livepatch': initializing patching transition
>>  -livepatch: 'test_klp_livepatch': starting patching transition
>>  -livepatch: 'test_klp_livepatch': completing patching transition
>>  -livepatch: 'test_klp_livepatch': patching complete
>>  -% echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
>>  -livepatch: 'test_klp_livepatch': initializing unpatching transition
>>  -livepatch: 'test_klp_livepatch': starting unpatching transition
>>  -livepatch: 'test_klp_livepatch': completing unpatching transition
>>  -livepatch: 'test_klp_livepatch': unpatching complete
>>  -% rmmod test_klp_livepatch
>>  +[   T3659] % insmod test_modules/test_klp_livepatch.ko
>>  +[   T3682] livepatch: enabling patch 'test_klp_livepatch'
>>  +[   T3682] livepatch: 'test_klp_livepatch': initializing patching transition
>>  +[   T3682] livepatch: 'test_klp_livepatch': starting patching transition
>>  +[    T826] livepatch: 'test_klp_livepatch': completing patching transition
>>  +[    T826] livepatch: 'test_klp_livepatch': patching complete
>>  +[   T3659] % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
>>  +[   T3659] livepatch: 'test_klp_livepatch': initializing unpatching transition
>>  +[   T3659] livepatch: 'test_klp_livepatch': starting unpatching transition
>>  +[    T789] livepatch: 'test_klp_livepatch': completing unpatching transition
>>  +[    T789] livepatch: 'test_klp_livepatch': unpatching complete
>>  +[   T3659] % rmmod test_klp_livepatch
>>
>>   ERROR: livepatch kselftest(s) failed
>>  not ok 1 selftests: livepatch: test-livepatch.sh # exit=1
>>
>> Currently the check_result() handles the "[time]" removal from
>> the dmesg. Enhance the check to handle removal of "[Tid]" also.
>>
>> Signed-off-by: Madhavan Srinivasan <maddy at linux.ibm.com>
>> ---
>>  tools/testing/selftests/livepatch/functions.sh | 3 ++-
>>  1 file changed, 2 insertions(+), 1 deletion(-)
>>
>> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
>> index e5d06fb40233..a1730c1864a4 100644
>> --- a/tools/testing/selftests/livepatch/functions.sh
>> +++ b/tools/testing/selftests/livepatch/functions.sh
>> @@ -306,7 +306,8 @@ function check_result {
>>  	result=$(dmesg | awk -v last_dmesg="$LAST_DMESG" 'p; $0 == last_dmesg { p=1 }' | \
>>  		 grep -e 'livepatch:' -e 'test_klp' | \
>>  		 grep -v '\(tainting\|taints\) kernel' | \
>> -		 sed 's/^\[[ 0-9.]*\] //')
>> +		 sed 's/^\[[ 0-9.]*\] //' | \
>> +		 sed 's/^\[[ ]*T[0-9]*\] //')
> 
> Thanks for adding this to the filter.
> 
> If I read the PRINTK_CALLER docs correctly, there is a potential CPU
> identifier as well.  Are there any instances where the livepatching code
> will use the "[C$processor_id]" (out of task context) prefix?  Or would
> it hurt to future proof with [CT][0-9]?

Thanks for the review.

yeah, saw that case, but in my current build and boot test, seen only the Thread-id added,
so sent out to fix that. I did not get to add a test to create "processor id" scenario,
so cant test it at this point.

Maddy

> 
> Acked-by: Joe Lawrence <joe.lawrence at redhat.com>
> 
> --
> Joe
> 
>>  
>>  	if [[ "$expect" == "$result" ]] ; then
>>  		echo "ok"
>> -- 
>> 2.47.0
>>
>