Logging: support %{backtrace} in QT_MESSAGE_PATTERN
On supported platform, allow to show a backtrace by using
%{backtrace} or %{backtrace depth=N separator="|"}
[ChangeLog][QtCore][Logging] QT_MESSAGE_PATTERN can include a
backtrace using %{backtrace}
Change-Id: Ib00418c070d3bd6fe846dc04bf69fa91ba64f9cd
Reviewed-by: Kai Koehne <kai.koehne@digia.com>
This commit is contained in:
Olivier Goffart
parent
04b92bfa1a
commit
9f598d5ee9
@ -1,6 +1,7 @@
|
||||
/****************************************************************************
|
||||
**
|
||||
** Copyright (C) 2013 Digia Plc and/or its subsidiary(-ies).
|
||||
** Copyright (C) 2014 Olivier Goffart <ogoffart@woboq.com>
|
||||
** Contact: http://www.qt-project.org/legal
|
||||
**
|
||||
** This file is part of the QtCore module of the Qt Toolkit.
|
||||
@ -72,6 +73,22 @@
|
||||
# include <unistd.h>
|
||||
#endif
|
||||
|
||||
#if !defined QT_NO_REGULAREXPRESSION && !defined(QT_BOOTSTRAPPED)
|
||||
#ifdef __has_include
|
||||
#if __has_include(<cxxabi.h>) && __has_include(<execinfo.h>)
|
||||
#define QLOGGING_HAVE_BACKTRACE
|
||||
#endif
|
||||
#elif defined(__GLIBCXX__) && defined(__GLIBC__) // (because older version of gcc don't have __has_include)
|
||||
#define QLOGGING_HAVE_BACKTRACE
|
||||
#endif
|
||||
|
||||
#ifdef QLOGGING_HAVE_BACKTRACE
|
||||
#include <qregularexpression.h>
|
||||
#include <cxxabi.h>
|
||||
#include <execinfo.h>
|
||||
#endif
|
||||
#endif
|
||||
|
||||
#include <stdio.h>
|
||||
|
||||
QT_BEGIN_NAMESPACE
|
||||
@ -763,6 +780,7 @@ static const char pidTokenC[] = "%{pid}";
|
||||
static const char appnameTokenC[] = "%{appname}";
|
||||
static const char threadidTokenC[] = "%{threadid}";
|
||||
static const char timeTokenC[] = "%{time"; //not a typo: this command has arguments
|
||||
static const char backtraceTokenC[] = "%{backtrace"; //ditto
|
||||
static const char ifCategoryTokenC[] = "%{if-category}";
|
||||
static const char ifDebugTokenC[] = "%{if-debug}";
|
||||
static const char ifWarningTokenC[] = "%{if-warning}";
|
||||
@ -784,6 +802,10 @@ struct QMessagePattern {
|
||||
const char **literals;
|
||||
const char **tokens;
|
||||
QString timeFormat;
|
||||
#ifdef QLOGGING_HAVE_BACKTRACE
|
||||
int backtraceDepth;
|
||||
QString backtraceSeparator;
|
||||
#endif
|
||||
|
||||
bool fromEnvironment;
|
||||
static QBasicMutex mutex;
|
||||
@ -798,6 +820,10 @@ QBasicMutex QMessagePattern::mutex;
|
||||
QMessagePattern::QMessagePattern()
|
||||
: literals(0)
|
||||
, tokens(0)
|
||||
#ifdef QLOGGING_HAVE_BACKTRACE
|
||||
, backtraceDepth(5)
|
||||
, backtraceSeparator(QLatin1Char('|'))
|
||||
#endif
|
||||
, fromEnvironment(false)
|
||||
#ifndef QT_BOOTSTRAPPED
|
||||
, startTime(QDateTime::currentDateTime())
|
||||
@ -898,6 +924,25 @@ void QMessagePattern::setPattern(const QString &pattern)
|
||||
int spaceIdx = lexeme.indexOf(QChar::fromLatin1(' '));
|
||||
if (spaceIdx > 0)
|
||||
timeFormat = lexeme.mid(spaceIdx + 1, lexeme.length() - spaceIdx - 2);
|
||||
} else if (lexeme.startsWith(QLatin1String(backtraceTokenC))) {
|
||||
#ifdef QLOGGING_HAVE_BACKTRACE
|
||||
tokens[i] = backtraceTokenC;
|
||||
QRegularExpression depthRx(QStringLiteral(" depth=(?|\"([^\"]*)\"|([^ }]*))"));
|
||||
QRegularExpression separatorRx(QStringLiteral(" separator=(?|\"([^\"]*)\"|([^ }]*))"));
|
||||
QRegularExpressionMatch m = depthRx.match(lexeme);
|
||||
if (m.hasMatch()) {
|
||||
int depth = m.capturedRef(1).toInt();
|
||||
if (depth <= 0)
|
||||
error += QStringLiteral("QT_MESSAGE_PATTERN: %{backtrace} depth must be a number greater than 0\n");
|
||||
else
|
||||
backtraceDepth = depth;
|
||||
}
|
||||
m = separatorRx.match(lexeme);
|
||||
if (m.hasMatch())
|
||||
backtraceSeparator = m.captured(1);
|
||||
#else
|
||||
error += QStringLiteral("QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build\n");
|
||||
#endif
|
||||
}
|
||||
|
||||
#define IF_TOKEN(LEVEL) \
|
||||
@ -1068,6 +1113,58 @@ Q_CORE_EXPORT QString qMessageFormatString(QtMsgType type, const QMessageLogCont
|
||||
} else if (token == threadidTokenC) {
|
||||
message.append(QLatin1String("0x"));
|
||||
message.append(QString::number(qlonglong(QThread::currentThread()->currentThread()), 16));
|
||||
#ifdef QLOGGING_HAVE_BACKTRACE
|
||||
} else if (token == backtraceTokenC) {
|
||||
QVarLengthArray<void*, 32> buffer(15 + pattern->backtraceDepth);
|
||||
int n = backtrace(buffer.data(), buffer.size());
|
||||
if (n > 0) {
|
||||
QScopedPointer<char*, QScopedPointerPodDeleter> strings(backtrace_symbols(buffer.data(), n));
|
||||
int numberPrinted = 0;
|
||||
for (int i = 0; i < n && numberPrinted < pattern->backtraceDepth; ++i) {
|
||||
QString trace = QString::fromLatin1(strings.data()[i]);
|
||||
// The results of backtrace_symbols looks like this:
|
||||
// /lib/libc.so.6(__libc_start_main+0xf3) [0x4a937413]
|
||||
// The offset and function name are optional.
|
||||
// This regexp tries to extract the librry name (without the path) and the function name.
|
||||
// This code is protected by QMessagePattern::mutex so it is thread safe on all compilers
|
||||
static QRegularExpression rx(QStringLiteral("^(?:[^(]*/)?([^(/]+)\\(([^+]*)(?:[\\+[a-f0-9x]*)?\\) \\[[a-f0-9x]*\\]$"),
|
||||
QRegularExpression::OptimizeOnFirstUsageOption);
|
||||
|
||||
QRegularExpressionMatch m = rx.match(trace);
|
||||
if (m.hasMatch()) {
|
||||
// skip the trace from QtCore that are because of the qDebug itself
|
||||
QString library = m.captured(1);
|
||||
QString function = m.captured(2);
|
||||
if (!numberPrinted && library.contains(QLatin1String("Qt5Core"))
|
||||
&& (function.isEmpty() || function.contains(QLatin1String("Message"), Qt::CaseInsensitive)
|
||||
|| function.contains(QLatin1String("QDebug")))) {
|
||||
continue;
|
||||
}
|
||||
|
||||
if (function.startsWith(QLatin1String("_Z"))) {
|
||||
QScopedPointer<char, QScopedPointerPodDeleter> demangled(
|
||||
abi::__cxa_demangle(function.toUtf8(), 0, 0, 0));
|
||||
if (demangled)
|
||||
function = QString::fromUtf8(qCleanupFuncinfo(demangled.data()));
|
||||
}
|
||||
|
||||
if (numberPrinted > 0)
|
||||
message.append(pattern->backtraceSeparator);
|
||||
|
||||
if (function.isEmpty())
|
||||
message += QLatin1Char('?') + library + QLatin1Char('?');
|
||||
else
|
||||
message += function;
|
||||
|
||||
} else {
|
||||
if (numberPrinted == 0)
|
||||
continue;
|
||||
message += pattern->backtraceSeparator + QLatin1String("???");
|
||||
}
|
||||
numberPrinted++;
|
||||
}
|
||||
}
|
||||
#endif
|
||||
} else if (token == timeTokenC) {
|
||||
quint64 ms = pattern->timer.elapsed();
|
||||
if (pattern->timeFormat.isEmpty())
|
||||
@ -1458,6 +1555,14 @@ void qErrnoWarning(int code, const char *msg, ...)
|
||||
\row \li \c %{time} \li time of the message, in seconds since the process started
|
||||
\row \li \c %{time format} \li system time when the message occurred, formatted by
|
||||
passing the \c format to \l QDateTime::toString()
|
||||
\row \li \c{%{backtrace [depth=N] [separator="..."]}} \li A backtrace with the number of frames
|
||||
specified by the optional \c depth parameter (defaults to 5), and separated by the optional
|
||||
\c separator parameter (defaults to "|").
|
||||
This expansion is available only on some platforms (currently only platfoms using glibc).
|
||||
Names are only known for exported functions. If you want to see the name of every function
|
||||
in your application, use \c{QMAKE_LFLAGS += -rdynamic}.
|
||||
When reading backtraces, take into account that frames might be missing due to inlining or
|
||||
tail call optimization.
|
||||
\endtable
|
||||
|
||||
You can also use conditionals on the type of the message using \c %{if-debug},
|
||||
|
||||
@ -10,3 +10,6 @@ CONFIG += console
|
||||
|
||||
SOURCES += main.cpp
|
||||
DEFINES += QT_DISABLE_DEPRECATED_BEFORE=0
|
||||
|
||||
gcc:!mingw: QMAKE_LFLAGS += -rdynamic
|
||||
|
||||
|
||||
@ -42,11 +42,37 @@
|
||||
#include <QCoreApplication>
|
||||
#include <QLoggingCategory>
|
||||
|
||||
#ifdef Q_CC_GNU
|
||||
#define NEVER_INLINE __attribute__((__noinline__))
|
||||
#else
|
||||
#define NEVER_INLINE
|
||||
#endif
|
||||
|
||||
struct T {
|
||||
T() { qDebug("static constructor"); }
|
||||
~T() { qDebug("static destructor"); }
|
||||
} t;
|
||||
|
||||
class MyClass : public QObject
|
||||
{
|
||||
Q_OBJECT
|
||||
public slots:
|
||||
virtual NEVER_INLINE QString mySlot1();
|
||||
private:
|
||||
virtual NEVER_INLINE void myFunction(int a);
|
||||
};
|
||||
|
||||
QString MyClass::mySlot1()
|
||||
{
|
||||
myFunction(34);
|
||||
return QString();
|
||||
}
|
||||
|
||||
void MyClass::myFunction(int a)
|
||||
{
|
||||
qDebug() << "from_a_function" << a;
|
||||
}
|
||||
|
||||
int main(int argc, char **argv)
|
||||
{
|
||||
QCoreApplication app(argc, argv);
|
||||
@ -65,5 +91,10 @@ int main(int argc, char **argv)
|
||||
|
||||
qDebug("qDebug2");
|
||||
|
||||
MyClass cl;
|
||||
QMetaObject::invokeMethod(&cl, "mySlot1");
|
||||
|
||||
return 0;
|
||||
}
|
||||
|
||||
#include "main.moc"
|
||||
|
||||
@ -1,6 +1,7 @@
|
||||
/****************************************************************************
|
||||
**
|
||||
** Copyright (C) 2013 Digia Plc and/or its subsidiary(-ies).
|
||||
** Copyright (C) 2014 Olivier Goffart <ogoffart@woboq.com>
|
||||
** Contact: http://www.qt-project.org/legal
|
||||
**
|
||||
** This file is part of the test suite of the Qt Toolkit.
|
||||
@ -650,14 +651,15 @@ void tst_qmessagehandler::qMessagePattern_data()
|
||||
|
||||
// %{file} is tricky because of shadow builds
|
||||
QTest::newRow("basic") << "%{type} %{appname} %{line} %{function} %{message}" << true << (QList<QByteArray>()
|
||||
<< "debug 46 T::T static constructor"
|
||||
<< "debug 52 T::T static constructor"
|
||||
// we can't be sure whether the QT_MESSAGE_PATTERN is already destructed
|
||||
<< "static destructor"
|
||||
<< "debug tst_qlogging 57 main qDebug"
|
||||
<< "warning tst_qlogging 58 main qWarning"
|
||||
<< "critical tst_qlogging 59 main qCritical"
|
||||
<< "warning tst_qlogging 62 main qDebug with category"
|
||||
<< "debug tst_qlogging 66 main qDebug2");
|
||||
<< "debug tst_qlogging 73 MyClass::myFunction from_a_function 34"
|
||||
<< "debug tst_qlogging 83 main qDebug"
|
||||
<< "warning tst_qlogging 84 main qWarning"
|
||||
<< "critical tst_qlogging 85 main qCritical"
|
||||
<< "warning tst_qlogging 88 main qDebug with category"
|
||||
<< "debug tst_qlogging 92 main qDebug2");
|
||||
|
||||
|
||||
QTest::newRow("invalid") << "PREFIX: %{unknown} %{message}" << false << (QList<QByteArray>()
|
||||
@ -701,6 +703,23 @@ void tst_qmessagehandler::qMessagePattern_data()
|
||||
QTest::newRow("time") << "<%{time}>%{message}" << true << (QList<QByteArray>()
|
||||
<< "< ");
|
||||
|
||||
#ifdef __GLIBC__
|
||||
#ifdef QT_NAMESPACE
|
||||
#define QT_NAMESPACE_STR QT_STRINGIFY(QT_NAMESPACE::)
|
||||
#else
|
||||
#define QT_NAMESPACE_STR ""
|
||||
#endif
|
||||
|
||||
#ifndef QT_NO_DEBUG
|
||||
QTest::newRow("backtrace") << "[%{backtrace}] %{message}" << true << (QList<QByteArray>()
|
||||
// MyClass::qt_static_metacall is explicitly marked as hidden in the Q_OBJECT macro
|
||||
<< "[MyClass::myFunction|MyClass::mySlot1|?app?|" QT_NAMESPACE_STR "QMetaMethod::invoke|" QT_NAMESPACE_STR "QMetaObject::invokeMethod] from_a_function 34");
|
||||
#endif
|
||||
|
||||
QTest::newRow("backtrace depth,separator") << "[%{backtrace depth=2 separator=\"\n\"}] %{message}" << true << (QList<QByteArray>()
|
||||
<< "[MyClass::myFunction\nMyClass::mySlot1] from_a_function 34");
|
||||
#endif
|
||||
|
||||
}
|
||||
|
||||
|
||||
@ -734,7 +753,11 @@ void tst_qmessagehandler::qMessagePattern()
|
||||
QCOMPARE(!output.contains("QT_MESSAGE_PATTERN"), valid);
|
||||
|
||||
foreach (const QByteArray &e, expected) {
|
||||
QVERIFY(output.contains(e));
|
||||
if (!output.contains(e)) {
|
||||
qDebug() << output;
|
||||
qDebug() << "expected: " << e;
|
||||
QVERIFY(output.contains(e));
|
||||
}
|
||||
}
|
||||
#endif
|
||||
}
|
||||
|
||||
Loading…
Reference in New Issue
Block a user