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 <kai.koehne@nokia.com>
sailfishos · Jan 24, 2012 · 398e27f · 398e27f
1 parent ecab027
commit 398e27f
Show file tree

Hide file tree

Showing 9 changed files with 125 additions and 23 deletions.
diff --git 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
@@ -80,6 +80,20 @@ enum ConsoleLogTypes {
     Error
 };
 
+static QString extendMessage(const QString &msg) {
+    if (qmlConsoleExtended()) {
+        v8::Local<v8::StackTrace> stackTrace = v8::StackTrace::CurrentStackTrace(1);
+        if (stackTrace->GetFrameCount()) {
+            v8::Local<v8::StackFrame> 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<v8::Value> console(ConsoleLogTypes logType, const v8::Arguments &args)
 {
     v8::HandleScope handleScope;
@@ -105,19 +119,7 @@ v8::Handle<v8::Value> console(ConsoleLogTypes logType, const v8::Arguments &args
         }
     }
 
-    if (qmlConsoleExtended()) {
-        int line = -1;
-        QString scriptName;
-        //get only current frame
-        v8::Local<v8::StackTrace> stackTrace = v8::StackTrace::CurrentStackTrace(1);
-        if (stackTrace->GetFrameCount()) {
-            v8::Local<v8::StackFrame> 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<v8::Value> consoleTimeEnd(const v8::Arguments &args)
     return v8::Undefined();
 }
 
+v8::Handle<v8::Value> 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<v8::StackTrace> stackTrace =
+        v8::StackTrace::CurrentStackTrace(1, v8::StackTrace::kOverview);
+
+    if (stackTrace->GetFrameCount()) {
+        v8::Local<v8::StackFrame> 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<v8::Value> 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
@@ -67,6 +67,7 @@ v8::Handle<v8::Value> consoleProfile(const v8::Arguments &args);
 v8::Handle<v8::Value> consoleProfileEnd(const v8::Arguments &args);
 v8::Handle<v8::Value> consoleTime(const v8::Arguments &args);
 v8::Handle<v8::Value> consoleTimeEnd(const v8::Arguments &args);
+v8::Handle<v8::Value> consoleCount(const v8::Arguments &args);
 v8::Handle<v8::Value> consoleTrace(const v8::Arguments &args);
 v8::Handle<v8::Value> consoleWarn(const v8::Arguments &args);
 v8::Handle<v8::Value> isQtObject(const v8::Arguments &args);

diff --git a/src/declarative/qml/v8/qv8engine.cpp b/src/declarative/qml/v8/qv8engine.cpp
@@ -531,6 +531,7 @@ void QV8Engine::initializeGlobal(v8::Handle<v8::Object> 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
@@ -432,6 +432,9 @@ class Q_DECLARATIVE_EXPORT QV8Engine
     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<v8::Value> value);
     QSet<int> visitedConversionObjects;
 
@@ -486,6 +489,8 @@ class Q_DECLARATIVE_EXPORT QV8Engine
     QElapsedTimer m_time;
     QHash<QString, qint64> m_startedTimers;
 
+    QHash<QString, quint32> m_consoleCount;
+
     QVariant toBasicVariant(v8::Handle<v8::Value>);
 
     void initializeGlobal(v8::Handle<v8::Object>);

diff --git 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
@@ -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
@@ -44,13 +44,22 @@ 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");
         console.info("console.info");
         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
@@ -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);