| Message ID | 20200710051043.899291-1-kamalesh@linux.vnet.ibm.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | selftests/livepatch: adopt to newer sysctl error format | expand |
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: > > # 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: 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 Best Regards, Petr
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@pks.im> 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@pks.im> 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: > 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. > 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). Regards, -- Joe
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@pks.im> > 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@pks.im> > > 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). >
diff --git a/tools/testing/selftests/livepatch/functions.sh b/tools/testing/selftests/livepatch/functions.sh index 36648ca367c2..e3c0490d5a45 100644 --- a/tools/testing/selftests/livepatch/functions.sh +++ b/tools/testing/selftests/livepatch/functions.sh @@ -75,7 +75,8 @@ function set_dynamic_debug() { } function set_ftrace_enabled() { - result=$(sysctl kernel.ftrace_enabled="$1" 2>&1 | paste --serial --delimiters=' ') + result=$(sysctl kernel.ftrace_enabled="$1" 2>&1 | paste --serial --delimiters=' ' | \ + cut -d" " -f1-8) echo "livepatch: $result" > /dev/kmsg } diff --git a/tools/testing/selftests/livepatch/test-ftrace.sh b/tools/testing/selftests/livepatch/test-ftrace.sh index 9160c9ec3b6f..552e165512f4 100755 --- a/tools/testing/selftests/livepatch/test-ftrace.sh +++ b/tools/testing/selftests/livepatch/test-ftrace.sh @@ -51,7 +51,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
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: # 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. With the patch, the test-ftrace.sh passes on v3.3.15, v3.3.16 versions of sysctl: ... # selftests: livepatch: test-ftrace.sh # TEST: livepatch interaction with ftrace_enabled sysctl ... ok ok 5 selftests: livepatch: test-ftrace.sh Signed-off-by: Kamalesh Babulal <kamalesh@linux.vnet.ibm.com> --- Based on livepatching/for-5.9/selftests-cleanup, to be merged through livepatching.git tools/testing/selftests/livepatch/functions.sh | 3 ++- tools/testing/selftests/livepatch/test-ftrace.sh | 2 +- 2 files changed, 3 insertions(+), 2 deletions(-) base-commit: 3fd9bd8b7e41a1908bf8bc0cd06606f2b787cd39