From 398e27f8907362b598fe1dfe2ecbf76bcbe530c4 Mon Sep 17 00:00:00 2001 From: Kai Koehne Date: Mon, 16 Jan 2012 15:40:27 +0100 Subject: [PATCH] Console API: Add console.count console.count can be handy to check how often code snippets are executed. Change-Id: I0eaf17ab893c76e7b8956122aa31e218745e92bf Reviewed-by: Kai Koehne --- doc/src/declarative/qdeclarativedebugging.qdoc | 13 +++++ .../qml/v8/qdeclarativebuiltinfunctions.cpp | 55 +++++++++++++++++----- .../qml/v8/qdeclarativebuiltinfunctions_p.h | 1 + src/declarative/qml/v8/qv8engine.cpp | 10 ++++ src/declarative/qml/v8/qv8engine_p.h | 5 ++ .../debugger/qdebugmessageservice/data/test.qml | 1 + .../tst_qdebugmessageservice.cpp | 48 +++++++++++++++---- .../qdeclarativeconsole/data/logging.qml | 9 ++++ .../tst_qdeclarativeconsole.cpp | 6 ++- 9 files changed, 125 insertions(+), 23 deletions(-) diff --git a/doc/src/declarative/qdeclarativedebugging.qdoc b/doc/src/declarative/qdeclarativedebugging.qdoc index d8e7842..c59952d 100644 --- a/doc/src/declarative/qdeclarativedebugging.qdoc +++ b/doc/src/declarative/qdeclarativedebugging.qdoc @@ -71,6 +71,19 @@ function f() { it was called. The stack trace info contains function name, file name, line number and column number. The stack trace is limited to last 10 stack frames. +\section2 Count + +\c console.count prints the current number of times a particular piece of code has been executed, +along with a message. That is, + +\qml +function f() { + console.count("f called"); +} +\endqml + +will print \c{f called: 1}, \c{f called: 2} ... whenever \c{f()} is executed. + \section2 Profile \c console.profile turns on the QML and JavaScript profilers. Nested calls are not diff --git a/src/declarative/qml/v8/qdeclarativebuiltinfunctions.cpp b/src/declarative/qml/v8/qdeclarativebuiltinfunctions.cpp index 2e258b3..a77c8a0 100644 --- a/src/declarative/qml/v8/qdeclarativebuiltinfunctions.cpp +++ b/src/declarative/qml/v8/qdeclarativebuiltinfunctions.cpp @@ -80,6 +80,20 @@ enum ConsoleLogTypes { Error }; +static QString extendMessage(const QString &msg) { + if (qmlConsoleExtended()) { + v8::Local stackTrace = v8::StackTrace::CurrentStackTrace(1); + if (stackTrace->GetFrameCount()) { + v8::Local frame = stackTrace->GetFrame(0); + int line = frame->GetLineNumber(); + QString scriptName = QString::fromUtf16(*v8::String::Value(frame->GetScriptName())); + + return QString::fromLatin1("%1 (%2:%3)").arg(msg).arg(scriptName).arg(line); + } + } + return msg; +} + v8::Handle console(ConsoleLogTypes logType, const v8::Arguments &args) { v8::HandleScope handleScope; @@ -105,19 +119,7 @@ v8::Handle console(ConsoleLogTypes logType, const v8::Arguments &args } } - if (qmlConsoleExtended()) { - int line = -1; - QString scriptName; - //get only current frame - v8::Local stackTrace = v8::StackTrace::CurrentStackTrace(1); - if (stackTrace->GetFrameCount()) { - v8::Local currentStackFrame = stackTrace->GetFrame(0); - line = currentStackFrame->GetLineNumber(); - scriptName = V8ENGINE()->toString(currentStackFrame->GetScriptName()); - } - - result = QString(QLatin1String("%1 (%2:%3)")).arg(result).arg(scriptName).arg(line); - } + result = extendMessage(result); switch (logType) { case Log: @@ -218,6 +220,33 @@ v8::Handle consoleTimeEnd(const v8::Arguments &args) return v8::Undefined(); } +v8::Handle consoleCount(const v8::Arguments &args) +{ + // first argument: name to print. Ignore any additional arguments + QString name; + if (args.Length() > 0) + name = V8ENGINE()->toString(args[0]); + + v8::Handle stackTrace = + v8::StackTrace::CurrentStackTrace(1, v8::StackTrace::kOverview); + + if (stackTrace->GetFrameCount()) { + v8::Local frame = stackTrace->GetFrame(0); + + QString scriptName = V8ENGINE()->toString(frame->GetScriptName()); + int line = frame->GetLineNumber(); + int column = frame->GetColumn(); + + int value = V8ENGINE()->consoleCountHelper(scriptName, line, column); + QString message = name + QLatin1String(": ") + QString::number(value); + if (qmlConsoleExtended()) + message = QString::fromLatin1("%1 (%2:%3)").arg(message).arg(scriptName).arg(line); + qDebug("%s", qPrintable(message)); + } + + return v8::Undefined(); +} + v8::Handle consoleTrace(const v8::Arguments &args) { if (args.Length() != 0) diff --git a/src/declarative/qml/v8/qdeclarativebuiltinfunctions_p.h b/src/declarative/qml/v8/qdeclarativebuiltinfunctions_p.h index 37e2c14..8761bdc 100644 --- a/src/declarative/qml/v8/qdeclarativebuiltinfunctions_p.h +++ b/src/declarative/qml/v8/qdeclarativebuiltinfunctions_p.h @@ -67,6 +67,7 @@ v8::Handle consoleProfile(const v8::Arguments &args); v8::Handle consoleProfileEnd(const v8::Arguments &args); v8::Handle consoleTime(const v8::Arguments &args); v8::Handle consoleTimeEnd(const v8::Arguments &args); +v8::Handle consoleCount(const v8::Arguments &args); v8::Handle consoleTrace(const v8::Arguments &args); v8::Handle consoleWarn(const v8::Arguments &args); v8::Handle isQtObject(const v8::Arguments &args); diff --git a/src/declarative/qml/v8/qv8engine.cpp b/src/declarative/qml/v8/qv8engine.cpp index 8c31809..aaf912a 100644 --- a/src/declarative/qml/v8/qv8engine.cpp +++ b/src/declarative/qml/v8/qv8engine.cpp @@ -531,6 +531,7 @@ void QV8Engine::initializeGlobal(v8::Handle global) console->Set(v8::String::New("warn"), V8FUNCTION(consoleWarn, this)); console->Set(v8::String::New("error"), V8FUNCTION(consoleError, this)); + console->Set(v8::String::New("count"), V8FUNCTION(consoleCount, this)); console->Set(v8::String::New("profile"), V8FUNCTION(consoleProfile, this)); console->Set(v8::String::New("profileEnd"), V8FUNCTION(consoleProfileEnd, this)); console->Set(v8::String::New("time"), V8FUNCTION(consoleTime, this)); @@ -1514,6 +1515,15 @@ qint64 QV8Engine::stopTimer(const QString &timerName, bool *wasRunning) return m_time.elapsed() - startedAt; } +int QV8Engine::consoleCountHelper(const QString &file, int line, int column) +{ + const QString key = file + QString::number(line) + QString::number(column); + int number = m_consoleCount.value(key, 0); + number++; + m_consoleCount.insert(key, number); + return number; +} + void QV8GCCallback::registerGcPrologueCallback() { QV8Engine::ThreadData *td = QV8Engine::threadData(); diff --git a/src/declarative/qml/v8/qv8engine_p.h b/src/declarative/qml/v8/qv8engine_p.h index 20fc474..b625704 100644 --- a/src/declarative/qml/v8/qv8engine_p.h +++ b/src/declarative/qml/v8/qv8engine_p.h @@ -432,6 +432,9 @@ public: void startTimer(const QString &timerName); qint64 stopTimer(const QString &timerName, bool *wasRunning); + // used for console.count() + int consoleCountHelper(const QString &file, int line, int column); + QObject *qtObjectFromJS(v8::Handle value); QSet visitedConversionObjects; @@ -486,6 +489,8 @@ protected: QElapsedTimer m_time; QHash m_startedTimers; + QHash m_consoleCount; + QVariant toBasicVariant(v8::Handle); void initializeGlobal(v8::Handle); diff --git a/tests/auto/declarative/debugger/qdebugmessageservice/data/test.qml b/tests/auto/declarative/debugger/qdebugmessageservice/data/test.qml index e8c9d6b..4a61f32 100644 --- a/tests/auto/declarative/debugger/qdebugmessageservice/data/test.qml +++ b/tests/auto/declarative/debugger/qdebugmessageservice/data/test.qml @@ -46,5 +46,6 @@ Item { height: 360 Component.onCompleted: { console.log("console.log") + console.count("console.count"); } } diff --git a/tests/auto/declarative/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp b/tests/auto/declarative/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp index fa83422..15fd0c5 100644 --- a/tests/auto/declarative/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp +++ b/tests/auto/declarative/debugger/qdebugmessageservice/tst_qdebugmessageservice.cpp @@ -59,14 +59,16 @@ class tst_QDebugMessageService : public QDeclarativeDataTest public: tst_QDebugMessageService(); + void init(bool extendedOutput); + private slots: void initTestCase(); void cleanupTestCase(); - void init(); void cleanup(); void retrieveDebugOutput(); + void retrieveDebugOutputExtended(); private: QDeclarativeDebugProcess *m_process; @@ -158,13 +160,14 @@ void tst_QDebugMessageService::cleanupTestCase() delete m_connection; } -void tst_QDebugMessageService::init() +void tst_QDebugMessageService::init(bool extendedOutput) { m_connection = new QDeclarativeDebugConnection(); m_process = new QDeclarativeDebugProcess(QLibraryInfo::location(QLibraryInfo::BinariesPath) + "/qmlscene"); m_client = new QDeclarativeDebugMsgClient(m_connection); - m_process->setEnvironment(QProcess::systemEnvironment() << "QML_CONSOLE_EXTENDED=1"); + if (extendedOutput) + m_process->setEnvironment(QProcess::systemEnvironment() << "QML_CONSOLE_EXTENDED=1"); m_process->start(QStringList() << QLatin1String(NORMALMODE) << QDeclarativeDataTest::instance()->testFile(QMLFILE)); if (!m_process->waitForSessionStart()) { QFAIL(QString("Could not launch app. Application output: \n%1").arg(m_process->output()).toAscii()); @@ -196,15 +199,42 @@ void tst_QDebugMessageService::cleanup() void tst_QDebugMessageService::retrieveDebugOutput() { - if (m_client->logBuffer.isEmpty()) + init(false); + + int maxTries = 2; + while ((m_client->logBuffer.size() < 2) + && (maxTries-- > 0)) + QVERIFY(QDeclarativeDebugTest::waitForSignal(m_client, SIGNAL(debugOutput()))); + + QCOMPARE(m_client->logBuffer.size(), 2); + + QCOMPARE(m_client->logBuffer.at(0).toString(), + LogEntry(QtDebugMsg, QLatin1String("console.log")).toString()); + QCOMPARE(m_client->logBuffer.at(1).toString(), + LogEntry(QtDebugMsg, QLatin1String("console.count: 1")).toString()); +} + +void tst_QDebugMessageService::retrieveDebugOutputExtended() +{ + init(true); + + int maxTries = 2; + while ((m_client->logBuffer.size() < 2) + && (maxTries-- > 0)) QDeclarativeDebugTest::waitForSignal(m_client, SIGNAL(debugOutput())); - QVERIFY(!m_client->logBuffer.isEmpty()); + QCOMPARE(m_client->logBuffer.size(), 2); + + const QString path = + QUrl::fromLocalFile(QDeclarativeDataTest::instance()->testFile(QMLFILE)).toString(); + + QString logMsg = QString::fromLatin1("console.log (%1:%2)").arg(path).arg(48); + QString countMsg = QString::fromLatin1("console.count: 1 (%1:%2)").arg(path).arg(49); - QString msg = QString::fromLatin1("console.log (%1:%2)").arg( - QUrl::fromLocalFile(QDeclarativeDataTest::instance()->testFile(QMLFILE)).toString()).arg(48); - QCOMPARE(m_client->logBuffer.last().toString(), - LogEntry(QtDebugMsg, msg).toString()); + QCOMPARE(m_client->logBuffer.at(0).toString(), + LogEntry(QtDebugMsg, logMsg).toString()); + QCOMPARE(m_client->logBuffer.at(1).toString(), + LogEntry(QtDebugMsg, countMsg).toString()); } QTEST_MAIN(tst_QDebugMessageService) diff --git a/tests/auto/declarative/qdeclarativeconsole/data/logging.qml b/tests/auto/declarative/qdeclarativeconsole/data/logging.qml index 716cb41..05c8be0 100644 --- a/tests/auto/declarative/qdeclarativeconsole/data/logging.qml +++ b/tests/auto/declarative/qdeclarativeconsole/data/logging.qml @@ -44,6 +44,12 @@ import QtQuick 2.0 QtObject { id:root + + function consoleCount() { + console.count("console.count", "Ignore additonal argument"); + console.count(); + } + Component.onCompleted: { console.debug("console.debug"); console.log("console.log"); @@ -51,6 +57,9 @@ QtObject { console.warn("console.warn"); console.error("console.error"); + consoleCount(); + consoleCount(); + var a = [1, 2]; var b = {a: "hello", d: 1 }; var c diff --git a/tests/auto/declarative/qdeclarativeconsole/tst_qdeclarativeconsole.cpp b/tests/auto/declarative/qdeclarativeconsole/tst_qdeclarativeconsole.cpp index 9737b3a..f750377 100644 --- a/tests/auto/declarative/qdeclarativeconsole/tst_qdeclarativeconsole.cpp +++ b/tests/auto/declarative/qdeclarativeconsole/tst_qdeclarativeconsole.cpp @@ -69,6 +69,11 @@ void tst_qdeclarativeconsole::logging() QTest::ignoreMessage(QtWarningMsg, "console.warn"); QTest::ignoreMessage(QtCriticalMsg, "console.error"); + QTest::ignoreMessage(QtDebugMsg, "console.count: 1"); + QTest::ignoreMessage(QtDebugMsg, ": 1"); + QTest::ignoreMessage(QtDebugMsg, "console.count: 2"); + QTest::ignoreMessage(QtDebugMsg, ": 2"); + QTest::ignoreMessage(QtDebugMsg, "[1,2]"); QTest::ignoreMessage(QtDebugMsg, "Object"); QTest::ignoreMessage(QtDebugMsg, "undefined"); @@ -80,7 +85,6 @@ void tst_qdeclarativeconsole::logging() QTest::ignoreMessage(QtDebugMsg, "1 pong! Object"); QTest::ignoreMessage(QtDebugMsg, "1 [ping,pong] Object 2"); - QDeclarativeComponent component(&engine, testUrl); QObject *object = component.create(); QVERIFY(object != 0); -- 2.7.4