Measuring Scripts Performance
Users can check their scripts' performance in two places in the viewer:
- The Statistics panel - the "Script Time" field shows the total execution time for all the scripts in the region in the last frame
- The Top Scripts window - shows the total execution time in the last 30 seconds of the slowest scripts in the region
Both of these statistics are calculated by measuring the execution time of each Script Instance.
- ScriptInstance.executionTimer is a Stopwatch that's used whenever the script is being processed in the scripting engine.
- This timer is automatically stopped when the script is sleeping, and restarted afterwards. See OSSL_Api.ScriptSleep() and LSL_Api.Sleep(). That's done because scripts don't use any CPU power while they're sleeping.
- Each Scene adds up all of its scripts' execution times each frame. See Scene.m_scriptExecutionTime. This is what's shown in the "Statistics" panel.
- Each ScriptInstance uses a sliding window to keep track of its execution time in the last 30 seconds. See ScriptInstance.ExecutionTime, which is an instance of the MetricsCollectorTime class. This is what's shown in the "Top Scripts" window.
We use the Stopwatch class to calculate the script execution times. This is a high-resolution timer, which is important because many script executions take less than 1ms, so a lower-resolution timer would think that the script didn't take any time at all.
The script time is "gross time", i.e. including the time the scripting engine used before and after the actual script execution. That's because this time should be attributed to the script's execution time, as it takes CPU power. For example, a script that fires thousands of events per second causes the scripting engine to do a lot of setup and teardown work that isn't part of the script's actual work, but it does slow down the simulator.
When a script is Stopped, we don't reset its ExecutionTime. This is done to allow the user to see runaway scripts, i.e. scripts that have executed for so long that they were forcibly aborted. When a script is forcibly aborted, it's Stopped. If we had reset the ExecutionTime when scripts are stopped then paradoxically, runaway script wouldn't have shown up in the "Top Scripts" dialog, even though they're the top CPU hogs among all the scripts.
The "Top Scripts" window shows the script's execution time in the last 30 seconds. This value needs to be short, so that when users modify a script to make it faster they can get quick feedback.
Possible Future Improvements
Currently, when scripts are sleeping this is done by making the script thread sleep. Although this doesn't use the CPU, it does lock up one of the limited number of script threads. A better implementation would be to release the thread during sleeps. However, since we already use quite a lot of threads, this doesn't seem like a high priority.
It would be nice if we could measure a script's memory usage: both total memory used, and memory thrashing which leads to garbage-collection time. E.g., a script that does a lot of work with lists is probably constantly creating and discarding lists, which is inefficient.