Reading performance statistics from the logs

If ITP/Server is configured to log progress information (level two or higher), job statistics are written to the itpserver.log file. This information can help to analyze the performance and load of the ITP/Server configuration.

The statistics can be identified by the prefix STATS: on the line. Information is written as 'KEY[VALUE]' pairs.

Annotated example

16:19:31.890[2] ITPDP [Sample] #1@HOST: STATS:
         SUB[16:19:08.734] STR[16:19:08.734] END[16:19:31.890] ID[StH] OL[0] SRV[Test] STS[4] IID[3]

This status line contains the following information:

• 16:19:31.890
  Time the statistics line was written to the log.
• [2]
  Log level (only shown if ITP/Server is configured to log all information).
• ITPDP [Sample] #1@HOST
  Identification of the specific Document Processor @ Server that executed the job.
• SUB[16:19:08.734]
  Time the job was received and queued by ITP/Server.
• STR[16:19:08.734]
  Time the job was started by the designated ITP/Document Processor.
• END[16:19:31.890]
  Time the job finished.
• ID[StH]
  Job ID.
• OL[0]
  Identifies if the job is interactive or batch. This flag is 1 if the job is submitted through the ITP/OnLine Server API and 0 otherwise.
• SRV[Test]
  Service.
• STS[4]
  Completion status. 3 indicates successful completion, 4 indicates that the script reported an error back. Other values indicate that the job failed to run at all.
• IID[3]
  Internal identification of the job. This attribute is based on the order in which jobs are submitted to ITP/Server. However, this attribute cannot be used as a unique identification because scheduled jobs and maintenance jobs will generate a STATS: line every time the job runs on an ITP/Document Processor.

Timing for a job can be derived from this information:

• (STR - SUB) is the time the job spent queued, waiting for assignment to an available ITP/Document Processor.
  In the above example the job was immediately assigned to an idle ITP/Document Processor.
• (END - STR) is the time the ITP/Document Processor spent executing the job.
  In the above example the ITP/Document Processor spent 13.156 seconds executing this job.

All times in the STATS: line are based on a 24-hour clock, read from the clock of the computer hosting the ITPServer service. The frequency of this clock is 60Hz, causing timings to be accurate to approximately 15-16 millisecond intervals.

Processing STATS: lines

The STATS: line is intended for automated processing. Applications which parse this line must adhere to the following guidelines:

• All attributes are written in the format 'KEY[VALUE]'.
• The order of the attributes is not fixed and can change between versions. Applications should ignore unknown attributes.
• Because times are based on a 24-hour local clock applications must account for jobs running past midnight or during DST clock changes.