1berry/qtbase
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Fix qSetMessagePattern to have many time/backtrace parts

Browse Source 
The previous implementation overwrote multiple 'time' parts in the
qSetMessagePattern with the last setting in the pattern line.
%{time}%{time process}%{time boot} ended up to be output as if
%{time boot}%{time boot}%{time boot} was set.

This fix keeps the arguments of each individual 'time' part.

The same holds for multiple 'backtrace' parts. The previouse
implementation overwrote multiple 'backtrace' arguments with the
arguments of the last occurrence.

This fix keeps the individual arguments for the 'process' parts.

The individual arguments are applied in qFormatLogMessage.

A new test to verify the individual 'time' arguments application
is added, too.

Task-number: QTBUG-51944
Change-Id: Ib757614a482c5f31ed0a61b550daa2eea4b907b4
Reviewed-by: Olivier Goffart (Woboq GmbH) <ogoffart@woboq.com>
This commit is contained in:
M. Moellney 2016-03-19 22:00:32 +01:00 committed by Michael Möllney
parent 2e385b3d74
commit 705d29585b
2 changed files with 60 additions and 20 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

69
src/corelib/global/qlogging.cpp
View File

@ -980,13 +980,16 @@ struct QMessagePattern {
// 0 terminated arrays of literal tokens / literal or placeholder tokens // 0 terminated arrays of literal tokens / literal or placeholder tokens
const char **literals; const char **literals;
const char **tokens; const char **tokens;
QString timeFormat; QList<QString> timeArgs; // timeFormats in sequence of %{time
#ifndef QT_BOOTSTRAPPED #ifndef QT_BOOTSTRAPPED
QElapsedTimer timer; QElapsedTimer timer;
#endif #endif
#ifdef QLOGGING_HAVE_BACKTRACE #ifdef QLOGGING_HAVE_BACKTRACE
QString backtraceSeparator; struct BacktraceParams {
int backtraceDepth; QString backtraceSeparator;
int backtraceDepth;
};
QList<BacktraceParams> backtraceArgs; // backtrace argumens in sequence of %{backtrace
#endif #endif
bool fromEnvironment; bool fromEnvironment;
@ -998,10 +1001,6 @@ QBasicMutex QMessagePattern::mutex;
QMessagePattern::QMessagePattern() QMessagePattern::QMessagePattern()
: literals(0) : literals(0)
, tokens(0) , tokens(0)
#ifdef QLOGGING_HAVE_BACKTRACE
, backtraceSeparator(QLatin1Char('|'))
, backtraceDepth(5)
#endif
, fromEnvironment(false) , fromEnvironment(false)
{ {
#ifndef QT_BOOTSTRAPPED #ifndef QT_BOOTSTRAPPED
@ -1104,10 +1103,14 @@ void QMessagePattern::setPattern(const QString &pattern)
tokens[i] = timeTokenC; tokens[i] = timeTokenC;
int spaceIdx = lexeme.indexOf(QChar::fromLatin1(' ')); int spaceIdx = lexeme.indexOf(QChar::fromLatin1(' '));
if (spaceIdx > 0) if (spaceIdx > 0)
timeFormat = lexeme.mid(spaceIdx + 1, lexeme.length() - spaceIdx - 2); timeArgs.append(lexeme.mid(spaceIdx + 1, lexeme.length() - spaceIdx - 2));
else
timeArgs.append(QString());
} else if (lexeme.startsWith(QLatin1String(backtraceTokenC))) { } else if (lexeme.startsWith(QLatin1String(backtraceTokenC))) {
#ifdef QLOGGING_HAVE_BACKTRACE #ifdef QLOGGING_HAVE_BACKTRACE
tokens[i] = backtraceTokenC; tokens[i] = backtraceTokenC;
QString backtraceSeparator = QStringLiteral("|");
int backtraceDepth = 5;
QRegularExpression depthRx(QStringLiteral(" depth=(?|\"([^\"]*)\"|([^ }]*))")); QRegularExpression depthRx(QStringLiteral(" depth=(?|\"([^\"]*)\"|([^ }]*))"));
QRegularExpression separatorRx(QStringLiteral(" separator=(?|\"([^\"]*)\"|([^ }]*))")); QRegularExpression separatorRx(QStringLiteral(" separator=(?|\"([^\"]*)\"|([^ }]*))"));
QRegularExpressionMatch m = depthRx.match(lexeme); QRegularExpressionMatch m = depthRx.match(lexeme);
@ -1121,6 +1124,10 @@ void QMessagePattern::setPattern(const QString &pattern)
m = separatorRx.match(lexeme); m = separatorRx.match(lexeme);
if (m.hasMatch()) if (m.hasMatch())
backtraceSeparator = m.captured(1); backtraceSeparator = m.captured(1);
BacktraceParams backtraceParams;
backtraceParams.backtraceDepth = backtraceDepth;
backtraceParams.backtraceSeparator = backtraceSeparator;
backtraceArgs.append(backtraceParams);
#else #else
error += QStringLiteral("QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build\n"); error += QStringLiteral("QT_MESSAGE_PATTERN: %{backtrace} is not supported by this Qt build\n");
#endif #endif
@ -1263,13 +1270,29 @@ QString qFormatLogMessage(QtMsgType type, const QMessageLogContext &context, con
bool skip = false; bool skip = false;
#ifndef QT_BOOTSTRAPPED
int timeArgsIdx = 0;
#ifdef QLOGGING_HAVE_BACKTRACE
int backtraceArgsIdx = 0;
#endif
#endif
// we do not convert file, function, line literals to local encoding due to overhead // we do not convert file, function, line literals to local encoding due to overhead
for (int i = 0; pattern->tokens[i] != 0; ++i) { for (int i = 0; pattern->tokens[i] != 0; ++i) {
const char *token = pattern->tokens[i]; const char *token = pattern->tokens[i];
if (token == endifTokenC) { if (token == endifTokenC) {
skip = false; skip = false;
} else if (skip) { } else if (skip) {
// do nothing // we skip adding messages, but we have to iterate over
// timeArgsIdx and backtraceArgsIdx anyway
#ifndef QT_BOOTSTRAPPED
if (token == timeTokenC)
timeArgsIdx++;
#ifdef QLOGGING_HAVE_BACKTRACE
else if (token == backtraceTokenC)
backtraceArgsIdx++;
#endif
#endif
} else if (token == messageTokenC) { } else if (token == messageTokenC) {
message.append(str); message.append(str);
} else if (token == categoryTokenC) { } else if (token == categoryTokenC) {
@ -1307,11 +1330,15 @@ QString qFormatLogMessage(QtMsgType type, const QMessageLogContext &context, con
message.append(QString::number(qlonglong(QThread::currentThread()->currentThread()), 16)); message.append(QString::number(qlonglong(QThread::currentThread()->currentThread()), 16));
#ifdef QLOGGING_HAVE_BACKTRACE #ifdef QLOGGING_HAVE_BACKTRACE
} else if (token == backtraceTokenC) { } else if (token == backtraceTokenC) {
QVarLengthArray<void*, 32> buffer(7 + pattern->backtraceDepth); QMessagePattern::BacktraceParams backtraceParams = pattern->backtraceArgs.at(backtraceArgsIdx);
QString backtraceSeparator = backtraceParams.backtraceSeparator;
int backtraceDepth = backtraceParams.backtraceDepth;
backtraceArgsIdx++;
QVarLengthArray<void*, 32> buffer(7 + backtraceDepth);
int n = backtrace(buffer.data(), buffer.size()); int n = backtrace(buffer.data(), buffer.size());
if (n > 0) { if (n > 0) {
int numberPrinted = 0; int numberPrinted = 0;
for (int i = 0; i < n && numberPrinted < pattern->backtraceDepth; ++i) { for (int i = 0; i < n && numberPrinted < backtraceDepth; ++i) {
QScopedPointer<char*, QScopedPointerPodDeleter> strings(backtrace_symbols(buffer.data() + i, 1)); QScopedPointer<char*, QScopedPointerPodDeleter> strings(backtrace_symbols(buffer.data() + i, 1));
QString trace = QString::fromLatin1(strings.data()[0]); QString trace = QString::fromLatin1(strings.data()[0]);
// The results of backtrace_symbols looks like this: // The results of backtrace_symbols looks like this:
@ -1341,7 +1368,7 @@ QString qFormatLogMessage(QtMsgType type, const QMessageLogContext &context, con
} }
if (numberPrinted > 0) if (numberPrinted > 0)
message.append(pattern->backtraceSeparator); message.append(backtraceSeparator);
if (function.isEmpty()) { if (function.isEmpty()) {
if (numberPrinted == 0 && context.function) if (numberPrinted == 0 && context.function)
@ -1355,27 +1382,29 @@ QString qFormatLogMessage(QtMsgType type, const QMessageLogContext &context, con
} else { } else {
if (numberPrinted == 0) if (numberPrinted == 0)
continue; continue;
message += pattern->backtraceSeparator + QLatin1String("???"); message += backtraceSeparator + QLatin1String("???");
} }
numberPrinted++; numberPrinted++;
} }
} }
#endif #endif
} else if (token == timeTokenC) { } else if (token == timeTokenC) {
if (pattern->timeFormat == QLatin1String("process")) { QString timeFormat = pattern->timeArgs.at(timeArgsIdx);
quint64 ms = pattern->timer.elapsed(); timeArgsIdx++;
message.append(QString::asprintf("%6d.%03d", uint(ms / 1000), uint(ms % 1000))); if (timeFormat == QLatin1String("process")) {
} else if (pattern->timeFormat == QLatin1String("boot")) { quint64 ms = pattern->timer.elapsed();
message.append(QString::asprintf("%6d.%03d", uint(ms / 1000), uint(ms % 1000)));
} else if (timeFormat == QLatin1String("boot")) {
// just print the milliseconds since the elapsed timer reference // just print the milliseconds since the elapsed timer reference
// like the Linux kernel does // like the Linux kernel does
QElapsedTimer now; QElapsedTimer now;
now.start(); now.start();
uint ms = now.msecsSinceReference(); uint ms = now.msecsSinceReference();
message.append(QString::asprintf("%6d.%03d", uint(ms / 1000), uint(ms % 1000))); message.append(QString::asprintf("%6d.%03d", uint(ms / 1000), uint(ms % 1000)));
} else if (pattern->timeFormat.isEmpty()) { } else if (timeFormat.isEmpty()) {
message.append(QDateTime::currentDateTime().toString(Qt::ISODate)); message.append(QDateTime::currentDateTime().toString(Qt::ISODate));
} else { } else {
message.append(QDateTime::currentDateTime().toString(pattern->timeFormat)); message.append(QDateTime::currentDateTime().toString(timeFormat));
} }
#endif #endif
} else if (token == ifCategoryTokenC) { } else if (token == ifCategoryTokenC) {

11
tests/auto/corelib/global/qlogging/tst_qlogging.cpp
View File

@ -779,6 +779,17 @@ void tst_qmessagehandler::qMessagePattern_data()
<< true << (QList<QByteArray>() << true << (QList<QByteArray>()
<< ('/' + QDateTime::currentDateTime().toString("yyyy - MM - d").toUtf8() + "/qDebug")); << ('/' + QDateTime::currentDateTime().toString("yyyy - MM - d").toUtf8() + "/qDebug"));
QTest::newRow("time-time") << "/%{time yyyy - MM - d}/%{time dd-MM-yy}/%{message}"
<< true << (QList<QByteArray>()
<< ('/' + QDateTime::currentDateTime().toString("yyyy - MM - d").toUtf8()
+ '/' + QDateTime::currentDateTime().toString("dd-MM-yy").toUtf8()
+ "/qDebug"));
QTest::newRow("skipped-time-shown-time")
<< "/%{if-warning}%{time yyyy - MM - d}%{endif}%{if-debug}%{time dd-MM-yy}%{endif}/%{message}"
<< true << (QList<QByteArray>()
<< ('/' + QDateTime::currentDateTime().toString("dd-MM-yy").toUtf8() + "/qDebug"));
// %{time} should have a padding of 6 so if it takes less than 10 seconds to show // %{time} should have a padding of 6 so if it takes less than 10 seconds to show
// the first message, there should be 5 spaces // the first message, there should be 5 spaces
QTest::newRow("time-process") << "<%{time process}>%{message}" << true << (QList<QByteArray>() QTest::newRow("time-process") << "<%{time process}>%{message}" << true << (QList<QByteArray>()