Use system tracing
Use the system tracing feature to store the Web application s execution path as well the execution time for each action (Page or Method). This information is then written to the console upon completion of the request. It can also be written to an event log file found in the MyApp\logs directory. When you activate system tracing and run a model, system trace control records the amount of time it took to run through each of the action builders in a model.
Quick Tips
- Use system tracing to trace only one model at a time. This will help you to narrow down performance problems within a model.
- We can also use Log4j tracing. For more information, see the online help topic, Property Driven System Level Logging.
- The system can only perform tracing on actions that are called through the WebAppAccess methods callMethod(..) and processPage(..). This means that if you call a method directly from another method, the tracing is bypassed and cannot be automatically tracked. We can add tracing manually to an internal Web application method or an Linked Java Object method. To manually do this, use the WebAppAccess method addSystemTrace(..) to add the start of a trace and to end the trace use the SystemTrace endTrace() method as shown below.
{
SystemTrace trace = webAppAccess.addSystemTrace(SystemTrace.METHOD, "in My Method");
... do some work;
trace.endTrace();
}
- To determine which event log contains the tracing information, look at the file name of the event log. The file name contains the date and the time it was created. For example, the following file was created at 10:29 P.M. (22.29) on November 22, 2001. Notice the time is based on the 24-hour clock.
event_11.22.2001.22.29.29.699.log
How to Start System Tracing
To start system tracing:
- Open the Run Configuration wizard.
This Wizard is available from the green Run icon's down-arrow menu.
- Select Run... from this menu to display the Run Configuration wizard.
- Click the Tracing tab and on the Tracing page enable the Run with system tracing check box and click Apply.
- Click Run at the bottom of the wizard page to run the model you want to trace.
How to Decipher Error Logging Displayed in the Command Prompt Window
The output below shows a list of actions performed and the milliseconds used for those actions. Look for large spikes to determine performance problems.
Action Total Action calls 1932 4456 Start Request: WebAppRunner.doRequest 0 0 [Model/ModelContainer] 1833 1833 Regen: 120 120 Compile: Methods Class 80 571 Method: main 240 491 .Page: StartingPage 0 0 ..Method: C1InitializeModelContainer 0 0 ..[Page/PageNavigation1] 31 31 ..Regen: 20 20 ..Compile: Methods Class 0 0 ..Method: main 60 90 ..Page: StartingPage 30 30 ...Page: NavigationPage 0 0 ..[Model/ModelContainer] 0 0 ..Method: C2InitializeModelContainer 0 0 ..[Page/PageNavigation2] 30 30 ..Regen: 10 10 ..Compile: Methods Class 0 0 ..Method: main 30 70 ..Page: StartingPage 0 0 ...Method: Increment 40 40 ...Page: NavigationPage Note: Because of the granularity of the system clock, many operations that are less than the clock granularity will show up as zero. Times do accumulate, so you may see several zeroes, followed by 10 ms, for example.
The timing information is most clear when running with one user. For multiple users, the elapsed time can end up being combined for any concurrent requests.