make profiler_unittest less brittle

So I noticed that profiler_unittest failed somewhat regularly on
armhf. On inspection I found that it fails because the test compares
"nested-most" tick counts between several profiles and we had most
ticks inside inlined atomic ops functions and not test_main_thread.

On the other hand, removing atomic ops from nested loop makes test way
too fast for the modern quick x86 desktops.

So lets make it try harder to be non-brittle. We do that by grabbing
access to profiler's ticks count, which helps our inner loops to run
long enough to get sufficient ticks count.

We also do couple more minor updates.

*) we have shell script use random temp directory name. Which allows
us to exercise golang-stress and similar utils.

*) we drop PERFTOOLS_UNITTEST and relevant code because this
"variable" was always set to be true anyways.
This commit is contained in:
Aliaksei Kandratsenka 2024-09-23 13:45:45 -04:00
parent dd751345df
commit 3cc9014c57
4 changed files with 69 additions and 64 deletions

View File

@ -143,6 +143,8 @@ class ProfileData {
void GetCurrentState(State* state) const; void GetCurrentState(State* state) const;
private: private:
friend class CpuProfiler;
static const int kAssociativity = 4; // For hashtable static const int kAssociativity = 4; // For hashtable
static const int kBuckets = 1 << 10; // For hashtable static const int kBuckets = 1 << 10; // For hashtable
static const int kBufferLength = 1 << 18; // For eviction buffer static const int kBufferLength = 1 << 18; // For eviction buffer

View File

@ -68,12 +68,6 @@ typedef int ucontext_t; // just to quiet the compiler, mostly
using std::string; using std::string;
DEFINE_bool(cpu_profiler_unittest,
EnvToBool("PERFTOOLS_UNITTEST", true),
"Determines whether or not we are running under the \
control of a unit test. This allows us to include or \
exclude certain behaviours.");
// Collects up all profile data. This is a singleton, which is // Collects up all profile data. This is a singleton, which is
// initialized by a constructor at startup. If no cpu profiler // initialized by a constructor at startup. If no cpu profiler
// signal is specified then the profiler lifecycle is either // signal is specified then the profiler lifecycle is either
@ -176,22 +170,13 @@ CpuProfiler CpuProfiler::instance_;
// Initialize profiling: activated if getenv("CPUPROFILE") exists. // Initialize profiling: activated if getenv("CPUPROFILE") exists.
CpuProfiler::CpuProfiler() CpuProfiler::CpuProfiler()
: prof_handler_token_(NULL) { : prof_handler_token_(NULL) {
// TODO(cgd) Move this code *out* of the CpuProfile constructor into a
// separate object responsible for initialization. With ProfileHandler there
// is no need to limit the number of profilers.
if (getenv("CPUPROFILE") == NULL) { if (getenv("CPUPROFILE") == NULL) {
if (!FLAGS_cpu_profiler_unittest) {
RAW_LOG(WARNING, "CPU profiler linked but no valid CPUPROFILE environment variable found\n");
}
return; return;
} }
// We don't enable profiling if setuid -- it's a security risk // We don't enable profiling if setuid -- it's a security risk
#ifdef HAVE_GETEUID #ifdef HAVE_GETEUID
if (getuid() != geteuid()) { if (getuid() != geteuid()) {
if (!FLAGS_cpu_profiler_unittest) {
RAW_LOG(WARNING, "Cannot perform CPU profiling when running with setuid\n");
}
return; return;
} }
#endif #endif
@ -212,11 +197,8 @@ CpuProfiler::CpuProfiler()
} else { } else {
char fname[PATH_MAX]; char fname[PATH_MAX];
if (!GetUniquePathFromEnv("CPUPROFILE", fname)) { if (!GetUniquePathFromEnv("CPUPROFILE", fname)) {
if (!FLAGS_cpu_profiler_unittest) {
RAW_LOG(WARNING, "CPU profiler linked but no valid CPUPROFILE environment variable found\n");
}
return; return;
} }
if (!Start(fname, NULL)) { if (!Start(fname, NULL)) {
RAW_LOG(FATAL, "Can't turn on cpu profiling for '%s': %s\n", RAW_LOG(FATAL, "Can't turn on cpu profiling for '%s': %s\n",
@ -307,9 +289,23 @@ void CpuProfiler::GetCurrentState(ProfilerState* state) {
state->enabled = collector_state.enabled; state->enabled = collector_state.enabled;
state->start_time = static_cast<time_t>(collector_state.start_time); state->start_time = static_cast<time_t>(collector_state.start_time);
state->samples_gathered = collector_state.samples_gathered; state->samples_gathered = collector_state.samples_gathered;
int buf_size = sizeof(state->profile_name);
strncpy(state->profile_name, collector_state.profile_name, buf_size); constexpr int kBufSize = sizeof(state->profile_name);
state->profile_name[buf_size-1] = '\0'; std::string_view profile_name{collector_state.profile_name};
memcpy(state->profile_name, profile_name.data(), std::min<size_t>(kBufSize, profile_name.size() + 1));
state->profile_name[kBufSize - 1] = '\0';
// Note, this is "secret" and version-specific API we do for
// profiler_unittest. It is explicitly not part of any API/ABI
// stability guarantees.
//
// If there is space in profile_name left for the pointer, then we
// append address of samples_gathered. The test uses this "ticks
// count" as a form of clock to know how long it runs.
if (profile_name.size() + 1 + sizeof(void*) <= kBufSize) {
void* ptr = &collector_.count_;
memcpy(state->profile_name + profile_name.size() + 1, &ptr, sizeof(ptr));
}
} }
void CpuProfiler::EnableHandler() { void CpuProfiler::EnableHandler() {

View File

@ -38,10 +38,12 @@
#include "config_for_unittests.h" #include "config_for_unittests.h"
#include <stdio.h> #include <stdio.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h>
#ifdef HAVE_UNISTD_H #ifdef HAVE_UNISTD_H
#include <unistd.h> // for fork() #include <unistd.h> // for fork()
#endif
#include <sys/wait.h> // for wait() #include <sys/wait.h> // for wait()
#endif
#include <atomic> #include <atomic>
#include <mutex> #include <mutex>
@ -49,23 +51,43 @@
#include "gperftools/profiler.h" #include "gperftools/profiler.h"
#include "tests/testutil.h" #include "tests/testutil.h"
static std::atomic<int> result;
static int g_iters; // argv[1] static int g_iters; // argv[1]
// g_ticks_count points to internal profiler's tick count that
// increments each profiling tick. Makes it possible for this test
// loops to run long enough to get enough ticks.
static int volatile *g_ticks_count = ([] () {
ProfilerState state;
memset(&state, 0, sizeof(state));
ProfilerGetCurrentState(&state);
size_t sz = strlen(state.profile_name);
if (sz + 1 + sizeof(g_ticks_count) > sizeof(state.profile_name)) {
fprintf(stderr, "too long profile_name?: %zu (%s)\n", sz, state.profile_name);
abort();
}
int volatile* ptr;
memcpy(&ptr, state.profile_name + sz + 1, sizeof(ptr));
return ptr;
})();
std::mutex mutex; std::mutex mutex;
static void test_other_thread() { static void test_other_thread() {
#ifndef NO_THREADS #ifndef NO_THREADS
ProfilerRegisterThread(); ProfilerRegisterThread();
int i, m; int result = 0;
char b[128]; char b[128];
// Get at least 30 ticks
int limit = *g_ticks_count + 30;
std::lock_guard ml(mutex); std::lock_guard ml(mutex);
for (m = 0; m < 1000000; ++m) { // run millions of times
for (i = 0; i < g_iters; ++i ) { while (*g_ticks_count < limit) {
result ^= i; for (int i = 0; i < g_iters * 10; ++i ) {
*const_cast<volatile int*>(&result) ^= i;
} }
snprintf(b, sizeof(b), "other: %d", result.load()); // get some libc action snprintf(b, sizeof(b), "other: %d", result); // get some libc action
(void)noopt(b); // 'consume' b. Ensure that smart compiler doesn't (void)noopt(b); // 'consume' b. Ensure that smart compiler doesn't
// remove snprintf call // remove snprintf call
} }
@ -73,18 +95,24 @@ static void test_other_thread() {
} }
static void test_main_thread() { static void test_main_thread() {
int i, m; int result = 0;
char b[128]; char b[128];
// Get at least 30 ticks
int limit = *g_ticks_count + 30;
std::lock_guard ml(mutex); std::lock_guard ml(mutex);
for (m = 0; m < 1000000; ++m) { // run millions of times
for (i = 0; i < g_iters; ++i ) { while (*g_ticks_count < limit) {
result ^= i; for (int i = 0; i < g_iters * 10; ++i ) {
*const_cast<volatile int*>(&result) ^= i;
} }
snprintf(b, sizeof(b), "same: %d", result.load()); // get some libc action snprintf(b, sizeof(b), "same: %d", result); // get some libc action
(void)noopt(b); // 'consume' b (void)noopt(b); // 'consume' b
} }
} }
int main(int argc, char** argv) { int main(int argc, char** argv) {
if ( argc <= 1 ) { if ( argc <= 1 ) {
fprintf(stderr, "USAGE: %s <iters> [num_threads] [filename]\n", argv[0]); fprintf(stderr, "USAGE: %s <iters> [num_threads] [filename]\n", argv[0]);

View File

@ -2,11 +2,11 @@
# Copyright (c) 2005, Google Inc. # Copyright (c) 2005, Google Inc.
# All rights reserved. # All rights reserved.
# #
# Redistribution and use in source and binary forms, with or without # Redistribution and use in source and binary forms, with or without
# modification, are permitted provided that the following conditions are # modification, are permitted provided that the following conditions are
# met: # met:
# #
# * Redistributions of source code must retain the above copyright # * Redistributions of source code must retain the above copyright
# notice, this list of conditions and the following disclaimer. # notice, this list of conditions and the following disclaimer.
# * Redistributions in binary form must reproduce the above # * Redistributions in binary form must reproduce the above
@ -16,7 +16,7 @@
# * Neither the name of Google Inc. nor the names of its # * Neither the name of Google Inc. nor the names of its
# contributors may be used to endorse or promote products derived from # contributors may be used to endorse or promote products derived from
# this software without specific prior written permission. # this software without specific prior written permission.
# #
# THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS # THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
# "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT # "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
# LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR # LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
@ -53,15 +53,12 @@ if [ "x$1" = "x-h" -o "x$1" = "x--help" ]; then
exit 1 exit 1
fi fi
TMPDIR=/tmp/profile_info # note, this also creates temp directory
TMPDIR=`mktemp -d`
UNITTEST_DIR=${1:-$BINDIR} UNITTEST_DIR=${1:-$BINDIR}
PPROF=${2:-$PPROF_PATH} PPROF=${2:-$PPROF_PATH}
# We test the sliding-window functionality of the cpu-profile reader
# by using a small stride, forcing lots of reads.
PPROF_FLAGS="--test_stride=128"
PROFILER1="$UNITTEST_DIR/profiler1_unittest" PROFILER1="$UNITTEST_DIR/profiler1_unittest"
PROFILER2="$UNITTEST_DIR/profiler2_unittest" PROFILER2="$UNITTEST_DIR/profiler2_unittest"
PROFILER3="$UNITTEST_DIR/profiler3_unittest" PROFILER3="$UNITTEST_DIR/profiler3_unittest"
@ -85,17 +82,6 @@ PROFILER4_REALNAME=`Realname "$PROFILER4"`
# It's meaningful to the profiler, so make sure we know its state # It's meaningful to the profiler, so make sure we know its state
unset CPUPROFILE unset CPUPROFILE
# Some output/logging in the profiler can cause issues when running the unit
# tests. For example, logging a warning when the profiler is detected as being
# present but no CPUPROFILE is specified in the environment. Especially when
# we are checking for a silent run or specific timing constraints are being
# checked. So set the env variable signifying that we are running in a unit
# test environment.
PERFTOOLS_UNITTEST=1
rm -rf "$TMPDIR"
mkdir "$TMPDIR" || exit 2
num_failures=0 num_failures=0
RegisterFailure() { RegisterFailure() {
@ -118,8 +104,8 @@ VerifySimilar() {
# We are careful not to put exec1 and exec2 in quotes, because if # We are careful not to put exec1 and exec2 in quotes, because if
# they are the empty string, it means we want to use the 1-arg # they are the empty string, it means we want to use the 1-arg
# version of pprof. # version of pprof.
mthread1=`"$PPROF" $PPROF_FLAGS $exec1 "$prof1" | grep test_main_thread | awk '{print $1}'` mthread1=`"$PPROF" $exec1 "$prof1" | grep test_main_thread | awk '{print $1}'`
mthread2=`"$PPROF" $PPROF_FLAGS $exec2 "$prof2" | grep test_main_thread | awk '{print $1}'` mthread2=`"$PPROF" $exec2 "$prof2" | grep test_main_thread | awk '{print $1}'`
mthread1_plus=`expr $mthread1 + 5` mthread1_plus=`expr $mthread1 + 5`
mthread2_plus=`expr $mthread2 + 5` mthread2_plus=`expr $mthread2 + 5`
if [ -z "$mthread1" ] || [ -z "$mthread2" ] || \ if [ -z "$mthread1" ] || [ -z "$mthread2" ] || \
@ -151,8 +137,8 @@ VerifyAcrossThreads() {
# We are careful not to put exec1 in quotes, because if it is the # We are careful not to put exec1 in quotes, because if it is the
# empty string, it means we want to use the 1-arg version of pprof. # empty string, it means we want to use the 1-arg version of pprof.
mthread=`$PPROF $PPROF_FLAGS $exec1 "$prof1" | grep test_main_thread | awk '{print $1}'` mthread=`$PPROF $exec1 "$prof1" | grep test_main_thread | awk '{print $1}'`
othread=`$PPROF $PPROF_FLAGS $exec1 "$prof1" | grep test_other_thread | awk '{print $1}'` othread=`$PPROF $exec1 "$prof1" | grep test_other_thread | awk '{print $1}'`
if [ -z "$mthread" ] || [ -z "$othread" ] || \ if [ -z "$mthread" ] || [ -z "$othread" ] || \
[ "$mthread" -le 0 -o "$othread" -le 0 ] [ "$mthread" -le 0 -o "$othread" -le 0 ]
# || [ `expr $mthread \* $mult \* 3` -gt `expr $othread \* 10` -o \ # || [ `expr $mthread \* $mult \* 3` -gt `expr $othread \* 10` -o \
@ -166,13 +152,6 @@ VerifyAcrossThreads() {
fi fi
} }
echo
echo ">>> WARNING <<<"
echo "This test looks at timing information to determine correctness."
echo "If your system is loaded, the test may spuriously fail."
echo "If the test does fail with an 'Actual times' error, try running again."
echo
# profiler1 is a non-threaded version # profiler1 is a non-threaded version
"$PROFILER1" 50 1 "$TMPDIR/p1" || RegisterFailure "$PROFILER1" 50 1 "$TMPDIR/p1" || RegisterFailure
"$PROFILER1" 100 1 "$TMPDIR/p2" || RegisterFailure "$PROFILER1" 100 1 "$TMPDIR/p2" || RegisterFailure