Skip to content

Commit

Permalink
Clean test_{runner,scalafmt_helper}, add diagnostic env vars, and i…
Browse files Browse the repository at this point in the history
…mprove `test_cross_build` performance (#1646)

* Clean test_{runner,scalafmt_helper}, add env vars

Did a little cleaning up while trying to get protobuf to stop
recompiling so often. Didn't impact that problem, but good cleanups
regardless.

Also added two environment variables to make diagnosing test failures
(or slowdowns) easier:

- Defining `RULES_SCALA_TEST_ONLY`will cause only one specific test case
  to run, with full Bazel output. This is helpful for pinpointing and
  working on a specific test without hunting for it or recreating its
  commands.

- Defining `RULES_SCALA_TEST_VERBOSE` will cause all tests to emit full
  Bazel output. This is more useful when running all the tests from a
  specific script from `test/shell/test_*.sh`.

Also, today I learned that `SECONDS` is a special Bash variable. Making
it `local` screwed it up and showed all tests as taking zero seconds.

* Don't clean test_cross_build, shutdown at end

This speeds up the `test_cross_build.sh` tests substantially,
particularly between runs. Here are the times for two runs before this
change; the first is after running `bazel clean` and `bazel shutdown` in
the `test_cross_build` directory:

```txt
$ /usr/bin/time ./test_cross_build.sh

running test test_cross_build
 Test "test_cross_build" successful (73 sec)
running test test_scalafmt
 Test "test_scalafmt" successful (94 sec)
      167.01 real         0.37 user         0.50 sys

$ /usr/bin/time ./test_cross_build.sh

running test test_cross_build
 Test "test_cross_build" successful (8 sec)
running test test_scalafmt
 Test "test_scalafmt" successful (92 sec)
       99.96 real         0.35 user         0.48 sys
```

Here are the times for two equivalent runs after this change:

```txt
$ /usr/bin/time ./test_cross_build.sh

running test test_cross_build
 Test "test_cross_build" successful (71 sec)
running test test_scalafmt
 Test "test_scalafmt" successful (6 sec)
       77.50 real         0.33 user         0.44 sys

$ /usr/bin/time ./test_cross_build.sh

running test test_cross_build
 Test "test_cross_build" successful (5 sec)
running test test_scalafmt
 Test "test_scalafmt" successful (2 sec)
        7.21 real         0.26 user         0.38 sys
```

The effect is even more dramatic when setting compiler flags in
`.bazelrc`, as I've tried while building protobuf-v28.3 under Bazel
6.5.0.
  • Loading branch information
mbland authored Nov 12, 2024
1 parent f758956 commit d43ae0d
Show file tree
Hide file tree
Showing 3 changed files with 64 additions and 35 deletions.
11 changes: 9 additions & 2 deletions test/shell/test_cross_build.sh
Original file line number Diff line number Diff line change
Expand Up @@ -9,11 +9,11 @@ cd test_cross_build

function test_cross_build() {
bazel test //...
bazel clean
bazel shutdown;
}

function test_scalafmt() {
bazel build //scalafmt/...

run_formatting scalafmt binary2 binary2
run_formatting scalafmt binary3 binary3
run_formatting scalafmt library2 library2
Expand All @@ -24,3 +24,10 @@ function test_scalafmt() {

$runner test_cross_build
$runner test_scalafmt

# `bazel shutdown` used to be in `test_cross_build`, after a `bazel clean`.
# However, the protobuf library tends to rebuild frequently. Not cleaning and
# postponing the shutdown to the end of the script helps avoid rebuilding as
# often, speeding up the tests. It also potentially speeds up debugging by
# preserving the workspace state when a test fails.
bazel shutdown
45 changes: 32 additions & 13 deletions test/shell/test_runner.sh
Original file line number Diff line number Diff line change
Expand Up @@ -13,9 +13,10 @@ run_test_ci() {
echo "running test $TEST_ARG"
eval $TEST_ARG &>$log_file &
local test_pid=$!

SECONDS=0
TIMOUT=${TEST_TIMEOUT-60}
test_pulse_printer $! $TIMOUT $TEST_ARG &
test_pulse_printer "$test_pid" "${TEST_TIMEOUT:-60}" $TEST_ARG &

local pulse_printer_pid=$!
local result

Expand All @@ -25,7 +26,7 @@ run_test_ci() {
kill $pulse_printer_pid && wait $pulse_printer_pid 2>/dev/null || true
} || return 1

DURATION=$SECONDS
local DURATION=$SECONDS
if [ $result -eq 0 ]; then
echo -e "\n${GREEN}Test \"$TEST_ARG\" successful ($DURATION sec) $NC"
else
Expand All @@ -38,9 +39,9 @@ run_test_ci() {

test_pulse_printer() {
# makes sure something is printed to stdout while test is running
local test_pid=$1
local test_pid="$1"
shift
local timeout=$1 # in minutes
local timeout="$1" # in minutes
shift
local count=0

Expand All @@ -60,24 +61,42 @@ test_pulse_printer() {
run_test_local() {
# runs the tests locally
set +e
SECONDS=0
TEST_ARG=$@
local TEST_ARG=$@
local RES=''

# This allows us to run a single test case with full Bazel output without
# having to search for it and recreate its command line.
if [[ -n "$RULES_SCALA_TEST_ONLY" &&
"$TEST_ARG" != "$RULES_SCALA_TEST_ONLY" ]]; then
return
fi

echo "running test $TEST_ARG"
RES=$($TEST_ARG 2>&1)
RESPONSE_CODE=$?
DURATION=$SECONDS
SECONDS=0

if [[ -n "$RULES_SCALA_TEST_VERBOSE" || -n "$RULES_SCALA_TEST_ONLY" ]]; then
$TEST_ARG
else
RES="$($TEST_ARG 2>&1)"
fi

local RESPONSE_CODE="$?"
local DURATION="$SECONDS"

if [ $RESPONSE_CODE -eq 0 ]; then
echo -e "${GREEN} Test \"$TEST_ARG\" successful ($DURATION sec) $NC"
else
echo -e "\nLog:\n"
echo "$RES"
if [[ -n "$RES" ]]; then
echo -e "\nLog:\n"
echo "$RES"
fi
echo -e "${RED} Test \"$TEST_ARG\" failed $NC ($DURATION sec) $NC"
exit $RESPONSE_CODE
fi
}

get_test_runner() {
test_env=$1
local test_env="$1"
if [[ "${test_env}" != "ci" && "${test_env}" != "local" ]]; then
echo -e "${RED}test_env must be either 'local' or 'ci'"
exit 1
Expand Down
43 changes: 23 additions & 20 deletions test/shell/test_scalafmt_helper.sh
Original file line number Diff line number Diff line change
@@ -1,57 +1,60 @@
backup_unformatted() {
FILE_PATH=$1
FILENAME=$2
cp $FILE_PATH/unformatted/unformatted-$FILENAME.scala $FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala
local FILE_PATH="$1"
local FILENAME="$2"
cp "$FILE_PATH/unformatted/unformatted-$FILENAME.scala" \
"$FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala"
}

restore_unformatted_before_exit() {
FILE_PATH=$1
FILENAME=$2
cp $FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala $FILE_PATH/unformatted/unformatted-$FILENAME.scala
rm -f $FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala
local FILE_PATH="$1"
local FILENAME="$2"
cp "$FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala" \
"$FILE_PATH/unformatted/unformatted-$FILENAME.scala"
rm -f "$FILE_PATH/unformatted/unformatted-$FILENAME.backup.scala"
}

run_formatting() {
set +e

PACKAGE_DIR=$1
RULE_TYPE=$2
FILENAME=$3
local PACKAGE_DIR="$1"
local RULE_TYPE="$2"
local FILENAME="$3"

#on windows scalafmt targets need to be run using bash.
#TODO: improve the scalafmt funcitonality so we don't need to use the run_under mechanism
local run_under=""
local bazel_run=('bazel' 'run')
if is_windows; then
run_under="--run_under=bash"
bazel_run+=('--run_under=bash')
fi

bazel run //$PACKAGE_DIR:formatted-$RULE_TYPE.format-test $run_under
"${bazel_run[@]}" "//$PACKAGE_DIR:formatted-$RULE_TYPE.format-test"
if [ $? -ne 0 ]; then
echo -e "${RED} formatted-$RULE_TYPE.format-test should be a formatted target. $NC"
exit 1
fi

bazel run //$PACKAGE_DIR:unformatted-$RULE_TYPE.format-test $run_under
"${bazel_run[@]}" "//$PACKAGE_DIR:unformatted-$RULE_TYPE.format-test"
if [ $? -eq 0 ]; then
echo -e "${RED} unformatted-$RULE_TYPE.format-test should be an unformatted target. $NC"
exit 1
fi

backup_unformatted $PACKAGE_DIR $FILENAME
backup_unformatted "$PACKAGE_DIR" "$FILENAME"
# format unformatted*.scala

bazel run //$PACKAGE_DIR:unformatted-$RULE_TYPE.format $run_under
"${bazel_run[@]}" "//$PACKAGE_DIR:unformatted-$RULE_TYPE.format"
if [ $? -ne 0 ]; then
echo -e "${RED} unformatted-$RULE_TYPE.format should run formatting. $NC"
restore_unformatted_before_exit $PACKAGE_DIR $FILENAME
restore_unformatted_before_exit "$PACKAGE_DIR" "$FILENAME"
exit 1
fi

diff $FILE_PATH/unformatted/unformatted-$FILENAME.scala $FILE_PATH/formatted/formatted-$FILENAME.scala
diff "$PACKAGE_DIR/unformatted/unformatted-$FILENAME.scala" \
"$PACKAGE_DIR/formatted/formatted-$FILENAME.scala"
if [ $? -ne 0 ]; then
echo -e "${RED} unformatted-$FILENAME.scala should be the same as formatted-$FILENAME.scala after formatting. $NC"
restore_unformatted_before_exit $PACKAGE_DIR $FILENAME
restore_unformatted_before_exit "$PACKAGE_DIR" "$FILENAME"
exit 1
fi
restore_unformatted_before_exit $FILE_PATH $FILENAME
restore_unformatted_before_exit "$PACKAGE_DIR" "$FILENAME"
}

0 comments on commit d43ae0d

Please sign in to comment.