Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Obtain script backtrace when a log event is generated in C++ code #1156

Draft
wants to merge 3 commits into
base: master
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions interface/src/Application.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -255,6 +255,7 @@
#include "AboutUtil.h"
#include "ExternalResource.h"
#include <ThreadHelpers.h>
#include "ScriptEngineLoggingAgent.h"

#if defined(Q_OS_WIN)
#include <VersionHelpers.h>
Expand Down Expand Up @@ -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());
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
ScriptEngineLoggingAgent *scriptLogger = new ScriptEngineLoggingAgent(scriptEngine.data());
ScriptEngineLoggingAgent* scriptLogger = new ScriptEngineLoggingAgent(scriptEngine.data());

scriptEngine->setAgent(scriptLogger);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree with david that it would be good to disable this by default so it doesn’t affect the performance of normal scripts. it seems like it adds overhead to every single function call.

I also wonder, is this agent automatically deleted when the script engine dies? what about the associated thread local storage?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good point, I'll look into it.

}

bool Application::canAcceptURL(const QString& urlString) const {
Expand Down
1 change: 1 addition & 0 deletions libraries/script-engine/src/ScriptEngine.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,7 @@
#include "ScriptEngines.h"
#include "StackTestScriptingInterface.h"
#include "ModelScriptingInterface.h"
#include "ScriptEngineLoggingAgent.h"

#include <Profile.h>

Expand Down
52 changes: 52 additions & 0 deletions libraries/script-engine/src/ScriptEngineLoggingAgent.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,52 @@
//
// ScriptEngineLoggingAgent.cpp
// script-engine/src
//
// Created by Dale Glass on 04/04/2021.
// Copyright 2021 Vircadia Contributors
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// Copyright 2021 Vircadia Contributors
// 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 <QObject>
#include <QScriptEngine>
#include <QDebug>
#include <QLoggingCategory>
#include <QScriptContextInfo>

Q_LOGGING_CATEGORY(script_logger, "vircadia.script-engine.logging-agent")


ScriptEngineLoggingAgent::ScriptEngineLoggingAgent(QScriptEngine *engine) : QScriptEngineAgent(engine) {

}

void ScriptEngineLoggingAgent::functionEntry(qint64 scriptId) {
if ( scriptId != -1) {
Comment on lines +27 to +28
Copy link
Collaborator

@ctrlaltdavid ctrlaltdavid Apr 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
void ScriptEngineLoggingAgent::functionEntry(qint64 scriptId) {
if ( scriptId != -1) {
void ScriptEngineLoggingAgent::functionEntry(qint64 scriptID) {
if (scriptID != -1) {

// We only care about non-native functions
return;
}

QStringList backtrace;
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 );
}

void ScriptEngineLoggingAgent::functionExit(qint64 scriptId, const QScriptValue &returnValue) {
if ( scriptId != -1) {
Comment on lines +44 to +45
Copy link
Collaborator

@ctrlaltdavid ctrlaltdavid Apr 15, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
void ScriptEngineLoggingAgent::functionExit(qint64 scriptId, const QScriptValue &returnValue) {
if ( scriptId != -1) {
void ScriptEngineLoggingAgent::functionExit(qint64 scriptID, const QScriptValue& returnValue) {
if (scriptID != -1) {

// We only care about non-native functions
return;
}

ScriptContextHelper::pop();
}

35 changes: 35 additions & 0 deletions libraries/script-engine/src/ScriptEngineLoggingAgent.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
//
// ScriptEngineLoggingAgent.h
// script-engine/src
//
// Created by Dale Glass on 04/04/2021.
// Copyright 2021 Vircadia Contributors
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// Copyright 2021 Vircadia Contributors
// 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 <QObject>
#include <QStringList>
#include <QScriptEngineAgent>
#include <QThreadStorage>
#include <QLoggingCategory>
#include <mutex>

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;
Comment on lines +29 to +30
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
virtual void functionEntry(qint64 scriptId) override;
virtual void functionExit(qint64 scriptId, const QScriptValue &returnValue) override;
virtual void functionEntry(qint64 scriptID) override;
virtual void functionExit(qint64 scriptID, const QScriptValue& returnValue) override;

private:
std::mutex _lock;
};

#endif
16 changes: 16 additions & 0 deletions libraries/shared/src/LogHandler.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
#include <QtCore/QMutexLocker>
#include <QtCore/QThread>
#include <QtCore/QTimer>
#include "ScriptContextHelper.h"

QMutex LogHandler::_mutex(QMutex::Recursive);

Expand Down Expand Up @@ -209,6 +210,21 @@ QString LogHandler::printMessage(LogMsgType type, const QMessageLogContext& cont
fprintf(stdout, "[Previous message was repeated %i times]\n", _repeatCount);
}

if (context.category && strcmp(context.category, "vircadia.script-engine.logging-agent") != 0 ) {
QStringList context = ScriptContextHelper::get();
if ( !context.isEmpty()) {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
if ( !context.isEmpty()) {
if (!context.isEmpty()) {

#ifdef Q_OS_WIN
OutputDebugStringA(qPrintable(QString("Script context:\n")));
#endif
fprintf(stdout, "Script context:\n");
for( auto line : context) {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
for( auto line : context) {
for (auto line : context) {

fprintf(stdout, "\t%s\n", line.toStdString().c_str());
#ifdef Q_OS_WIN
OutputDebugStringA(qPrintable(line));
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
OutputDebugStringA(qPrintable(line));
OutputDebugStringA(qPrintable(QString("\t" + line + "\n")));

#endif
}
}
}
fprintf(stdout, "%s%s%s", color, qPrintable(logMessage), resetColor);
_repeatCount = 0;
} else {
Expand Down
45 changes: 45 additions & 0 deletions libraries/shared/src/ScriptContextHelper.cpp
Original file line number Diff line number Diff line change
@@ -0,0 +1,45 @@
//
// ScriptContextHelper.cpp
// shared/src
//
// Created by Dale Glass on 04/04/2021.
// Copyright 2021 Vircadia Contributors
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// Copyright 2021 Vircadia Contributors
// 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<QList<QStringList>> ScriptContextHelper::_context;

void ScriptContextHelper::push(QStringList context) {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
void ScriptContextHelper::push(QStringList context) {
void ScriptContextHelper::push(const QStringList& context) {

QList<QStringList> data = _context.localData();

data.append(context);

_context.setLocalData(data);
}

QStringList ScriptContextHelper::get() {
QList<QStringList> data = _context.localData();

if ( data.isEmpty() ) {
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
if ( data.isEmpty() ) {
if (data.isEmpty()) {

return QStringList();
} else {
return data.last();
}

//return _context.localData();
Comment on lines +32 to +33
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
//return _context.localData();

}

void ScriptContextHelper::pop() {
QList<QStringList> data = _context.localData();

if (!data.isEmpty()) {
data.removeLast();
}

_context.setLocalData(data);
}

31 changes: 31 additions & 0 deletions libraries/shared/src/ScriptContextHelper.h
Original file line number Diff line number Diff line change
@@ -0,0 +1,31 @@
//
// ScriptContextHelper.h
// shared/src
//
// Created by Dale Glass on 04/04/2021.
// Copyright 2021 Vircadia Contributors
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
// Copyright 2021 Vircadia Contributors
// 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 <QObject>
#include <QStringList>
#include <QThreadStorage>
#include <QList>


class ScriptContextHelper {
public:
static void push(QStringList context);
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
static void push(QStringList context);
static void push(const QStringList& context);

static QStringList get();
static void pop();

private:
static QThreadStorage<QList<QStringList>> _context;
};

#endif