Skip to content

Make stack trace display more user friendly #3406

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 4 commits into from
Jun 21, 2019
Merged

Make stack trace display more user friendly #3406

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
2192877
Support multiple stacktrace format
rosun82 Jun 20, 2019
0263de7
Fix an issue
rosun82 Jun 20, 2019
c4e4e75
Fix a macro
rosun82 Jun 20, 2019
d85580f
Minor fix
rosun82 Jun 21, 2019
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
49 changes: 39 additions & 10 deletions src/base/kaldi-error-test.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -17,19 +17,14 @@
// See the Apache 2 License for the specific language governing permissions and
// limitations under the License.


#include "base/kaldi-common.h"

// testing that we get the stack trace.
namespace kaldi {

void MyFunction2() {
KALDI_ERR << "Ignore this error";
}
void MyFunction2() { KALDI_ERR << "Ignore this error"; }

void MyFunction1() {
MyFunction2();
}
void MyFunction1() { MyFunction2(); }

void UnitTestError() {
{
Expand All @@ -38,16 +33,50 @@ void UnitTestError() {
}
}

void VerifySymbolRange(const std::string &trace, const bool want_found,
const std::string &want_symbol) {
size_t begin, end;
const bool found = internal::LocateSymbolRange(trace, &begin, &end);
if (found != want_found) {
KALDI_ERR << "Found mismatch, got " << found << " want " << want_found;
}
if (!found) {
return;
}
const std::string symbol = trace.substr(begin, end - begin);
if (symbol != want_symbol) {
KALDI_ERR << "Symbol mismatch, got " << symbol << " want " << want_symbol;
}
}

void TestLocateSymbolRange() {
VerifySymbolRange("", false, "");
VerifySymbolRange(
R"TRACE(./kaldi-error-test(_ZN5kaldi13UnitTestErrorEv+0xb) [0x804965d])TRACE",
true, "_ZN5kaldi13UnitTestErrorEv");
// It is ok thread_start is not found because it is a C symbol.
VerifySymbolRange(
R"TRACE(31 libsystem_pthread.dylib 0x00007fff6fe4e40d thread_start + 13)TRACE",
false, "");
VerifySymbolRange(
R"TRACE(0 server 0x000000010f67614d _ZNK5kaldi13MessageLogger10LogMessageEv + 813)TRACE",
true, "_ZNK5kaldi13MessageLogger10LogMessageEv");
VerifySymbolRange(
R"TRACE(29 libsystem_pthread.dylib 0x00007fff6fe4f2eb _pthread_body + 126)TRACE",
true, "_pthread_body");
}

} // end namespace kaldi.
} // namespace kaldi

int main() {
kaldi::TestLocateSymbolRange();

kaldi::SetProgramName("/foo/bar/kaldi-error-test");
try {
kaldi::UnitTestError();
KALDI_ASSERT(0); // should not happen.
KALDI_ASSERT(0); // should not happen.
exit(1);
} catch(kaldi::KaldiFatalError &e) {
} catch (kaldi::KaldiFatalError &e) {
std::cout << "The error we generated was: '" << e.KaldiMessage() << "'\n";
}
}
116 changes: 70 additions & 46 deletions src/base/kaldi-error.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
// base/kaldi-error.cc

// Copyright 2019 LAIX (Yi Sun)
// Copyright 2019 SmartAction LLC (kkm)
// Copyright 2016 Brno University of Technology (author: Karel Vesely)
// Copyright 2009-2011 Microsoft Corporation; Lukas Burget; Ondrej Glembek
Expand All @@ -20,23 +21,22 @@
// limitations under the License.

#ifdef HAVE_EXECINFO_H
#include <execinfo.h> // To get stack trace in error messages.
#include <execinfo.h> // To get stack trace in error messages.
// If this #include fails there is an error in the Makefile, it does not
// support your platform well. Make sure HAVE_EXECINFO_H is undefined,
// and the code will compile.
#ifdef HAVE_CXXABI_H
#include <cxxabi.h> // For name demangling.
#include <cxxabi.h> // For name demangling.
// Useful to decode the stack trace, but only used if we have execinfo.h
#endif // HAVE_CXXABI_H
#endif // HAVE_EXECINFO_H
#endif // HAVE_CXXABI_H
#endif // HAVE_EXECINFO_H

#include "base/kaldi-common.h"
#include "base/kaldi-error.h"
#include "base/version.h"

namespace kaldi {


/***** GLOBAL VARIABLES FOR LOGGING *****/

int32 g_kaldi_verbose_level = 0;
Expand All @@ -51,7 +51,6 @@ void SetProgramName(const char *basename) {
program_name = basename;
}


/***** HELPER FUNCTIONS *****/

// Trim filename to at most 1 trailing directory long. Given a filename like
Expand All @@ -70,40 +69,68 @@ static const char *GetShortFileName(const char *path) {
return prev;
}


/***** STACK TRACE *****/

namespace internal {
bool LocateSymbolRange(const std::string &trace_name, size_t *begin,
size_t *end) {
// Find the first '_' with leading ' ' or '('.
*begin = std::string::npos;
for (size_t i = 1; i < trace_name.size(); i++) {
if (trace_name[i] != '_') {
continue;
}
if (trace_name[i - 1] == ' ' || trace_name[i - 1] == '(') {
*begin = i;
break;
}
}
if (*begin == std::string::npos) {
return false;
}
*end = trace_name.find_first_of(" +", *begin);
return *end != std::string::npos;
}
} // namespace internal

#ifdef HAVE_EXECINFO_H
static std::string Demangle(std::string trace_name) {
#ifdef HAVE_CXXABI_H
// At input the string looks like:
#ifndef HAVE_CXXABI_H
return trace_name;
#else // HAVE_CXXABI_H
// Try demangle the symbol. We are trying to support the following formats
// produced by different platforms:
//
// Linux:
// ./kaldi-error-test(_ZN5kaldi13UnitTestErrorEv+0xb) [0x804965d]
// We want to extract the name e.g. '_ZN5kaldi13UnitTestErrorEv"
// and demangle it.

// Try to locate '(' and '+', take the string in between.
size_t begin(trace_name.find("(")),
end(trace_name.rfind("+"));
if (begin != std::string::npos && end != std::string::npos && begin < end) {
trace_name = trace_name.substr(begin + 1, end - (begin + 1));
//
// Mac:
// 0 server 0x000000010f67614d _ZNK5kaldi13MessageLogger10LogMessageEv + 813
//
// We want to extract the name e.g., '_ZN5kaldi13UnitTestErrorEv' and
// demangle it info a readable name like kaldi::UnitTextError.
size_t begin, end;
if (!internal::LocateSymbolRange(trace_name, &begin, &end)) {
return trace_name;
}
// Try to demangle function name.
std::string symbol = trace_name.substr(begin, end - begin);
int status;
char *demangled_name = abi::__cxa_demangle(trace_name.c_str(), 0, 0, &status);
if (status == 0 && demangled_name != NULL) {
trace_name = demangled_name;
char *demangled_name = abi::__cxa_demangle(symbol.c_str(), 0, 0, &status);
if (status == 0 && demangled_name != nullptr) {
symbol = demangled_name;
free(demangled_name);
}
#endif // HAVE_CXXABI_H
return trace_name;
return trace_name.substr(0, begin) + symbol +
trace_name.substr(end, std::string::npos);
#endif // HAVE_CXXABI_H
}
#endif // HAVE_EXECINFO_H
#endif // HAVE_EXECINFO_H

static std::string KaldiGetStackTrace() {
std::string ans;
#ifdef HAVE_EXECINFO_H
const size_t KALDI_MAX_TRACE_SIZE = 50;
const size_t KALDI_MAX_TRACE_PRINT = 20; // Must be even.
const size_t KALDI_MAX_TRACE_PRINT = 50; // Must be even.
// Buffer for the trace.
void *trace[KALDI_MAX_TRACE_SIZE];
// Get the trace.
Expand All @@ -119,34 +146,33 @@ static std::string KaldiGetStackTrace() {
for (size_t i = 0; i < size; i++) {
ans += Demangle(trace_symbol[i]) + "\n";
}
} else { // Print out first+last (e.g.) 5.
for (size_t i = 0; i < KALDI_MAX_TRACE_PRINT/2; i++) {
} else { // Print out first+last (e.g.) 5.
for (size_t i = 0; i < KALDI_MAX_TRACE_PRINT / 2; i++) {
ans += Demangle(trace_symbol[i]) + "\n";
}
ans += ".\n.\n.\n";
for (size_t i = size - KALDI_MAX_TRACE_PRINT/2; i < size; i++) {
for (size_t i = size - KALDI_MAX_TRACE_PRINT / 2; i < size; i++) {
ans += Demangle(trace_symbol[i]) + "\n";
}
if (size == KALDI_MAX_TRACE_SIZE)
ans += ".\n.\n.\n"; // Stack was too long, probably a bug.
ans += ".\n.\n.\n"; // Stack was too long, probably a bug.
}

// We must free the array of pointers allocated by backtrace_symbols(),
// but not the strings themselves.
free(trace_symbol);
#endif // HAVE_EXECINFO_H
#endif // HAVE_EXECINFO_H
return ans;
}


/***** KALDI LOGGING *****/

MessageLogger::MessageLogger(LogMessageEnvelope::Severity severity,
const char *func, const char *file, int32 line) {
// Obviously, we assume the strings survive the destruction of this object.
envelope_.severity = severity;
envelope_.func = func;
envelope_.file = GetShortFileName(file); // Points inside 'file'.
envelope_.file = GetShortFileName(file); // Points inside 'file'.
envelope_.line = line;
}

Expand All @@ -164,29 +190,29 @@ void MessageLogger::LogMessage() const {
full_message << "VLOG[" << envelope_.severity << "] (";
} else {
switch (envelope_.severity) {
case LogMessageEnvelope::kInfo :
case LogMessageEnvelope::kInfo:
full_message << "LOG (";
break;
case LogMessageEnvelope::kWarning :
case LogMessageEnvelope::kWarning:
full_message << "WARNING (";
break;
case LogMessageEnvelope::kAssertFailed :
case LogMessageEnvelope::kAssertFailed:
full_message << "ASSERTION_FAILED (";
break;
case LogMessageEnvelope::kError :
default: // If not the ERROR, it still an error!
case LogMessageEnvelope::kError:
default: // If not the ERROR, it still an error!
full_message << "ERROR (";
break;
}
}
// Add other info from the envelope and the message text.
full_message << program_name.c_str() << "[" KALDI_VERSION "]" << ':'
<< envelope_.func << "():" << envelope_.file << ':'
<< envelope_.func << "():" << envelope_.file << ':'
<< envelope_.line << ") " << GetMessage().c_str();

// Add stack trace for errors and assertion failures, if available.
if (envelope_.severity < LogMessageEnvelope::kWarning) {
const std::string& stack_trace = KaldiGetStackTrace();
const std::string &stack_trace = KaldiGetStackTrace();
if (!stack_trace.empty()) {
full_message << "\n\n" << stack_trace;
}
Expand All @@ -197,19 +223,17 @@ void MessageLogger::LogMessage() const {
std::cerr << full_message.str();
}


/***** KALDI ASSERTS *****/

void KaldiAssertFailure_(const char *func, const char *file,
int32 line, const char *cond_str) {
void KaldiAssertFailure_(const char *func, const char *file, int32 line,
const char *cond_str) {
MessageLogger::Log() =
MessageLogger (LogMessageEnvelope::kAssertFailed, func, file, line)
MessageLogger(LogMessageEnvelope::kAssertFailed, func, file, line)
<< "Assertion failed: (" << cond_str << ")";
fflush(NULL); // Flush all pending buffers, abort() may not flush stderr.
fflush(NULL); // Flush all pending buffers, abort() may not flush stderr.
std::abort();
}


/***** THIRD-PARTY LOG-HANDLER *****/

LogHandler SetLogHandler(LogHandler handler) {
Expand All @@ -218,4 +242,4 @@ LogHandler SetLogHandler(LogHandler handler) {
return old_handler;
}

} // namespace kaldi
} // namespace kaldi
Loading