Performance testing

Classic Servoy
1

Hello,

Does someone know if there is a way to monitor what Servoy method are called how many times and how many ms it took to finish the method (something like the performance data in the application server, but then for methods and not for queries)
If something like that exsist, it would help me to find performance issues in the javascript.
Because when you step through your coding with the debugger you see that all works correct, but you can’t see if there is some performance issue.

Martin

2

You can do it yourself by writing a timestamp at the method start and another one at the method end. You could write to a logfile or directly to a log table, in the last case you could also have a calculation to show the length and a nice GUI to see the results.

3

Another output option is the status bar – immediate feedback. Great for smart client testing on dodgy connections.

[attachment=0]Picture 22.png[/attachment]

Picture 22.png

4

Below is a profiling method I use in my testing. It’s a better approach to my mind because it requires no changes to your original code to track the timestamps, etc.

function profile_global_method()
{
  var orig = arguments[0];
  var newName = orig + '_orig';
 
  if(typeof globals[newName] == 'function')
    globals[orig] = globals[newName];
  globals[newName] = globals[orig];

  var pStart;
  var before = function() { pStart = new Date(); };
  var after = function() { application.output(orig + ":" + (new Date() - pStart)); };
 
  var repl = function() {
  switch(typeof before)
  {
    case 'string' : eval(before); break;
    case 'function' : before(); break;
  }
  var result = globals[newName].apply(this, arguments);
  switch(typeof after)
  {
    case 'string' : eval(after); break;
    case 'function' : after(); break;
  }
  return result;
  }
  globals[orig] = repl;
}

This takes the name of a global method. You call it from somewhere else, typically in an “enter profiler mode” method somewhere that will call it repeated for the different methods you want to watch. It aliases the original global method in the runtime and replaces it with a version that tracks profiling ticks and outputs them to the console. No further modifications to your original code are required.

Once you do this, everytime the method is called you get “methodName:[ticks]” to the console after it runs. Clearly you could modify this to track that in a db, keep counts of the number of times particular methods are called, etc.

greg.

5

agiletortoise:
This takes the name of a global method. You call it from somewhere else, typically in an “enter profiler mode” method somewhere that will call it repeated for the different methods you want to watch. It aliases the original global method in the runtime and replaces it with a version that tracks profiling ticks and outputs them to the console. No further modifications to your original code are required.

Thanks Greg for sharing this,

Can you please, write a little bit about the use of this method, profile_global_method(). I am little bit confused how to use this Method to check for performance Issue in my code.

I have added this method, profile_global_method() to my globals. Let’s I have method executeCode(), and I would like to check the time it takes to finish executing the method. How can I do that?

I tried ```
globals.profile_global_method(globals.executeCode);


Is there any additional set up required?

Thanks in advance.
6

andrew2pinsky:
I am little bit confused how to use this Method to check for performance Issue in my code.

Join the club! I was confused as well.
But after discussing with a colleague we have found out how it works.

And we must say thanks very much Greg for this example. For us this is really high level Javascript.

This is what we did to use it:

for (var i = 0; i < globals.allmethods.length; i++){
	if (globals.allmethods[i] != 'profile_global_method')
		globals.profile_global_method(globals.allmethods[i]);
}

Now all global methods are profiled without any change! By the way, this only works in Servoy 4. Not in 3.5.x

7

Hi Marteen,

Thanks for your reply.

After, profiling my global method, by,

globals.profile_global_method(globals.executeCode);

When, I am executing the method, executeCode(), it simply go on executing. It doesn’t displaying any console output…

Am I missing something???

8

Hi Andrew,

You should use it like this:

globals.profile_global_method('executeCode');

I made the same error when I tested the method.

Martin

9

martinh:
Hi Andrew,

You should use it like this:

globals.profile_global_method('executeCode');

I made the same error when I tested the method.

Martin

Hi Marteen,

Thanks…I got it…Now it is working… :D

Thanks a lot for the same.

10

Here’s an improved version which tracks profile data in a global variable $profileData, counts the number of times a method was executed, and outputs to the console the “START” and “END” points of each method call.

function profile_global_method()
{
  var orig = arguments[0];
  var newName = orig + '_orig';

  if(typeof globals[newName] == 'function') globals[orig] = globals[newName];
  globals[newName] = globals[orig];

  if(typeof $profileData == 'undefined') $profileData = { };
  if(typeof $profileData[orig] == 'undefined') $profileData[orig] = {count:0, lastStart:null, lastEnd:null, ticks:0};
  
  var before = function() { 
  		$profileData[orig].count = $profileData[orig].count + 1;
  		$profileData[orig].lastStart = new Date();
  		application.output("START | globals." + orig + " | count: " + $profileData[orig].count);
  };
  var after = function() { 
  		$profileData[orig].lastEnd = new Date();
  		$profileData[orig].ticks = $profileData[orig].lastEnd - $profileData[orig].lastStart;
  		application.output('END   | globals.' + orig + " | count: " + $profileData[orig].count + ", ticks: " + $profileData[orig].ticks); 
  };

  var repl = function() {
		before(); 
  	var result = globals[newName].apply(this, arguments);
		after();
  	return result;
  }
  globals[orig] = repl;
}

The output you get in the console will look like the below. This example is one call to ‘test2’ which is a method which also calls ‘test1’ from inside it.

START | globals.test2 | count: 6
START | globals.test1 | count: 7
END   | globals.test1 | count: 7, ticks: 10
END   | globals.test2 | count: 6, ticks: 50
11

Great code, thnkx Greg!

12

agiletortoise:
Here’s an improved version…

Great. Thanks Greg. :D