| Message ID | 4df1b25365287e0fa3e7b4c8d1400ad5d576d992.1693945163.git.josef@toxicpanda.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | btrfs-progs: add eb leak detection and fixes | expand |
On Tue, Sep 05, 2023 at 04:21:53PM -0400, Josef Bacik wrote: > I introduced a regression where we were leaking extent buffers, and this > resulted in the CI failing because we were spewing these errors. > > Instead of waiting for fstests to catch my mistakes, check every command > output for leak messages, and fail the test if we detect any of these > messages. I've made this generic enough that we could check for other > debug messages in the future. > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> There already is a script to verify more than just the error leaks, I've added it to all the test type running scripts so it would fail. > --- > tests/common | 108 +++++++++++++++++++++++++++++---------------------- > 1 file changed, 61 insertions(+), 47 deletions(-) > > diff --git a/tests/common b/tests/common > index 602a4122..607ad747 100644 > --- a/tests/common > +++ b/tests/common > @@ -160,6 +160,18 @@ _is_target_command() > return 1 > } > > +# Check to see if there's any debug messages that may mean we have a problem. > +_check_output() > +{ > + local results="$1" > + > + if grep -q "extent buffer leak" "$results"; then > + _fail "extent buffer leak reported" There's more than that we'd like to catch, see tests/scan-results.sh. > + return 1 > + fi > + return 0 > +} > + > # Expanding extra commands/options for current command string > # This function is responsible for inserting the following things: > # - @INSTRUMENT before 'btrfs' commands
On 2023/9/6 04:21, Josef Bacik wrote: > I introduced a regression where we were leaking extent buffers, and this > resulted in the CI failing because we were spewing these errors. > > Instead of waiting for fstests to catch my mistakes, check every command > output for leak messages, and fail the test if we detect any of these > messages. I've made this generic enough that we could check for other > debug messages in the future. > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> Another solution is to make debug build of btrfs-progs more noisy when eb leak is detected. Instead of a graceful exit (which is suitable for release build), a noisy BUG_ON()/ASSERT() would definitely catch our attention, and requires less work in the test framework. Thanks, Qu > --- > tests/common | 108 +++++++++++++++++++++++++++++---------------------- > 1 file changed, 61 insertions(+), 47 deletions(-) > > diff --git a/tests/common b/tests/common > index 602a4122..607ad747 100644 > --- a/tests/common > +++ b/tests/common > @@ -160,6 +160,18 @@ _is_target_command() > return 1 > } > > +# Check to see if there's any debug messages that may mean we have a problem. > +_check_output() > +{ > + local results="$1" > + > + if grep -q "extent buffer leak" "$results"; then > + _fail "extent buffer leak reported" > + return 1 > + fi > + return 0 > +} > + > # Expanding extra commands/options for current command string > # This function is responsible for inserting the following things: > # - @INSTRUMENT before 'btrfs' commands > @@ -206,6 +218,48 @@ expand_command() > done > } > > +# This is the helper for the run_check variants. > +# The first argument is the run_check type > +# The second argument is the run_check type that will get logged to tty > +# The third argument is wether we want the output echo'ed > +# The rest of the arguments are the command > +_run_check() > +{ > + local header_type > + local test_log_type > + local do_stdout > + local tmp_output > + > + run_type="$1" > + shift > + > + test_log_type="$1" > + shift > + > + do_stdout="$1" > + shift > + > + tmp_output=$(mktemp --tmpdir btrfs-progs-leak-detect.XXXXXX) > + > + expand_command "$@" > + echo "====== RUN $run_type ${cmd_array[@]}" >> "$RESULTS" 2>&1 > + if [[ $TEST_LOG =~ tty ]]; then echo "$test_log_type: ${cmd_array[@]}" \ > + > /dev/tty; fi > + "${cmd_array[@]}" > "$tmp_output" 2>&1 > + ret=$? > + > + cat "$tmp_output" >> "$RESULTS" > + [ "$do_stdout" = true ] && cat "$tmp_output" > + > + if ! _check_output "$tmp_output"; then > + _fail "bad output" > + rm "$tmp_output" > + return 1 > + fi > + rm "$tmp_output" > + return "$ret" > +} > + > # Argument passing magic: > # the command passed to run_* helpers is inspected, if there's 'btrfs command' > # found and there are defined additional arguments, they're inserted just after > @@ -216,11 +270,7 @@ expand_command() > > run_check() > { > - expand_command "$@" > - echo "====== RUN CHECK ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD: ${cmd_array[@]}" > /dev/tty; fi > - > - "${cmd_array[@]}" >> "$RESULTS" 2>&1 || _fail "failed: ${cmd_array[@]}" > + _run_check "CHECK" "CMD" "false" "$@" || _fail "failed: ${cmd_array[@]}" > } > > # same as run_check but the stderr+stdout output is duplicated on stdout and > @@ -230,12 +280,8 @@ run_check() > # filter the output, as INSTRUMENT can easily pollute the output. > run_check_stdout() > { > - expand_command "$@" > - echo "====== RUN CHECK ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(stdout): ${cmd_array[@]}" \ > - > /dev/tty; fi > - "${cmd_array[@]}" 2>&1 | tee -a "$RESULTS" > - if [ ${PIPESTATUS[0]} -ne 0 ]; then > + _run_check "CHECK" "CMD(stdout)" "true" "$@" > + if [ $? -ne 0 ]; then > _fail "failed: $@" > fi > } > @@ -245,11 +291,7 @@ run_check_stdout() > # output is logged > run_mayfail() > { > - expand_command "$@" > - echo "====== RUN MAYFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mayfail): ${cmd_array[@]}" \ > - > /dev/tty; fi > - "${cmd_array[@]}" >> "$RESULTS" 2>&1 > + _run_check "MAYFAIL" "CMD(mayfail)" "false" "$@" > ret=$? > if [ $ret != 0 ]; then > echo "failed (ignored, ret=$ret): $@" >> "$RESULTS" > @@ -271,19 +313,8 @@ run_mayfail() > # store the output to a variable for further processing. > run_mayfail_stdout() > { > - tmp_output=$(mktemp --tmpdir btrfs-progs-mayfail-stdout.XXXXXX) > - > - expand_command "$@" > - echo "====== RUN MAYFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mayfail): ${cmd_array[@]}" \ > - > /dev/tty; fi > - "${cmd_array[@]}" 2>&1 > "$tmp_output" > + _run_check "MAYFAIL" "CMD(mayfail)" "true" "$@" > ret=$? > - > - cat "$tmp_output" >> "$RESULTS" > - cat "$tmp_output" > - rm -- "$tmp_output" > - > if [ "$ret" != 0 ]; then > echo "failed (ignored, ret=$ret): $@" >> "$RESULTS" > if [ "$ret" == 139 ]; then > @@ -312,12 +343,7 @@ run_mustfail() > exit 1 > fi > > - > - expand_command "$@" > - echo "====== RUN MUSTFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mustfail): ${cmd_array[@]}" \ > - > /dev/tty; fi > - "${cmd_array[@]}" >> "$RESULTS" 2>&1 > + _run_check "MUSTFAIL" "CMD(mustfail)" "false" "$@" > if [ $? != 0 ]; then > echo "failed (expected): $@" >> "$RESULTS" > return 0 > @@ -337,9 +363,6 @@ run_mustfail_stdout() > { > local msg > local ret > - local tmp_output > - > - tmp_output=$(mktemp --tmpdir btrfs-progs-mustfail-stdout.XXXXXX) > > msg="$1" > shift > @@ -349,17 +372,8 @@ run_mustfail_stdout() > exit 1 > fi > > - expand_command "$@" > - echo "====== RUN MUSTFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 > - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mustfail): ${cmd_array[@]}" \ > - > /dev/tty; fi > - "${cmd_array[@]}" 2>&1 > "$tmp_output" > + _run_check "MUSTFAIL" "CMD(mustfail)" "true" "$@" > ret=$? > - > - cat "$tmp_output" >> "$RESULTS" > - cat "$tmp_output" > - rm "$tmp_output" > - > if [ "$ret" != 0 ]; then > echo "failed (expected): $@" >> "$RESULTS" > return 0
On Tue, Sep 05, 2023 at 10:49:56PM +0200, David Sterba wrote: > On Tue, Sep 05, 2023 at 04:21:53PM -0400, Josef Bacik wrote: > > I introduced a regression where we were leaking extent buffers, and this > > resulted in the CI failing because we were spewing these errors. > > > > Instead of waiting for fstests to catch my mistakes, check every command > > output for leak messages, and fail the test if we detect any of these > > messages. I've made this generic enough that we could check for other > > debug messages in the future. > > > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> > > There already is a script to verify more than just the error leaks, I've > added it to all the test type running scripts so it would fail. > > --- > > tests/common | 108 +++++++++++++++++++++++++++++---------------------- > > 1 file changed, 61 insertions(+), 47 deletions(-) > > > > diff --git a/tests/common b/tests/common > > index 602a4122..607ad747 100644 > > --- a/tests/common > > +++ b/tests/common > > @@ -160,6 +160,18 @@ _is_target_command() > > return 1 > > } > > > > +# Check to see if there's any debug messages that may mean we have a problem. > > +_check_output() > > +{ > > + local results="$1" > > + > > + if grep -q "extent buffer leak" "$results"; then > > + _fail "extent buffer leak reported" > > There's more than that we'd like to catch, see tests/scan-results.sh. Yup I prefer your solution, you can ignore this patch. Thanks, Josef
On Wed, Sep 06, 2023 at 06:57:55AM +0800, Qu Wenruo wrote: > > > On 2023/9/6 04:21, Josef Bacik wrote: > > I introduced a regression where we were leaking extent buffers, and this > > resulted in the CI failing because we were spewing these errors. > > > > Instead of waiting for fstests to catch my mistakes, check every command > > output for leak messages, and fail the test if we detect any of these > > messages. I've made this generic enough that we could check for other > > debug messages in the future. > > > > Signed-off-by: Josef Bacik <josef@toxicpanda.com> > > Another solution is to make debug build of btrfs-progs more noisy when > eb leak is detected. > > Instead of a graceful exit (which is suitable for release build), a > noisy BUG_ON()/ASSERT() would definitely catch our attention, and > requires less work in the test framework. The eb leak checks are in the kernel-shared directory that does not share much with the debugging helpers in the other code. Eg. the message helpers, so we can't even grep for ERROR in the logs when there are no supposed to be seen.
diff --git a/tests/common b/tests/common index 602a4122..607ad747 100644 --- a/tests/common +++ b/tests/common @@ -160,6 +160,18 @@ _is_target_command() return 1 } +# Check to see if there's any debug messages that may mean we have a problem. +_check_output() +{ + local results="$1" + + if grep -q "extent buffer leak" "$results"; then + _fail "extent buffer leak reported" + return 1 + fi + return 0 +} + # Expanding extra commands/options for current command string # This function is responsible for inserting the following things: # - @INSTRUMENT before 'btrfs' commands @@ -206,6 +218,48 @@ expand_command() done } +# This is the helper for the run_check variants. +# The first argument is the run_check type +# The second argument is the run_check type that will get logged to tty +# The third argument is wether we want the output echo'ed +# The rest of the arguments are the command +_run_check() +{ + local header_type + local test_log_type + local do_stdout + local tmp_output + + run_type="$1" + shift + + test_log_type="$1" + shift + + do_stdout="$1" + shift + + tmp_output=$(mktemp --tmpdir btrfs-progs-leak-detect.XXXXXX) + + expand_command "$@" + echo "====== RUN $run_type ${cmd_array[@]}" >> "$RESULTS" 2>&1 + if [[ $TEST_LOG =~ tty ]]; then echo "$test_log_type: ${cmd_array[@]}" \ + > /dev/tty; fi + "${cmd_array[@]}" > "$tmp_output" 2>&1 + ret=$? + + cat "$tmp_output" >> "$RESULTS" + [ "$do_stdout" = true ] && cat "$tmp_output" + + if ! _check_output "$tmp_output"; then + _fail "bad output" + rm "$tmp_output" + return 1 + fi + rm "$tmp_output" + return "$ret" +} + # Argument passing magic: # the command passed to run_* helpers is inspected, if there's 'btrfs command' # found and there are defined additional arguments, they're inserted just after @@ -216,11 +270,7 @@ expand_command() run_check() { - expand_command "$@" - echo "====== RUN CHECK ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD: ${cmd_array[@]}" > /dev/tty; fi - - "${cmd_array[@]}" >> "$RESULTS" 2>&1 || _fail "failed: ${cmd_array[@]}" + _run_check "CHECK" "CMD" "false" "$@" || _fail "failed: ${cmd_array[@]}" } # same as run_check but the stderr+stdout output is duplicated on stdout and @@ -230,12 +280,8 @@ run_check() # filter the output, as INSTRUMENT can easily pollute the output. run_check_stdout() { - expand_command "$@" - echo "====== RUN CHECK ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(stdout): ${cmd_array[@]}" \ - > /dev/tty; fi - "${cmd_array[@]}" 2>&1 | tee -a "$RESULTS" - if [ ${PIPESTATUS[0]} -ne 0 ]; then + _run_check "CHECK" "CMD(stdout)" "true" "$@" + if [ $? -ne 0 ]; then _fail "failed: $@" fi } @@ -245,11 +291,7 @@ run_check_stdout() # output is logged run_mayfail() { - expand_command "$@" - echo "====== RUN MAYFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mayfail): ${cmd_array[@]}" \ - > /dev/tty; fi - "${cmd_array[@]}" >> "$RESULTS" 2>&1 + _run_check "MAYFAIL" "CMD(mayfail)" "false" "$@" ret=$? if [ $ret != 0 ]; then echo "failed (ignored, ret=$ret): $@" >> "$RESULTS" @@ -271,19 +313,8 @@ run_mayfail() # store the output to a variable for further processing. run_mayfail_stdout() { - tmp_output=$(mktemp --tmpdir btrfs-progs-mayfail-stdout.XXXXXX) - - expand_command "$@" - echo "====== RUN MAYFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mayfail): ${cmd_array[@]}" \ - > /dev/tty; fi - "${cmd_array[@]}" 2>&1 > "$tmp_output" + _run_check "MAYFAIL" "CMD(mayfail)" "true" "$@" ret=$? - - cat "$tmp_output" >> "$RESULTS" - cat "$tmp_output" - rm -- "$tmp_output" - if [ "$ret" != 0 ]; then echo "failed (ignored, ret=$ret): $@" >> "$RESULTS" if [ "$ret" == 139 ]; then @@ -312,12 +343,7 @@ run_mustfail() exit 1 fi - - expand_command "$@" - echo "====== RUN MUSTFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mustfail): ${cmd_array[@]}" \ - > /dev/tty; fi - "${cmd_array[@]}" >> "$RESULTS" 2>&1 + _run_check "MUSTFAIL" "CMD(mustfail)" "false" "$@" if [ $? != 0 ]; then echo "failed (expected): $@" >> "$RESULTS" return 0 @@ -337,9 +363,6 @@ run_mustfail_stdout() { local msg local ret - local tmp_output - - tmp_output=$(mktemp --tmpdir btrfs-progs-mustfail-stdout.XXXXXX) msg="$1" shift @@ -349,17 +372,8 @@ run_mustfail_stdout() exit 1 fi - expand_command "$@" - echo "====== RUN MUSTFAIL ${cmd_array[@]}" >> "$RESULTS" 2>&1 - if [[ $TEST_LOG =~ tty ]]; then echo "CMD(mustfail): ${cmd_array[@]}" \ - > /dev/tty; fi - "${cmd_array[@]}" 2>&1 > "$tmp_output" + _run_check "MUSTFAIL" "CMD(mustfail)" "true" "$@" ret=$? - - cat "$tmp_output" >> "$RESULTS" - cat "$tmp_output" - rm "$tmp_output" - if [ "$ret" != 0 ]; then echo "failed (expected): $@" >> "$RESULTS" return 0
I introduced a regression where we were leaking extent buffers, and this resulted in the CI failing because we were spewing these errors. Instead of waiting for fstests to catch my mistakes, check every command output for leak messages, and fail the test if we detect any of these messages. I've made this generic enough that we could check for other debug messages in the future. Signed-off-by: Josef Bacik <josef@toxicpanda.com> --- tests/common | 108 +++++++++++++++++++++++++++++---------------------- 1 file changed, 61 insertions(+), 47 deletions(-)