Re: [PATCH] selftests/livepatch: adopt to newer sysctl error format

[Kamalesh Babulal]

On 11/07/20 12:01 am, Joe Lawrence wrote:
> On Fri, Jul 10, 2020 at 05:27:35PM +0200, Petr Mladek wrote:
>> On Fri 2020-07-10 10:40:43, Kamalesh Babulal wrote:
>>> With procfs v3.3.16, the sysctl command doesn't prints the set key and
>>> value on error.  This change breaks livepatch selftest test-ftrace.sh,
>>> that tests the interaction of sysctl ftrace_enabled:
>>>
> 
> Good catch, it looks like it was this procps commit that modified that
> behavior:
> 
>   commit da82fe49b1476d227874905068adb69577e11d96
>   Author: Patrick Steinhardt <ps@xxxxxx>
>   Date:   Tue May 29 13:29:03 2018 +0200
>   
>       sysctl: do not report set key in case `close_stream` fails
>       
>       As we're using buffered I/O when writing kernel parameters, write errors
>       may get delayed until we close the `FILE` stream. As we are currently
>       outputting the key that is to be set disregarding the return value of
>       `close_stream`, we may end up in a situation where we report error and
>       success:
>       
>           $ sysctl kernel.printk_ratelimit=100000000000000
>           sysctl: setting key "kernel.printk_ratelimit": error code 22
>           kernel.printk_ratelimit = 100000000000000
>       
>       Fix the issue by only outputting the updated value in case
>       `close_stream` does not report an error.
>       
>       Signed-off-by: Patrick Steinhardt <ps@xxxxxx>
> 
> And I'd agree that echoing the failed new value was confusing to see
> from a user's perspective.
> 
>>>  # selftests: livepatch: test-ftrace.sh
>>>  # TEST: livepatch interaction with ftrace_enabled sysctl ... not ok
>>>  #
>>>  # --- expected
>>>  # +++ result
>>>  # @@ -16,7 +16,7 @@ livepatch: 'test_klp_livepatch': initial
>>>  #  livepatch: 'test_klp_livepatch': starting patching transition
>>>  #  livepatch: 'test_klp_livepatch': completing patching transition
>>>  #  livepatch: 'test_klp_livepatch': patching complete
>>>  # -livepatch: sysctl: setting key "kernel.ftrace_enabled": Device or
>>>     resource busy kernel.ftrace_enabled = 0
>>>  # +livepatch: sysctl: setting key "kernel.ftrace_enabled": Device or
>>>     resource busy
>>>  #  % echo 0 > /sys/kernel/livepatch/test_klp_livepatch/enabled
>>>  #  livepatch: 'test_klp_livepatch': initializing unpatching transition
>>>  #  livepatch: 'test_klp_livepatch': starting unpatching transition
>>>  #
>>>  # ERROR: livepatch kselftest(s) failed
>>>
>>> on setting sysctl kernel.ftrace_enabled={0,1} value successfully, the
>>> set key and value is displayed.
>>>
>>> This patch fixes it by limiting the output from both the cases to eight
>>> words, that includes the error message or set key and value on failure
>>> and success. The upper bound of eight words is enough to display the
>>> only tracked error message. Also, adjust the check_result string in
>>> test-ftrace.sh to match the expected output.
>>
>> This looks really tricky.
>>
>> I wonder if we could use "sysctl -q" to refuse printing the value
>> even with older versions. The following patch works here with
>> sysctl 3.3.15:

Agree, "sysctl -q" is more robust, I tested it with sysctl v3.3.16 and the test
passes.  Can you please send the patch?

>>
> 
> FWIW, --quiet was added to procps way back in 2004, so it should be safe
> to use... and there's already a bunch of net selftests using it.

a couple of tests is using the "-q" options to set the sysctl values.

> 
>> diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh
>> index 2aab9791791d..47aa4c762bb4 100644
>> --- a/tools/testing/selftests/livepatch/functions.sh
>> +++ b/tools/testing/selftests/livepatch/functions.sh
>> @@ -64,7 +64,8 @@ function set_dynamic_debug() {
>>  }
>>  
>>  function set_ftrace_enabled() {
>> -	result=$(sysctl kernel.ftrace_enabled="$1" 2>&1 | paste --serial --delimiters=' ')
>> +	result=$(sysctl -q kernel.ftrace_enabled="$1" 2>&1 && \
>> +		 sysctl kernel.ftrace_enabled 2>&1)
>>  	echo "livepatch: $result" > /dev/kmsg
>>  }
>>  
>> diff --git a/tools/testing/selftests/livepatch/test-ftrace.sh b/tools/testing/selftests/livepatch/test-ftrace.sh
>> index e2a76887f40a..aa967c5d0558 100755
>> --- a/tools/testing/selftests/livepatch/test-ftrace.sh
>> +++ b/tools/testing/selftests/livepatch/test-ftrace.sh
>> @@ -53,7 +53,7 @@ livepatch: '$MOD_LIVEPATCH': initializing patching transition
>>  livepatch: '$MOD_LIVEPATCH': starting patching transition
>>  livepatch: '$MOD_LIVEPATCH': completing patching transition
>>  livepatch: '$MOD_LIVEPATCH': patching complete
>> -livepatch: sysctl: setting key \"kernel.ftrace_enabled\": Device or resource busy kernel.ftrace_enabled = 0
>> +livepatch: sysctl: setting key \"kernel.ftrace_enabled\": Device or resource busy
>>  % echo 0 > /sys/kernel/livepatch/$MOD_LIVEPATCH/enabled
>>  livepatch: '$MOD_LIVEPATCH': initializing unpatching transition
>>  livepatch: '$MOD_LIVEPATCH': starting unpatching transition
>>
>>
> 
> I think this method is less fragile than word count / cutting and we get
> to drop that strange 'paste' invocation (I had to look that up in the
> mapages to remember why we used it).
> 

-- 
Kamalesh