From d03d1883d8c99b820ac90358cb1c811569be7898 Mon Sep 17 00:00:00 2001 From: Dale Glass Date: Sun, 4 Apr 2021 23:22:26 +0200 Subject: [PATCH 1/3] Initial, horribly broken attempt --- interface/src/Application.cpp | 4 ++ libraries/script-engine/src/ScriptEngine.cpp | 1 + .../src/ScriptEngineLoggingAgent.cpp | 52 +++++++++++++++++++ .../src/ScriptEngineLoggingAgent.h | 33 ++++++++++++ libraries/shared/src/LogHandler.cpp | 10 ++++ libraries/shared/src/ScriptContextHelper.cpp | 45 ++++++++++++++++ libraries/shared/src/ScriptContextHelper.h | 31 +++++++++++ 7 files changed, 176 insertions(+) create mode 100644 libraries/script-engine/src/ScriptEngineLoggingAgent.cpp create mode 100644 libraries/script-engine/src/ScriptEngineLoggingAgent.h create mode 100644 libraries/shared/src/ScriptContextHelper.cpp create mode 100644 libraries/shared/src/ScriptContextHelper.h diff --git a/interface/src/Application.cpp b/interface/src/Application.cpp index 057f32f370b..57136d2af8a 100644 --- a/interface/src/Application.cpp +++ b/interface/src/Application.cpp @@ -255,6 +255,7 @@ #include "AboutUtil.h" #include "ExternalResource.h" #include +#include "ScriptEngineLoggingAgent.h" #if defined(Q_OS_WIN) #include @@ -7652,6 +7653,9 @@ void Application::registerScriptEngineWithApplicationServices(const ScriptEngine connect(scriptEngine.data(), &ScriptEngine::infoMessage, scriptEngines, &ScriptEngines::onInfoMessage); connect(scriptEngine.data(), &ScriptEngine::clearDebugWindow, scriptEngines, &ScriptEngines::onClearDebugWindow); + + ScriptEngineLoggingAgent *scriptLogger = new ScriptEngineLoggingAgent(scriptEngine.data()); + scriptEngine->setAgent(scriptLogger); } bool Application::canAcceptURL(const QString& urlString) const { diff --git a/libraries/script-engine/src/ScriptEngine.cpp b/libraries/script-engine/src/ScriptEngine.cpp index 9fbf7a28015..c07594a5e96 100644 --- a/libraries/script-engine/src/ScriptEngine.cpp +++ b/libraries/script-engine/src/ScriptEngine.cpp @@ -78,6 +78,7 @@ #include "ScriptEngines.h" #include "StackTestScriptingInterface.h" #include "ModelScriptingInterface.h" +#include "ScriptEngineLoggingAgent.h" #include diff --git a/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp b/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp new file mode 100644 index 00000000000..ca07e261111 --- /dev/null +++ b/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp @@ -0,0 +1,52 @@ +// +// ScriptEngineLoggingAgent.cpp +// script-engine/src +// +// Created by Dale Glass on 04/04/2021. +// Copyright 2021 Vircadia Contributors +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#include "ScriptEngineLoggingAgent.h" +#include "ScriptContextHelper.h" +#include +#include +#include +#include +#include + +Q_LOGGING_CATEGORY(script_logger, "vircadia.script-engine.logging-agent") + + +ScriptEngineLoggingAgent::ScriptEngineLoggingAgent(QScriptEngine *engine) : QScriptEngineAgent(engine) { + +} + +void ScriptEngineLoggingAgent::functionEntry(qint64 scriptId) { + if ( scriptId != -1) { + // We only care about non-native functions + return; + } + + QStringList backtrace; + QScriptContext *ctx = engine()->currentContext(); + while( ctx ) { + QScriptContextInfo ctx_info(ctx); + backtrace.append( QString("%1:%2 %3").arg(ctx_info.fileName()).arg(ctx_info.lineNumber()).arg(ctx_info.functionName()) ); + ctx = ctx->parentContext(); + } + + ScriptContextHelper::push( backtrace ); +} + +void ScriptEngineLoggingAgent::functionExit(qint64 scriptId, const QScriptValue &returnValue) { + if ( scriptId != -1) { + // We only care about non-native functions + return; + } + + ScriptContextHelper::pop(); +} + diff --git a/libraries/script-engine/src/ScriptEngineLoggingAgent.h b/libraries/script-engine/src/ScriptEngineLoggingAgent.h new file mode 100644 index 00000000000..897e25f80cc --- /dev/null +++ b/libraries/script-engine/src/ScriptEngineLoggingAgent.h @@ -0,0 +1,33 @@ +// +// ScriptEngineLoggingAgent.h +// script-engine/src +// +// Created by Dale Glass on 04/04/2021. +// Copyright 2021 Vircadia Contributors +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#ifndef vircadia_ScriptEngineLoggingAgent_h +#define vircadia_ScriptEngineLoggingAgent_h + +#include +#include +#include +#include +#include + +Q_DECLARE_LOGGING_CATEGORY(script_logger) + + + +class ScriptEngineLoggingAgent : public QScriptEngineAgent { +public: + ScriptEngineLoggingAgent(QScriptEngine *engine); + virtual void functionEntry(qint64 scriptId) override; + virtual void functionExit(qint64 scriptId, const QScriptValue &returnValue) override; + +}; + +#endif \ No newline at end of file diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index 098e5e9a801..acbed0d483f 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -28,6 +28,7 @@ #include #include #include +#include "ScriptContextHelper.h" QMutex LogHandler::_mutex(QMutex::Recursive); @@ -209,6 +210,15 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont fprintf(stdout, "[Previous message was repeated %i times]\n", _repeatCount); } + if (strcmp(context.category, "vircadia.script-engine.logging-agent") != 0 ) { + QStringList context = ScriptContextHelper::get(); + if ( !context.isEmpty()) { + fprintf(stdout, "Script context:\n"); + for( auto line : context) { + fprintf(stdout, "\t%s\n", line.toStdString().c_str()); + } + } + } fprintf(stdout, "%s%s%s", color, qPrintable(logMessage), resetColor); _repeatCount = 0; } else { diff --git a/libraries/shared/src/ScriptContextHelper.cpp b/libraries/shared/src/ScriptContextHelper.cpp new file mode 100644 index 00000000000..0a45c4cdcc6 --- /dev/null +++ b/libraries/shared/src/ScriptContextHelper.cpp @@ -0,0 +1,45 @@ +// +// ScriptContextHelper.cpp +// shared/src +// +// Created by Dale Glass on 04/04/2021. +// Copyright 2021 Vircadia Contributors +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#include "ScriptContextHelper.h" + +QThreadStorage> ScriptContextHelper::_context; + +void ScriptContextHelper::push(QStringList context) { + QList data = _context.localData(); + + data.append(context); + + _context.setLocalData(data); +} + +QStringList ScriptContextHelper::get() { + QList data = _context.localData(); + + if ( data.isEmpty() ) { + return QStringList(); + } else { + return data.last(); + } + + //return _context.localData(); +} + +void ScriptContextHelper::pop() { + QList data = _context.localData(); + + if (!data.isEmpty()) { + data.removeLast(); + } + + _context.setLocalData(data); +} + diff --git a/libraries/shared/src/ScriptContextHelper.h b/libraries/shared/src/ScriptContextHelper.h new file mode 100644 index 00000000000..e0b3c04d9e7 --- /dev/null +++ b/libraries/shared/src/ScriptContextHelper.h @@ -0,0 +1,31 @@ +// +// ScriptContextHelper.h +// shared/src +// +// Created by Dale Glass on 04/04/2021. +// Copyright 2021 Vircadia Contributors +// +// Distributed under the Apache License, Version 2.0. +// See the accompanying file LICENSE or http://www.apache.org/licenses/LICENSE-2.0.html +// + +#ifndef vircadia_ScriptContextHelper_h +#define vircadia_ScriptContextHelper_h + +#include +#include +#include +#include + + +class ScriptContextHelper { +public: + static void push(QStringList context); + static QStringList get(); + static void pop(); + +private: + static QThreadStorage> _context; +}; + +#endif \ No newline at end of file From b6271abb1cd33877be85dd16f978cef88d87e5fe Mon Sep 17 00:00:00 2001 From: Dale Glass Date: Mon, 5 Apr 2021 18:26:37 +0200 Subject: [PATCH 2/3] Avoid crash by holding a lock to detect recursion --- .../script-engine/src/ScriptEngineLoggingAgent.cpp | 10 +++++----- libraries/script-engine/src/ScriptEngineLoggingAgent.h | 4 +++- libraries/shared/src/LogHandler.cpp | 2 +- 3 files changed, 9 insertions(+), 7 deletions(-) diff --git a/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp b/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp index ca07e261111..a0ee48978be 100644 --- a/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp +++ b/libraries/script-engine/src/ScriptEngineLoggingAgent.cpp @@ -31,11 +31,11 @@ void ScriptEngineLoggingAgent::functionEntry(qint64 scriptId) { } QStringList backtrace; - QScriptContext *ctx = engine()->currentContext(); - while( ctx ) { - QScriptContextInfo ctx_info(ctx); - backtrace.append( QString("%1:%2 %3").arg(ctx_info.fileName()).arg(ctx_info.lineNumber()).arg(ctx_info.functionName()) ); - ctx = ctx->parentContext(); + if (_lock.try_lock()) { + // We may end up calling ourselves through backtrace(). In such a case, do nothing to avoid + // getting into an infinite loop. + backtrace = engine()->currentContext()->backtrace(); + _lock.unlock(); } ScriptContextHelper::push( backtrace ); diff --git a/libraries/script-engine/src/ScriptEngineLoggingAgent.h b/libraries/script-engine/src/ScriptEngineLoggingAgent.h index 897e25f80cc..df046ab0472 100644 --- a/libraries/script-engine/src/ScriptEngineLoggingAgent.h +++ b/libraries/script-engine/src/ScriptEngineLoggingAgent.h @@ -17,6 +17,7 @@ #include #include #include +#include Q_DECLARE_LOGGING_CATEGORY(script_logger) @@ -27,7 +28,8 @@ class ScriptEngineLoggingAgent : public QScriptEngineAgent { ScriptEngineLoggingAgent(QScriptEngine *engine); virtual void functionEntry(qint64 scriptId) override; virtual void functionExit(qint64 scriptId, const QScriptValue &returnValue) override; - +private: + std::mutex _lock; }; #endif \ No newline at end of file diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index acbed0d483f..31870a4a037 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -210,7 +210,7 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont fprintf(stdout, "[Previous message was repeated %i times]\n", _repeatCount); } - if (strcmp(context.category, "vircadia.script-engine.logging-agent") != 0 ) { + if (context.category && strcmp(context.category, "vircadia.script-engine.logging-agent") != 0 ) { QStringList context = ScriptContextHelper::get(); if ( !context.isEmpty()) { fprintf(stdout, "Script context:\n"); From 2ea18eb65f5299942cc8f9d837447be27bfa028b Mon Sep 17 00:00:00 2001 From: Dale Glass Date: Sun, 11 Apr 2021 01:16:15 +0200 Subject: [PATCH 3/3] Output to VS debug window --- libraries/shared/src/LogHandler.cpp | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/libraries/shared/src/LogHandler.cpp b/libraries/shared/src/LogHandler.cpp index 31870a4a037..6218c51e991 100644 --- a/libraries/shared/src/LogHandler.cpp +++ b/libraries/shared/src/LogHandler.cpp @@ -213,9 +213,15 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont if (context.category && strcmp(context.category, "vircadia.script-engine.logging-agent") != 0 ) { QStringList context = ScriptContextHelper::get(); if ( !context.isEmpty()) { +#ifdef Q_OS_WIN + OutputDebugStringA(qPrintable(QString("Script context:\n"))); +#endif fprintf(stdout, "Script context:\n"); for( auto line : context) { fprintf(stdout, "\t%s\n", line.toStdString().c_str()); +#ifdef Q_OS_WIN + OutputDebugStringA(qPrintable(line)); +#endif } } }