Skip to content

Commit

Permalink
Use libbacktrace for stack dumps if available (#4088)
Browse files Browse the repository at this point in the history
- Memory allocation tracing hooks to track where memory is being
  allocated and print summary with stack trace of each allocation
  site.  Used when logging in ComputeWriteSet to understand how/why
  it is using so much memory.
  • Loading branch information
Chris Dodd authored Aug 14, 2023
1 parent 6a144da commit 2820a3c
Show file tree
Hide file tree
Showing 14 changed files with 367 additions and 16 deletions.
3 changes: 2 additions & 1 deletion BUILD.bazel
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,8 @@ genrule(
outs = ["config.h"],
cmd = " | ".join([
"sed 's|cmakedefine|define|g' < $(SRCS)",
"sed 's|define HAVE_LIBGC 1|undef HAVE_LIBGC|g' > $(OUTS)",
"sed 's|define HAVE_LIBGC 1|undef HAVE_LIBGC|g'",
"sed 's|define HAVE_LIBBACKTRACE 1|undef HAVE_LIBBACKTRACE|g' > $(OUTS)",
]),
visibility = ["//visibility:private"],
)
Expand Down
5 changes: 5 additions & 0 deletions CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -176,9 +176,14 @@ p4c_add_library (rt clock_gettime HAVE_CLOCK_GETTIME)
include (CheckIncludeFile)
check_include_file (execinfo.h HAVE_EXECINFO_H)
check_include_file (ucontext.h HAVE_UCONTEXT_H)
check_include_file (backtrace-supported.h HAVE_LIBBACKTRACE)
include (CheckIncludeFileCXX)
check_include_file_cxx (cxxabi.h HAVE_CXXABI_H)

if (HAVE_LIBBACKTRACE)
set (P4C_LIB_DEPS "${P4C_LIB_DEPS};-lbacktrace")
endif ()

# check functions

# set libraries to be used with check_function_exists
Expand Down
7 changes: 7 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -367,6 +367,13 @@ may become impractical for compiling large programs. **Do not disable
the GC**, unless you really have to. We have noticed that this may be
a problem on MacOS.

## Crash dumps

P4c will use [libbacktrace](https://github.com/ianlancetaylor/libbacktrace.git)
to produce readable crash dumps if it is available. This is an optional
dependency; if it is not available everything should build just fine, but
crash dumps will not be very readable.

# Development tools

There is a variety of design and development documentation [here](docs/README.md).
Expand Down
3 changes: 3 additions & 0 deletions cmake/config.h.cmake
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,9 @@
/* Define to 1 if you have the execinfo.h header */
#cmakedefine HAVE_EXECINFO_H 1

/* Define to 1 if you have libbacktrace */
#cmakedefine HAVE_LIBBACKTRACE 1

/* Define to 1 if you have the LIBGC library. */
#cmakedefine HAVE_LIBGC 1

Expand Down
35 changes: 28 additions & 7 deletions frontends/p4/def_use.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -361,6 +361,8 @@ bool Definitions::operator==(const Definitions &other) const {
//////////////////////////////////////////////////////////////////////////////////////////////
// ComputeWriteSet implementation

int ComputeWriteSet::nest_count = 0;

// This assumes that all variable declarations have been pushed to the top.
// We could remove this constraint if we also scanned variable declaration initializers.
void ComputeWriteSet::enterScope(const IR::ParameterList *parameters,
Expand Down Expand Up @@ -404,7 +406,10 @@ void ComputeWriteSet::enterScope(const IR::ParameterList *parameters,
}
allDefinitions->setDefinitionsAt(entryPoint, defs, false);
currentDefinitions = defs;
LOG3("CWS Entered scope " << entryPoint << " definitions are " << Log::endl << defs);
if (LOGGING(5))
LOG5("CWS Entered scope " << entryPoint << " definitions are " << Log::endl << defs);
else
LOG3("CWS Entered scope " << entryPoint << " with " << defs->size() << " definitions");
}

void ComputeWriteSet::exitScope(const IR::ParameterList *parameters,
Expand Down Expand Up @@ -454,7 +459,10 @@ bool ComputeWriteSet::setDefinitions(Definitions *defs, const IR::Node *node, bo
// that the definitions are monotonically increasing.
if (findContext<IR::ParserState>()) overwrite = true;
allDefinitions->setDefinitionsAt(point, currentDefinitions, overwrite);
LOG3("CWS Definitions at " << point << " are " << Log::endl << defs);
if (LOGGING(5))
LOG5("CWS Definitions at " << point << " are " << Log::endl << defs);
else
LOG3("CWS " << defs->size() << " definitions at " << point);
return false; // always returns false
}

Expand Down Expand Up @@ -693,8 +701,12 @@ bool ComputeWriteSet::preorder(const IR::MethodCallExpression *expression) {
for (auto c : callees) (void)c->getNode()->apply(cw);
currentDefinitions = cw.currentDefinitions;
exitDefinitions = exitDefinitions->joinDefinitions(cw.exitDefinitions);
LOG3("Definitions after call of " << DBPrint::Brief << expression << ":" << Log::endl
<< currentDefinitions << DBPrint::Reset);
if (LOGGING(5))
LOG5("Definitions after call of " << DBPrint::Brief << expression << ":" << Log::endl
<< currentDefinitions << DBPrint::Reset);
else
LOG3(currentDefinitions->size() << " definitions after call of " << DBPrint::Brief
<< expression << DBPrint::Reset);
}

auto result = LocationSet::empty;
Expand Down Expand Up @@ -815,7 +827,10 @@ bool ComputeWriteSet::preorder(const IR::BlockStatement *statement) {
bool ComputeWriteSet::preorder(const IR::ReturnStatement *statement) {
if (statement->expression != nullptr) visit(statement->expression);
returnedDefinitions = returnedDefinitions->joinDefinitions(currentDefinitions);
LOG3("Return definitions " << returnedDefinitions);
if (LOGGING(5))
LOG5("Return definitions " << returnedDefinitions);
else
LOG3("Return " << returnedDefinitions->size() << " definitions");
auto defs = currentDefinitions->cloneDefinitions();
defs->setUnreachable();
return setDefinitions(defs);
Expand All @@ -824,7 +839,10 @@ bool ComputeWriteSet::preorder(const IR::ReturnStatement *statement) {
bool ComputeWriteSet::preorder(const IR::ExitStatement *) {
if (currentDefinitions->isUnreachable()) return setDefinitions(currentDefinitions);
exitDefinitions = exitDefinitions->joinDefinitions(currentDefinitions);
LOG3("Exit definitions " << exitDefinitions);
if (LOGGING(5))
LOG5("Exit definitions " << exitDefinitions);
else
LOG3("Exit with " << exitDefinitions->size() << " definitions");
auto defs = currentDefinitions->cloneDefinitions();
defs->setUnreachable();
return setDefinitions(defs);
Expand Down Expand Up @@ -944,7 +962,10 @@ bool ComputeWriteSet::preorder(const IR::Function *function) {
returnedDefinitions = new Definitions();
visit(function->body);
currentDefinitions = currentDefinitions->joinDefinitions(returnedDefinitions);
LOG3("CWS @" << point.after() << "=" << currentDefinitions);
if (LOGGING(5))
LOG5("CWS @" << point.after() << "=" << currentDefinitions);
else
LOG3("CWS @" << point.after() << " with " << currentDefinitions->size() << " defs");
allDefinitions->setDefinitionsAt(point.after(), currentDefinitions, false);
exitScope(function->type->parameters, locals);

Expand Down
21 changes: 21 additions & 0 deletions frontends/p4/def_use.h
Original file line number Diff line number Diff line change
Expand Up @@ -22,6 +22,7 @@ limitations under the License.

#include "frontends/p4/typeChecking/typeChecker.h"
#include "ir/ir.h"
#include "lib/alloc_trace.h"
#include "lib/ordered_map.h"
#include "lib/ordered_set.h"

Expand Down Expand Up @@ -404,6 +405,7 @@ class Definitions : public IHasDbPrint {
Definitions *cloneDefinitions() const { return new Definitions(*this); }
void removeLocation(const StorageLocation *loc);
bool empty() const { return definitions.empty(); }
size_t size() const { return definitions.size(); }
};

class AllDefinitions : public IHasDbPrint {
Expand Down Expand Up @@ -469,6 +471,9 @@ class ComputeWriteSet : public Inspector, public IHasDbPrint {
/// For each expression the location set it writes
ordered_map<const IR::Expression *, const LocationSet *> writes;
bool virtualMethod; /// True if we are analyzing a virtual method
AllocTrace memuse;
alloc_trace_cb_t nested_trace;
static int nest_count;

/// Creates new visitor, but with same underlying data structures.
/// Needed to visit some program fragments repeatedly.
Expand Down Expand Up @@ -509,6 +514,22 @@ class ComputeWriteSet : public Inspector, public IHasDbPrint {
if (writes.empty()) out << "No writes";
for (auto &it : writes) out << it.first << " writes " << it.second << Log::endl;
}
profile_t init_apply(const IR::Node *root) override {
auto rv = Inspector::init_apply(root);
LOG1("starting ComputWriteSet" << Log::indent);
if (nest_count++ == 0 && LOGGING(2)) {
memuse.clear();
nested_trace = memuse.start();
}
return rv;
}
void end_apply() override {
LOG1("finished CWS" << Log::unindent);
if (--nest_count == 0 && LOGGING(2)) {
memuse.stop(nested_trace);
LOG2(memuse);
}
}

public:
explicit ComputeWriteSet(AllDefinitions *allDefinitions)
Expand Down
5 changes: 4 additions & 1 deletion lib/CMakeLists.txt
Original file line number Diff line number Diff line change
Expand Up @@ -13,7 +13,8 @@
# limitations under the License.

set (LIBP4CTOOLKIT_SRCS
backtrace.cpp
alloc_trace.cpp
backtrace_exception.cpp
bitvec.cpp
compile_context.cpp
crash.cpp
Expand All @@ -39,6 +40,8 @@ set (LIBP4CTOOLKIT_SRCS

set (LIBP4CTOOLKIT_HDRS
algorithm.h
alloc_trace.h
backtrace_exception.h
bitops.h
bitrange.h
bitvec.h
Expand Down
112 changes: 112 additions & 0 deletions lib/alloc_trace.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,112 @@
#include "alloc_trace.h"

#include "hex.h"
#include "log.h"
#include "n4.h"

#if HAVE_EXECINFO_H
#include <execinfo.h>
#endif
#if HAVE_LIBBACKTRACE
#include <backtrace.h>

#include "exename.h"
#endif
#if HAVE_CXXABI_H
#include <cxxabi.h>
#endif

extern const char *addr2line(void *addr, const char *text);

#if HAVE_LIBBACKTRACE
extern struct backtrace_state *global_backtrace_state;

void bt_error(void *, const char *msg, int) { BUG("%s", msg); }

int bt_print_callback(void *out_, uintptr_t pc, const char *file, int line, const char *func) {
std::ostream &out = *static_cast<std::ostream *>(out_);
if (file) {
if (const char *p = strstr(file, "/frontends/")) {
file = p + 1;
} else if (const char *p = strstr(file, "/backends/")) {
file = p + 1;
} else if (const char *p = strstr(file, "/extensions/")) {
file = p + 1;
} else if (const char *p = strstr(file, "/lib/")) {
file = p + 1;
} else if (const char *p = strstr(file, "/ir/")) {
file = p + 1;
} else if (const char *p = strstr(file, "/include/")) {
file = p + 9;
}
} else {
file = "??";
}
out << Log::endl << file << ":" << line;
if (func) {
#if HAVE_CXXABI_H
int status;
if (char *fn = abi::__cxa_demangle(func, 0, 0, &status)) {
if (strlen(fn) < 100) out << " (" << fn << ")";
free(fn);
} else
#endif
out << " (" << func << ")";
}
out << " [" << hex(pc) << "]";
return 0;
}
#endif

void AllocTrace::count(void **bt, size_t sz) {
backtrace tr(bt);
data[tr][sz]++;
}

std::ostream &operator<<(std::ostream &out, const AllocTrace &at) {
#if HAVE_LIBGC
PauseTrace temp_pause;
#endif
typedef decltype(at.data)::value_type data_t;
std::vector<std::pair<size_t, const data_t *>> sorted;
size_t total_total = 0;
for (auto &e : at.data) {
size_t total = 0;
for (auto &al : e.second) total += al.first * al.second;
sorted.emplace_back(total, &e);
total_total += total;
}
std::sort(sorted.begin(), sorted.end(), [](auto &a, auto &b) { return a.first > b.first; });
#if HAVE_LIBBACKTRACE
if (!global_backtrace_state)
global_backtrace_state = backtrace_create_state(exename(), 1, bt_error, &out);
#endif
out << "Allocated a total of " << n4(total_total) << "B memory";
for (auto &s : sorted) {
if (s.first < 1000000) break; // ignore little stuff
size_t count = 0;
for (auto &al : s.second->second) count += al.second;
out << Log::endl << "allocated " << n4(s.first) << "B in " << count << " calls";
#if HAVE_EXECINFO_H
out << " from:" << Log::indent;
#if HAVE_LIBBACKTRACE
for (int i = 1; i < ALLOC_TRACE_DEPTH; ++i) {
/* due to calling the callback multiple times for inlined functions, we need to
* do this in ascending order or it makes no sense */
backtrace_pcinfo(global_backtrace_state,
reinterpret_cast<uintptr_t>(s.second->first.trace[i]),
bt_print_callback, bt_error, &out);
}
#else
char **syms = backtrace_symbols(s.second->first.trace, ALLOC_TRACE_DEPTH);
for (int i = ALLOC_TRACE_DEPTH - 1; i >= 1; --i) {
const char *alt = addr2line(s.second->first.trace[i], syms[i]);
out << Log::endl << (alt ? alt : syms[i]) << ' ' << s.second->first.trace[i];
}
free(syms);
#endif
out << Log::unindent;
#endif
}
return out;
}
78 changes: 78 additions & 0 deletions lib/alloc_trace.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,78 @@
/*
Copyright 2023-present Intel
Licensed under the Apache License, Version 2.0 (the "License");
you may not use this file except in compliance with the License.
You may obtain a copy of the License at
http://www.apache.org/licenses/LICENSE-2.0
Unless required by applicable law or agreed to in writing, software
distributed under the License is distributed on an "AS IS" BASIS,
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
See the License for the specific language governing permissions and
limitations under the License.
*/

#ifndef LIB_ALLOC_TRACE_H_
#define LIB_ALLOC_TRACE_H_

#include <map>
#include <ostream>

#include "exceptions.h"
#include "gc.h"

class AllocTrace {
struct backtrace {
void *trace[ALLOC_TRACE_DEPTH];

backtrace(const backtrace &) = default;
explicit backtrace(void **bt) { memcpy(trace, bt, sizeof(trace)); }
bool operator<(const backtrace &a) const {
for (int i = 0; i < ALLOC_TRACE_DEPTH; ++i)
if (trace[i] != a.trace[i]) return trace[i] < a.trace[i];
return false;
}
bool operator==(const backtrace &a) const {
for (int i = 0; i < ALLOC_TRACE_DEPTH; ++i)
if (trace[i] != a.trace[i]) return false;
return true;
}
};
std::map<backtrace, std::map<size_t, int>> data;
void count(void **, size_t);
static void callback(void *t, void **bt, size_t sz) {
static_cast<AllocTrace *>(t)->count(bt, sz);
}

public:
void clear() { data.clear(); }
#if HAVE_LIBGC
alloc_trace_cb_t start() { return set_alloc_trace(callback, this); }
void stop(alloc_trace_cb_t old) {
auto tmp = set_alloc_trace(old);
BUG_CHECK(tmp.fn == callback && tmp.arg == this, "AllocTrace stopped when not running");
}
#else
alloc_trace_cb_t start() {
BUG("Can't trace allocations without garbage collection");
return alloc_trace_cb_t{};
}
void stop(alloc_trace_cb_t) {}
#endif
friend std::ostream &operator<<(std::ostream &, const AllocTrace &);
};

class PauseTrace {
#if HAVE_LIBGC
alloc_trace_cb_t hold;
PauseTrace(const PauseTrace &) = delete;

public:
PauseTrace() { hold = set_alloc_trace(nullptr, nullptr); }
~PauseTrace() { set_alloc_trace(hold); }
#endif
};

#endif /* LIB_ALLOC_TRACE_H_ */
Loading

0 comments on commit 2820a3c

Please sign in to comment.