Page 1 of 2

Profiling with QScriptEngineAgent

Posted: 16 Nov 2014, 17:44
by NoQ
I'm trying to use QScriptEngineAgent to gather detailed performance profiling for all script functions (not just API functions), but so far it doesn't work: i absolutely fail to obtain function name on functionEntry/functionExit events. It feels as if this functionality is either completely disabled on some level (some compile option?) or broken, or i'm doing something completely wrong: all ways of obtaining callee as QScriptValue result in a dead value (with NULL internal pointer) most of the time, QScriptContextInfo contains no info, and even line numbers are -1.

Does anybody have any idea? Here's what i'm trying to do (patch for master):

Re: Profiling with QScriptEngineAgent

Posted: 16 Nov 2014, 22:15
by Per
It just seems to work for me?

I have Qt 5.4.0

Re: Profiling with QScriptEngineAgent

Posted: 17 Nov 2014, 07:08
by NoQ
o_O Could you post a sample output, so that i "believed"? (:
Here's what i'm seeing:

Code: Select all

error   |08:29:31: [functionExit:173]  <- -1 -1    276
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    126
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    150
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    16
error   |08:29:31: [functionExit:173]  <- -1 -1    253
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    18
error   |08:29:31: [functionExit:173]  <- -1 -1    270
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    143
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    167
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    18
error   |08:29:31: [functionExit:173]  <- -1 -1    270
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    18
error   |08:29:31: [functionExit:173]  <- -1 -1    273
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    17
error   |08:29:31: [functionExit:173]  <- -1 -1    270
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    126
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    158
error   |08:29:31: [functionEntry:153] -> -1 -1   
error   |08:29:31: [functionExit:173]  <- -1 -1    18
error   |08:29:31: [functionExit:173]  <- -1 -1    262
On second thought, maybe that'd explain why scripts are running 10 times faster on my machine? Some script debugging features are disabled in qtscript compile-time in my distribution?

I'm on qt-5.3.2, but anyway these classes are around since qt-4.4.

Re: Profiling with QScriptEngineAgent

Posted: 18 Nov 2014, 00:00
by Per
Ok, then it doesn't work for me, either.

Re: Profiling with QScriptEngineAgent

Posted: 18 Nov 2014, 07:34
by NoQ
Then neither does it explain XD
Will keep struggling.

Re: Profiling with QScriptEngineAgent

Posted: 20 Nov 2014, 04:58
by vexed
Doing a quick look at the code, and nothing jumps out as being incorrect, however, as you posted, it don't work.
Looking up QString QScriptContextInfo::functionName() const
Returns the name of the called function, or an empty string if the name is not available.

They don't say why it wouldn't be available.

Then trying QStringList QScriptContext::backtrace() const
Returns a human-readable backtrace of this QScriptContext.

Each line is of the form <function-name>(<arguments>)@<file-name>:<line-number>.

To access individual pieces of debugging-related information (for example, to construct your own backtrace representation), use QScriptContextInfo.


Doesn't work either, there are no function names.

So, I am guessing this a bug in Qt ? :hmm:

Re: Profiling with QScriptEngineAgent

Posted: 22 Nov 2014, 10:57
by NoQ

Re: Profiling with QScriptEngineAgent

Posted: 22 Nov 2014, 17:28
by NoQ
Meanwhile, i have another approach to profiling in mind:

Code: Select all

var returnValue = profile("functionName", arguments...);
where profile() is a native API function that calls the given function by name, measures timing, and injects the stats obtained into the monitor.

This way we profile only what the script author wants to have profiled, which would probably reduce overhead, and no extra support from Qt is required.

Re: Profiling with QScriptEngineAgent

Posted: 22 Nov 2014, 18:25
by NoQ
JSProfile.patch
Something like that...
(2.57 KiB) Downloaded 371 times
That is, queue() and setTimer() already do profiling. This new function is different and necessary just because it calls the callee instantly, allowing the script to obtain the return value, and also to be sure no game objects get outdated, and also provide arbitrary number of arguments.

Note that callFunction()'s boolean return value was never checked anyway.

Re: Profiling with QScriptEngineAgent

Posted: 22 Nov 2014, 19:40
by NoQ
This approach makes it necessary to wrap every call of the function, rather than just its definition. It's possible to make a wrapper for the definition, but then if you queue the wrapper, it'd count performance twice (for different names, but still double overhead and poorly readable garbage in the stats).

An alternative is to implement profileStart("name") and profileEnd() calls, the first one would push name and ticks value into a stack, the second one would pop name and ticks and accumulate statistics. Then you'd have to put this inside the callee, on entry and every return (which may be many). Forgetting one of the returns, or throwing an exception, would break things quite a bit.

Would have still been easier with QScriptEngineAgent if only it worked.

Re: Profiling with QScriptEngineAgent

Posted: 23 Nov 2014, 13:35
by NoQ
http://qt-project.org/forums/viewthread/5909
http://qt-project.org/wiki/Qt_Modules_Maturity_Level
QScriptEngineAgent and related classes
State: Deprecated
Reasoning: flawed design, being replaced by a better design.
:stare:

I guess i'd push the js_profile() approach. Also, need to document jsdebug and performance monitor :hmm:

Do we plan to use QJSEngine, anyway? :ninja:

Re: Profiling with QScriptEngineAgent

Posted: 23 Nov 2014, 22:44
by Per
NoQ wrote:Do we plan to use QJSEngine, anyway? :ninja:
No, it is a very different design, and does not have half of what we need, unfortunately. But they will keep supporting QtScript for all of Qt5, and hopefully by Qt6 something superior will replace both.

Re: Profiling with QScriptEngineAgent

Posted: 25 Nov 2014, 04:08
by vexed
:annoyed:
OK calm down everyone.

If you are currently porting over WZscript to JS, that is fine, and this has no impact on your work.

I have moved the other posts to another area for further discussion, since some people have misconstrued what I was saying, and started to come to conclusions that were not correct for what is going on currently.
That was not my intention.

Once again, if you are currently porting over WZscript to JS, that is fine, and the talk that was being discussed has no impact on your work.

Re: Profiling with QScriptEngineAgent

Posted: 25 Nov 2014, 08:47
by NoQ
Here is a little hello-world proof-of-concept with QJSEngine.

tl;dr: i successfully defined API functions for an engine, called them from scripts, tested string and integer and arbitrary-js-value arguments, called JS function from C++, obtained script return values, and handled an exception.

Creating API functions is pleasantly easy: instead of an arbitrary array of QScriptValue arguments, we receive our arguments already converted into C++ ints or strings. On the other hand, we'd have to deal with their fancy Q_OBJECT (etc.) preprocessors.

No idea about performance so far. I guess we cannot know until we try.

qjs.pro:

Code: Select all

TEMPLATE = app
TARGET = qjs
INCLUDEPATH += .
QT += qml

SOURCES += main.cpp
HEADERS += main.h
main.h:

Code: Select all

#include <QObject>
#include <QString>
#include <QJSValue>

class FunctionWrapper: public QObject {
	Q_OBJECT;
	public:
		Q_INVOKABLE void testIntArgument(int arg);
		Q_INVOKABLE void testStringArgument(QString arg);
		Q_INVOKABLE void testValueArgument(QJSValue arg);
		Q_INVOKABLE QString testReturn();
};
main.cpp:

Code: Select all

#include "main.h"

#include <QJSEngine>
#include <QDebug>

void FunctionWrapper::testIntArgument(int arg) {
	qDebug() << arg;
}

void FunctionWrapper::testStringArgument(QString arg) {
	qDebug() << arg;
}

void FunctionWrapper::testValueArgument(QJSValue arg) {
	qDebug() << arg.toInt() << arg.toString();
}

QString FunctionWrapper::testReturn() {
	return "answer: 42";
}

int main() {
	FunctionWrapper *Wrap = new FunctionWrapper();
	QJSEngine *Eng = new QJSEngine();
	QJSValue Obj = Eng->newQObject(Wrap);
	Eng->globalObject().setProperty(
		"testIntArgument", Obj.property("testIntArgument"));
	Eng->globalObject().setProperty(
		"testStringArgument", Obj.property("testStringArgument"));
	Eng->globalObject().setProperty(
		"testValueArgument", Obj.property("testValueArgument"));
	Eng->globalObject().setProperty(
		"testReturn", Obj.property("testReturn"));
	QJSValue result = Eng->evaluate(
		"testIntArgument(6 * 7);"
		"testStringArgument(6 * 7);"
		"testValueArgument(6 * 7);"
		"testReturn();"
	);
	qDebug() << result.toString();
	result = Eng->evaluate("noSuchFunction();");
	if (result.isError())
		qDebug() << result.toString();
	else
		qDebug() << "No exception";
	result = Eng->evaluate("function foo(x) { return x * 7; }");
	if (result.isError())
		qDebug() << result.toString();
	else
		qDebug() << "No exception";
	QJSValueList args;
	args.push_back(6);
	result = Eng->globalObject().property("foo").call(args);
	qDebug() << "returned" << result.toInt();
	return 0;
}
Sample output:

Code: Select all

$ ./qjs
42
"42"
42 "42"
"answer: 42"
"ReferenceError: noSuchFunction is not defined"
No exception
returned 42

Re: Profiling with QScriptEngineAgent

Posted: 15 Dec 2014, 19:37
by NoQ
Half-way through qtscriptfuncs.cpp of converting to QJSEngine (as in, doing the replacing, didn't try to compile yet lol). Eg.:

Code: Select all

-static QScriptValue js_distBetweenTwoPoints(QScriptContext *context, QScriptEngine *engine)
-{
-       int x1 = context->argument(0).toNumber();
-       int y1 = context->argument(1).toNumber();
-       int x2 = context->argument(2).toNumber();
-       int y2 = context->argument(3).toNumber();
-       return QScriptValue(iHypot(x1 - x2, y1 - y2));
-}
+int WZAPI::distBetweenTwoPoints(int x1, int y1, int x2, int y2)
+{
+       return iHypot(x1 - x2, y1 - y2);
+}
It seems there's no good way to implement SCRIPT_ASSERT - neither to interrupt current native function (as return type may vary; this is solvable, of course, but ugly, but not much more ugly than before), nor to throw a script exception from inside native function (might be missing something; also, if we give up on this, we let scripts crash the game and/or themselves on error).

Also, QJSEngine doesn't support variadic arguments; namely, there are at most 10 arguments to any Q_INVOKABLE method. This means we cannot support templates with unlimited number of turrets (there aren't many anyway), and also we have problems with functions like debug() and dump() (have to drop remaining arguments).