Tracing performance timings

The Services Framework collects any task specific timing information after the task completes. The data is combined with the Services Framework timing information and added to a comma separated value file. A row is added for each run of a task configuration. If Services Framework is unable to write the data, and error is logged and the data is discarded.

Services Framework adds the timing information for task configurations set to allow monitoring. After Services Framework starts to write timings for a task configuration, it calls: 
public List<String> getTraceTimingKeys()
The method provides a list of all possible timing key strings for a task to establish the column order and create column headers in the comma separated value file. A separate file is created for each monitored task configuration. To obtain the task specific timing information, Services Framework calls: 
Public TaskTraceData getTraceTimingData()
The getter returns a value object that contains name and value pairs. Each of the key strings in the map must be one of the trace timing keys so it has a column header. Tracing task specific timing data in Services Framework is controlled from the general properties page. The properties that are shown in the following table are added.
Table 1. Tracing performance timing properties
Property name Description Default Example
Timing file enable Activates collecting and writing the detailed timing information false true, false
Timing file directory Directory name that contains the comma separated value files with the detailed timing information   /logs/timing
Timing file count Number of comma separated value files to keep. the file name is the task configuration name starting with zero (0) and increments by one (1). Each time Services Framework is started, existing files are increased. The latest file is always nnnn0.csv 10 1 through 99

Trace timing file example

The following example shows how Services Framework writes timing data to the timing file. The task must have the allow monitor property set to true and global tracing enabled.

During the initial run of the task, the getTraceTimingKeys method returns the following keys:
  • DB2_TIME
  • FILE_IO_TIME
and the getTraceTimingData method returns the following data:
  • For DB2_TIME - 1000
  • For FILE_IO_TIME - 1200
The following table shows the column headers and the row of comma separated data values for the timing file that would be created in this example. There are more column headers for a timing file than are shown in this table.
Table 2. Example timing file after the initial run of the task
TASK_RUN_TIME TASK_QUEUE_TIME … Additional headers … DB2_TIME FILE_IO_TIME
Task's run time Task's queue time … Additional data … 1000 1200
During the subsequent runs, if the task does not return a key or returns a null value for one of the keys, a blank is written in the CSV file for that key. For this run, the getTraceTimingKeys method returns the following keys:
  • DB2_TIME
  • FILE_IO_TIME
and the getTraceTimingData method returns the following data:
  • For DB2_TIME - 1234
  • For FILE_IO_TIME - NULL
The following table shows the timing file with the new row of data added to it.
Table 3. Example timing file after a task's second run
TASK_RUN_TIME TASK_QUEUE_TIME … Additional headers … DB2_TIME FILE_IO_TIME
Task's run time Task's queue time … Additional data … 1000 1200
Task's run time Task's queue time … Additional data … 1234  
During the subsequent runs, if the task adds a new trace timing key and data to the existing trace timing data set, the new trace timing key and data is ignored and the remaining trace data is written to the timing file. For this run, the getTraceTimingKeys method returns the following keys:
  • DB2_TIME
  • FILE_IO_TIME
  • FTP_TIME
and the getTraceTimingData method returns the following data:
  • For DB2_TIME - 1455
  • For FILE_IO_TIME - 6789
  • For FTP_TIME - 8903
The following table shows the timing file with the new row of data added to it.
Table 4. Example timing file after a task's third run
TASK_RUN_TIME TASK_QUEUE_TIME … Additional headers … DB2_TIME FILE_IO_TIME
Task's run time Task's queue time … Additional data … 1000 1200
Task's run time Task's queue time … Additional data … 1234  
Task's run time Task's queue time … Additional data … 1455 6789