Merge branch 'th/performance' into 'main'

[th/performance] add script for combining performance results

See merge request GNOME/glib!3954
This commit is contained in:
Philip Withnall 2024-03-18 15:07:03 +00:00
commit 5b9dac546e
2 changed files with 386 additions and 27 deletions

View File

@ -0,0 +1,224 @@
#!/bin/bash
# Copyright (C) 2024 Red Hat, Inc.
#
# SPDX-License-Identifier: LGPL-2.1-or-later
# Run ./build/gobject/tests/performance/performance for several commits
# and compare the result.
#
# Howto:
#
# 1) configure the build. For example run
# $ git clean -fdx
# $ meson build -Dprefix=/tmp/glib/ -Db_lto=true --buildtype release -Ddebug=true
# Beware, that running the script will check out other commits,
# build the tree and run `ninja install`. Don't have important
# work there.
#
# 2) run the script. Set $COMMITS to the list of commit sha's to test.
# Environment variables:
# COMMITS: list of git references to test.
# PATCH: if set, after checking out each commit, run `git cherry-pick $PATCH`
# before building.
# PREPARE_CMD: if set, invoke $PREPARE_CMD after checking out commit. Can be used
# to patch the sources.
# PERF: if set, run performance test via perf. Set for example, `PERF="perf stat -r 10 -B"`
# When setting `PERF`, you probably also want to set GLIB_PERFORMANCE_FACTOR,
# which depends on the test (run the test in verbose mode to find a suitable factor).
# STRIP: if set to 1, call `strip` on the library and binary before running.
# Arguments: arguments are directly passed to performance. For example try "-s 1".
#
# Example:
#
# # once:
# git clean -fdx
# meson build -Dprefix=/tmp/glib/ -Db_lto=true --buildtype release -Ddebug=true
#
# # test:
# COMMIT_END=my-test-branch
# COMMIT_START="$(git merge-base origin/main "$COMMIT_END")"
# PERF="" PATCH="" COMMITS=" $COMMIT_START $COMMIT_END " /tmp/performance-run.sh -s 5
# PERF="" PATCH="" COMMITS=" $COMMIT_START $( git log --reverse --pretty=%H "$COMMIT_START..$COMMIT_END" ) " /tmp/performance-run.sh -s 5
#
# GLIB_PERFORMANCE_FACTOR=17.06 PERF='perf stat -r 3 -B' PATCH="" COMMITS=" $COMMIT_START $COMMIT_END " /tmp/performance-run.sh -s 1 property-get
set -e
usage() {
sed -n '4,/^$/ s/^#\( \(.*\)\|\)$/\2/p' "$0"
}
if [ "$#" -eq 1 ] && [ "$1" == "-h" ] ; then
usage
exit 0
fi
die() {
printf "%s\n" "$*"
exit 1
}
die_with_last_cmd() {
cat /tmp/glib-performance-last-cmd || :
die "$@"
}
read -ra COMMITS_V -d '' <<<"$COMMITS" || :
[ "${#COMMITS_V[@]}" -gt 0 ] || die "Must set \$COMMITS"
COMMITS_SHA=()
for commit in "${COMMITS_V[@]}" ; do
c="$(git rev-parse --verify "$commit^{commit}")" || die "invalid git reference \"$commit\""
COMMITS_SHA+=( "$c" )
done
_list_commits() {
local PREFIX="$1"
local idx
local I
I=0
for idx in "${!COMMITS_V[@]}" ; do
I=$((I+1))
echo "${PREFIX}[$I] $(git log -n1 --oneline "${COMMITS_SHA[$idx]}") (${COMMITS_V[$idx]})"
done
}
cat << EOF
Testing commits:
$(_list_commits " ")
\$ meson build -Dprefix=/tmp/glib/ -Db_lto=true --buildtype release -Ddebug=true
\$ PATCH=$(printf '%q' "$PATCH") \\
PREPARE_CMD=$(printf '%q' "$PREPARE_CMD") \\
PERF=$(printf '%q' "$PERF") \\
GLIB_PERFORMANCE_FACTOR=$(printf '%q' "$GLIB_PERFORMANCE_FACTOR") \\
STRIP=$(printf '%q' "$STRIP") \\
COMMITS=$(printf '%q' "$COMMITS") \\
$0$(printf ' %q' "$@")
EOF
_get_timing() {
local LINE_NUM="$1"
local LINE_PREFIX="$2"
local FILE="$3"
sed -n "$LINE_NUM s/^$LINE_PREFIX: //p" "$FILE"
}
_perc() {
awk -v n1="$1" -v n2="$2" 'BEGIN { printf("%+0.3g%\n", (n2 - n1) / n1 * 100.0); }'
}
_cmd() {
# printf ' $' ; printf ' %s' "$@" ; printf '\n'
"$@"
}
I=0
for idx in "${!COMMITS_V[@]}" ; do
commit="${COMMITS_V[$idx]}"
commit_sha="${COMMITS_SHA[$idx]}"
I=$((I+1))
echo -n ">>> [$I] test [ $(git log -n1 --oneline "$commit") ]"
git checkout -f "$commit_sha" &> /tmp/glib-performance-last-cmd || (echo ...; die_with_last_cmd "Failure to checkout \"$commit\"")
touch glib/gdataset.c gobject/gobject.c gobject/tests/performance/performance.c
if [ "$PATCH" != "" ] ; then
read -ra PATCH_ARR -d '' <<<"$PATCH" || :
for p in "${PATCH_ARR[@]}" ; do
git cherry-pick "$p" &> /tmp/glib-performance-last-cmd || (echo ...; die_with_last_cmd "Failure to cherry-pick \"$PATCH\"")
done
fi
if [ "$PREPARE_CMD" != "" ] ; then
I="$I" COMMIT="$commit" "$PREPARE_CMD" &> /tmp/glib-performance-last-cmd || (echo ...; die_with_last_cmd "\$PREPARE_CMD failed")
fi
echo " commit $(git rev-parse --verify HEAD) > /tmp/glib-performance-output.$I"
( ninja -C build || ninja -C build ) &> /tmp/glib-performance-last-cmd || die_with_last_cmd "Failure to build with \`ninja -C build\`"
ninja -C build install &> /tmp/glib-performance-last-cmd || die_with_last_cmd "FAilure to install with \`ninja -C build install\`"
if [ "$STRIP" = 1 ] ; then
strip ./build/gobject/libgobject-2.0.so ./build/glib/libglib-2.0.so.0 ./build/gobject/tests/performance/performance
fi
# ls -lad -L \
# ./build/gobject/libgobject-2.0.so \
# ./build/glib/libglib-2.0.so \
# ./build/gobject/tests/performance/performance
# ldd ./build/gobject/tests/performance/performance
(
if [ -z "$PERF" ] ; then
TESTRUN="$I" TESTCOMMIT="$commit" ./build/gobject/tests/performance/performance "$@"
else
TESTRUN="$I" TESTCOMMIT="$commit" $PERF ./build/gobject/tests/performance/performance "$@"
fi
) |& tee "/tmp/glib-performance-output.$I" || :
[ "${PIPESTATUS[0]}" -eq 0 ] || die "Performance test failed"
done
merge_output() {
(
declare -A RES
LINE_NUM=0
OLD_IFS="$IFS"
while IFS=$'\n' read -r LINE ; do
LINE="${LINE:1}"
LINE_NUM=$((LINE_NUM+1))
line_regex='^([a-zA-Z0-9].*): +([0-9.]+)$'
if [[ "$LINE" =~ $line_regex ]] ; then
LINE_PREFIX="${BASH_REMATCH[1]}"
T1="${BASH_REMATCH[2]}"
echo -n "$LINE_PREFIX: $T1"
RES["$LINE_PREFIX"]="${RES[$LINE_PREFIX]} $T1"
for J in $(seq 2 "${#COMMITS_V[@]}") ; do
T="$(_get_timing "$LINE_NUM" "$LINE_PREFIX" "/tmp/glib-performance-output.$J")"
echo -n " $T ($(_perc "$T1" "$T"))"
RES["$LINE_PREFIX"]="${RES[$LINE_PREFIX]} $T"
done
echo
continue
fi
if [ -n "$PERF" ] ; then
if [[ "$LINE" == *"seconds time elapsed"* ]] ; then
echo "[1] $LINE"
for J in $(seq 2 "${#COMMITS_V[@]}") ; do
echo "[$J] $(sed -n "$LINE_NUM s/seconds time elapsed/\\0/p" "/tmp/glib-performance-output.$J")"
done
continue
fi
fi
echo "$LINE"
done < <( sed 's/^/x/' "/tmp/glib-performance-output.1" )
IFS="$OLD_IFS"
if [ -n "$PERF" ] ; then
for LINE_PREFIX in "${!RES[@]}"; do
# The values are interleaved. To cumbersome to process in bash.
read -ra T -d '' <<<"${RES[$LINE_PREFIX]}" || :
read -ra T_SORTED -d '' < <(printf '%s\n' "${T[@]}" | awk -v C="${#COMMITS_V[@]}" '{ print (1 + (NR-1) % C) " " $0 }' | sort -n -s | sed 's/^[0-9]\+ *//' ) || :
NGROUP="$(( "${#T_SORTED[@]}" / "${#COMMITS_V[@]}" ))"
echo -n "$LINE_PREFIX: "
SEP=''
for J in $(seq 0 "${#T_SORTED[@]}") ; do
echo -n "$SEP${T_SORTED[$J]}"
if [ $(( (J+1) % NGROUP )) = 0 ]; then
echo -n " ; "
SEP=''
else
SEP=" , "
fi
done
echo
done
fi
) | tee "/tmp/glib-performance-output.all"
}
echo ">>> combined result > /tmp/glib-performance-output.all"
merge_output

View File

@ -22,6 +22,7 @@
#include "../testcommon.h"
#define WARM_UP_N_RUNS 50
#define WARM_UP_ALWAYS_SEC 2.0
#define ESTIMATE_ROUND_TIME_N_RUNS 5
#define DEFAULT_TEST_TIME 15 /* seconds */
/* The time we want each round to take, in seconds, this should
@ -31,13 +32,20 @@
#define TARGET_ROUND_TIME 0.008
static gboolean verbose = FALSE;
static gboolean quiet = FALSE;
static int test_length = DEFAULT_TEST_TIME;
static double test_factor = 0;
static GTimer *global_timer = NULL;
static GOptionEntry cmd_entries[] = {
{"verbose", 'v', 0, G_OPTION_ARG_NONE, &verbose,
"Print extra information", NULL},
{"quiet", 'q', 0, G_OPTION_ARG_NONE, &quiet,
"Print extra information", NULL},
{"seconds", 's', 0, G_OPTION_ARG_INT, &test_length,
"Time to run each test in seconds", NULL},
{"factor", 'f', 0, G_OPTION_ARG_DOUBLE, &test_factor,
"Use a fixed factor for sample runs (also $GLIB_PERFORMANCE_FACTOR)", NULL},
G_OPTION_ENTRY_NULL
};
@ -69,7 +77,8 @@ run_test (PerformanceTest *test)
double elapsed, min_elapsed, max_elapsed, avg_elapsed, factor;
GTimer *timer;
g_print ("Running test %s\n", test->name);
if (verbose || !quiet)
g_print ("Running test %s\n", test->name);
/* Set up test */
timer = g_timer_new ();
@ -81,11 +90,43 @@ run_test (PerformanceTest *test)
g_timer_start (timer);
/* Warm up the test by doing a few runs */
for (i = 0; i < WARM_UP_N_RUNS; i++)
for (i = 0; TRUE; i++)
{
test->init (test, data, 1.0);
test->run (test, data);
test->finish (test, data);
if (test_factor > 0)
{
/* The caller specified a constant factor. That makes mostly
* sense, to ensure that the test run is independent from
* external factors. In this case, don't make warm up dependent
* on WARM_UP_ALWAYS_SEC. */
}
else if (global_timer)
{
if (g_timer_elapsed (global_timer, NULL) < WARM_UP_ALWAYS_SEC)
{
/* We always warm up for a certain time where we keep the
* CPU busy.
*
* Note that when we run multiple tests, then this is only
* performed once for the first test. */
continue;
}
g_clear_pointer (&global_timer, g_timer_destroy);
}
if (i >= WARM_UP_N_RUNS)
break;
if (test_factor == 0 && g_timer_elapsed (timer, NULL) > test_length / 10)
{
/* The warm up should not take longer than 10 % of the entire
* test run. Note that the warm up time for WARM_UP_ALWAYS_SEC
* already passed. */
break;
}
}
g_timer_stop (timer);
@ -97,24 +138,32 @@ run_test (PerformanceTest *test)
g_print ("Estimating round time\n");
}
/* Estimate time for one run by doing a few test rounds */
min_elapsed = 0;
for (i = 0; i < ESTIMATE_ROUND_TIME_N_RUNS; i++)
if (test_factor > 0)
{
test->init (test, data, 1.0);
g_timer_start (timer);
test->run (test, data);
g_timer_stop (timer);
test->finish (test, data);
elapsed = g_timer_elapsed (timer, NULL);
if (i == 0)
min_elapsed = elapsed;
else
min_elapsed = MIN (min_elapsed, elapsed);
factor = test_factor;
}
else
{
/* Estimate time for one run by doing a few test rounds. */
for (i = 0; i < ESTIMATE_ROUND_TIME_N_RUNS; i++)
{
test->init (test, data, 1.0);
g_timer_start (timer);
test->run (test, data);
g_timer_stop (timer);
test->finish (test, data);
factor = TARGET_ROUND_TIME / min_elapsed;
elapsed = g_timer_elapsed (timer, NULL);
if (i == 0)
min_elapsed = elapsed;
else
min_elapsed = MIN (min_elapsed, elapsed);
}
factor = TARGET_ROUND_TIME / min_elapsed;
}
if (verbose)
g_print ("Uncorrected round time: %.4f msecs, correction factor %.2f\n", 1000*min_elapsed, factor);
@ -127,7 +176,7 @@ run_test (PerformanceTest *test)
/* Run the test */
avg_elapsed = 0.0;
min_elapsed = 0.0;
min_elapsed = 1e100;
max_elapsed = 0.0;
for (i = 0; i < num_rounds; i++)
{
@ -136,16 +185,18 @@ run_test (PerformanceTest *test)
test->run (test, data);
g_timer_stop (timer);
test->finish (test, data);
if (i < num_rounds / 20)
{
/* The first 5% are additional warm up. Ignore. */
continue;
}
elapsed = g_timer_elapsed (timer, NULL);
if (i == 0)
max_elapsed = min_elapsed = avg_elapsed = elapsed;
else
{
min_elapsed = MIN (min_elapsed, elapsed);
max_elapsed = MAX (max_elapsed, elapsed);
avg_elapsed += elapsed;
}
min_elapsed = MIN (min_elapsed, elapsed);
max_elapsed = MAX (max_elapsed, elapsed);
avg_elapsed += elapsed;
}
if (num_rounds > 1)
@ -159,6 +210,7 @@ run_test (PerformanceTest *test)
}
/* Print the results */
g_print ("%s: ", test->name);
test->print_result (test, data, min_elapsed);
/* Tear down */
@ -1087,6 +1139,12 @@ test_set_setup (PerformanceTest *test)
data = g_new0 (struct SetTest, 1);
data->object = g_object_new (COMPLEX_TYPE_OBJECT, NULL);
/* g_object_get() will take a reference. Increasing the ref count from 1 to 2
* is more expensive, due to the check for toggle notifications. We have a
* performance test for that already. Don't also test that overhead during
* "property-get" test and avoid this by taking an additional reference. */
g_object_ref (data->object);
return data;
}
@ -1123,6 +1181,7 @@ test_set_teardown (PerformanceTest *test,
{
struct SetTest *data = _data;
g_object_unref (data->object);
g_object_unref (data->object);
g_free (data);
}
@ -1158,6 +1217,12 @@ test_get_setup (PerformanceTest *test)
data = g_new0 (struct GetTest, 1);
data->object = g_object_new (COMPLEX_TYPE_OBJECT, NULL);
/* g_object_get() will take a reference. Increasing the ref count from 1 to 2
* is more expensive, due to the check for toggle notifications. We have a
* performance test for that already. Don't also test that overhead during
* "property-get" test and avoid this by taking an additional reference. */
g_object_ref (data->object);
return data;
}
@ -1194,6 +1259,7 @@ test_get_teardown (PerformanceTest *test,
{
struct GetTest *data = _data;
g_object_unref (data->object);
g_object_unref (data->object);
g_free (data);
}
@ -1207,8 +1273,16 @@ test_get_teardown (PerformanceTest *test,
struct RefcountTest {
GObject *object;
int n_checks;
gboolean is_toggle_ref;
};
static void
test_refcount_toggle_ref_cb (gpointer data,
GObject *object,
gboolean is_last_ref)
{
}
static gpointer
test_refcount_setup (PerformanceTest *test)
{
@ -1217,6 +1291,13 @@ test_refcount_setup (PerformanceTest *test)
data = g_new0 (struct RefcountTest, 1);
data->object = g_object_new (COMPLEX_TYPE_OBJECT, NULL);
if (g_str_equal (test->name, "refcount-toggle"))
{
g_object_add_toggle_ref (data->object, test_refcount_toggle_ref_cb, NULL);
g_object_unref (data->object);
data->is_toggle_ref = TRUE;
}
return data;
}
@ -1254,6 +1335,21 @@ test_refcount_run (PerformanceTest *test,
}
}
static void
test_refcount_1_run (PerformanceTest *test,
gpointer _data)
{
struct RefcountTest *data = _data;
GObject *object = data->object;
int i;
for (i = 0; i < data->n_checks; i++)
{
g_object_ref (object);
g_object_unref (object);
}
}
static void
test_refcount_finish (PerformanceTest *test,
gpointer _data)
@ -1276,7 +1372,11 @@ test_refcount_teardown (PerformanceTest *test,
{
struct RefcountTest *data = _data;
g_object_unref (data->object);
if (data->is_toggle_ref)
g_object_remove_toggle_ref (data->object, test_refcount_toggle_ref_cb, NULL);
else
g_object_unref (data->object);
g_free (data);
}
@ -1524,7 +1624,27 @@ static PerformanceTest tests[] = {
test_refcount_finish,
test_refcount_teardown,
test_refcount_print_result
}
},
{
"refcount-1",
NULL,
test_refcount_setup,
test_refcount_init,
test_refcount_1_run,
test_refcount_finish,
test_refcount_teardown,
test_refcount_print_result
},
{
"refcount-toggle",
NULL,
test_refcount_setup,
test_refcount_init,
test_refcount_1_run,
test_refcount_finish,
test_refcount_teardown,
test_refcount_print_result
},
};
static PerformanceTest *
@ -1545,8 +1665,14 @@ main (int argc,
PerformanceTest *test;
GOptionContext *context;
GError *error = NULL;
const char *str;
int i;
if ((str = g_getenv ("GLIB_PERFORMANCE_FACTOR")) && str[0])
{
test_factor = g_strtod (str, NULL);
}
context = g_option_context_new ("GObject performance tests");
g_option_context_add_main_entries (context, cmd_entries, NULL);
if (!g_option_context_parse (context, &argc, &argv, &error))
@ -1555,6 +1681,14 @@ main (int argc,
return 1;
}
if (test_factor < 0)
{
g_printerr ("%s: test factor must be positive\n", argv[0]);
return 1;
}
global_timer = g_timer_new ();
if (argc > 1)
{
for (i = 1; i < argc; i++)
@ -1572,5 +1706,6 @@ main (int argc,
}
g_option_context_free (context);
g_clear_pointer (&global_timer, g_timer_destroy);
return 0;
}