A few years ago, I was teaching the basics of our %UnitTest framework during our Developing Using InterSystems Objects and SQL course. A student asked if it was possible to collect performance statistics while running unit tests. Here's some code that can be used with the %UnitTest classes to answer this question.
Using $zhorolog you can calculate the duration of the test. Beyond that, the %SYSTEM.Process class provides several metrics that you can collect for a process.
- Lines Executed
- Global References
- System CPU Time
- User CPU Time
- Disk Read Time
To enable any unit test to collect these stats, create a subclass of %UnitTest.TestCase, and add properties.
Class Performance.TestCase Extends %UnitTest.TestCase
{
Property Duration As %Time;
Property Lines As %Integer;
Property Globals As %Integer;
Property SystemCPUTime As %Integer;
Property UserCPUTime As %Integer;
Property DiskReadTime As %Integer;
}
Any specific unit test class you create should inherit from your new subclass instead of %UnitTest.TestCase.
In the subclass, use OnBeforeOneTest() to initialize the stats collection for each unit test. For everything except DiskReadTime, the code initializes the property with the current value.
/// initialize performance stats
Method OnBeforeOneTest(testname As %String) As %Status
{
// initialize with current values
set ..Duration = $zh
set ..Lines = $system.Process.LinesExecuted()
set ..Globals = $system.Process.GlobalReferences()
set ..SystemCPUTime = $piece(CPUTime, ",", 1)
set ..UserCPUTime = $piece(CPUTime, ",", 2)
// reset disk read time to 0 and start counting
do $system.Process.ResetDiskReadTiming()
do $system.Process.EnableDiskReadTiming()
return $$$OK
}
Use OnAfterOneTest() to finalize the stats collection for each unit test. For everything except DiskReadTime, the code subtracts the initial value from the current value.
/// Finalize performance stats
/// This is where you could also add code to save the counters to a separate table for analysis.
Method OnAfterOneTest(testname As %String) As %Status
{
set ..Duration = $zh - ..Duration
set ..Lines = $system.Process.LinesExecuted() - ..Lines
set ..Globals = $system.Process.GlobalReferences() - ..Globals
set CPUTime = $system.Process.GetCPUTime()
set ..SystemCPUTime = $piece(CPUTime, ",", 1) - ..SystemCPUTime
set ..UserCPUTime = $piece(CPUTime, ",", 2) - ..UserCPUTime
// get disk read time and stop counting
set ..DiskReadTime = $system.Process.DiskReadMilliseconds()
do $system.Process.DisableDiskReadTiming()
// add message to unit test log
set msg = "Performance: " _
"Duration: " _ ..Duration _
", Lines: " _ ..Lines _
", Globals: " _ ..Globals _
", System CPU Time: " _ (..SystemCPUTime / 1000) _
", User CPU Time: " _ (..UserCPUTime / 1000) _
", Disk Read Time: " _ (..DiskReadTime / 1000)
do $$$LogMessage(msg)
return $$$OK
}
There’s one more little trick. You may want to run your unit tests with or without collecting statistics. So, the code where you are invoking your unit tests must take an argument (could be a %Boolean 1 or 0) and somehow pass that in. The methods that actually run the tests (such as RunTest() or one of the other Run*() methods) take an array as the 3rd argument, passed by reference (preceded by a .). Here’s an example snippet:
// create an array to hold the logging argument (1 or 0) and pass it by reference
set p("logging") = logging
do ##class(%UnitTest.Manager).RunTest(test, qualifiers, .p)
The value you pass in the array can be accessed in OnBeforeOneTest() and OnAfterOneTest(). Add this as the first line in both methods:
if (..Manager.UserFields.GetAt("logging") = 0) { return $$$OK }
That’s it! Looking forward to your questions, comments, and additional ideas.
Top comments (0)