Tracing Application Engine Programs

This chapter provides overviews of tracing Application Engine programs and trace results and discusses how to:

• Enable Application Engine tracing.

• Locate trace files.

Understanding Tracing Application Engine Programs

You can set the following traces to monitor the performance of Application Engine programs:

• Application Engine step trace.

• Application Engine SQL trace.

• Application Engine statement timings trace.

• Database optimizer trace.

Note. The general PeopleTools SQL and PeopleCode traces also apply to Application Engine programs.

Understanding Trace Results

This section discusses:

• Trace file sections.

• Step trace.

• SQL trace.

• Statement timings trace.

• Database optimizer trace.

Trace File Sections

At the top of each trace, useful information helps you to identify the PeopleTools version, the database name, and the database platform type.

SQL Counts and Timings Section

The first section of a trace file is the SQL section. It records the performance of application-specific SQL. The trace values appear within a series of columns and sections. The following table describes each column within the first section of the trace file:

Note. When you run a SQL trace at the Application Engine level and the PeopleTools level simultaneously, you may see misleading results. Extra overhead is added to the overall SQL timings by the PeopleTools trace. Tracing SQL at the Application Engine level (-TRACE) adds to the non-SQL times because PeopleTools writes the trace data after timing the SQL.

PeopleCode Actions Section

The second section of the trace file, or PeopleCode section, records the performance associated with all the PeopleCode actions in your program. The following table describes each column in this section:

Note. The system rounds to the first decimal place (tenths), but only after calculating the sum of each action time.

PeopleCode Built-ins and Methods Section

The third section of the trace file contains either a list or summary of PeopleCode built-ins and methods used. To see a list of built-ins and methods, you must enable the PeopleCode detail timings in addition to the statement timings trace.

If a method or built-in function takes a large amount of time, you may want to consider alternatives. For example, if array processing dominates your runtime, consider inserting the data into temporary tables and performing the processing on tables in the database.

Summary Data

The fourth section of the trace file contains summary data. The values in this section reveal an overview of the program run without drilling down too far into details.

The following table describes the values that appear in this section:

Environment Information Section

The fifth section of the trace file contains environment information specific to Application Engine. If programs appear to be performing poorly, check the trace value that you have set.

Each trace produces an unavoidable degree of overhead. As such, the more traces you have enabled, the more likely you are to see degraded performance. Run only the traces you need. This section of the trace file shows you information about the following:

• SQL trace

• PeopleCode trace

• Application Engine trace

• Application Engine DbFlags (%UpdateStats)

Step Trace

The step trace reports each step name that your program executes and in what order. Associated with each step is a timestamp, the Do action level, and the action type.

The trace shows the steps that execute within a called section by indented formatting. For example, a step that executes within a called section is preceded by two dots (..), while other steps are preceded by only one dot.

SQL Trace

The SQL trace report shows formatted SQL processes, including commits, rollbacks, and restarts. You can also view the buffers associated with each SQL statement. Use the SQL trace to spot errors in your SQL and to view your commit strategy.

Statement Timings Trace

The Application Engine statement timing trace report is similar to a COBOL timings trace, in which you monitor the execution of COBOL programs for performance evaluations. This trace enables you to gather performance information to determine program bottlenecks. Once bottlenecks are identified, you might be able to modify your program to run more efficiently, or you may want to change the database schema and configuration to optimize the execution of your program.

The statement timings trace is invaluable for tuning an Application Engine program. It may also be useful as a default trace level for all production runs, to provide a metric for long-term performance trends.

By examining all of the figures in this trace, you can identify areas of your program that are not running as efficiently as possible. For instance, if compile counts are high, you can reduce the numbers by using the Application Engine reuse feature. If inserts appear to be running slow and you have many of them, you can increase the performance by using the Application Engine bulk insert feature. Each value in the trace, including cumulative totals, appears in a form rounded to the nearest tenth of a second, but totals are calculated using nonrounded timings.

You can write this trace to a file, or you can write the results to tables. Either way, timings trace overhead is minimal. Internal testing reveals that the Application Engine trace has an overhead between 2 percent and 5 percent of total runtime.

By storing timings information in a table, you can store historical data in the database, which enables you to produce reports that aid in trend analysis, allow ad hoc SQL queries for longest running statements, and so on. With the timings data stored in the database, you can manipulate and customize reports to show only the metrics in which you are most interested.

You can use third-party tools to query and present the data in such ways as detailed graphical representations of your program’s performance. You can also implement alarms if the performance of a program reaches a specified maximum value in a particular area such as SQL compile time.

Note. Application Engine does not write the timings trace to a table for programs invoked by the CallAppEngine PeopleCode function. To write to a table, a process instance is required, and programs invoked by CallAppEngine are not assigned a process instance.

The Statements Timings (table) option, or 1024 -TRACE option, populates the following tables.

• PS_BAT_TIMINGS_LOG (Parent)

  This table stores general information for a program run.

• PS_BAT_TIMINGS_DTL (Child)

  This table stores details associated with a program run, such as the execute count, fetch time, and so on.

The SQL Timings (table) option, or the 16834 -TRACE option, populates the following tables.

• PS_AE_TIMINGS_LG (Parent)

  This table stores general information for a program run.

• PS_AE_TIMINGS_DT (Child)

  This table stores details associated with a program run, such as the execute count, fetch time, and so on.

  PS_BAT_TIMINGS_FN

  This table stores PeopleCode detailed timing information.

PeopleSoft provides BATTIMES.SQR as an example of the type of reports you can generate to reflect the information stored in the BAT_TIMINGS tables. You can produce a summary report for all the programs for a specific run control ID, or you can get detail data for a specific process instance.

To invoke the BATTIMES.SQR report through PeopleSoft Process Scheduler:

1. Select PeopleTools, Process Scheduler, Batch Timings.

   The Batch Timings page appears.

2. From the Report Type drop-down list box, select Detail or Summary.

3. In the Batch Timings For group box, enter the run control ID for summary reports, and enter the process instance for detail reports.

4. When you have made the appropriate selections, click the Run button.

To view batch timings using Process Monitor:

1. Select PeopleTools, Process Scheduler, Process Monitor.

2. Locate the program run associated with the current trace.

3. Click the Job Details button.

4. On the Process Detail dialog box, click the Batch Timings link.

   PeopleCode detail timings do not appear. They appear only in the file format.

Database Optimizer Trace

The database optimizer trace reveals the execution or query plan for the SQL that your Application Engine program generates. Each SQL statement is traced only once. You can write the trace to a file or a table.

How you view the results of this trace depends on the relational database management system (RDBMS) that you are currently using. For instance, on some platforms, only the trace-to-file option is available, whereas on others only the trace-to-table option is available. The following table shows the options available for each of the platforms PeopleSoft supports:

Note. PeopleTools does not collect optimizer data for SQL originating from PeopleCode actions, except if you run Oracle and Informix and use file output. In this case, the system traces all SQL that executes after the first SQL action executes.

Oracle

When outputting the trace to a file, Application Engine writes the trace file to the default Oracle trace directory specified on the database server. To read the trace file, use the TKPROF utility.

To output the trace to a table on Oracle, a PLAN_TABLE table must exist, and the statement_id must be of type VarChar2(254), instead of VarChar2(30).

When outputting to a table, the PeopleSoft application updates the trace rows as follows:

• EXPLAIN PLAN SET STATEMENT_ID: PeopleSoft updates the STATEMENT ID column:

  EXPLAIN PLAN SET STATEMENT_ID = ApplId.Section.Step.Type FOR ​sqlstmt

• PLAN_TABLE’s REMARKS column: PeopleSoft updates the REMARKS column:

  PLAN_TABLE‘s REMARKS column = ‘ProcessInstance-RunControlId(QueryNo)’ 

  queryno is a count of how many SQL statements have been traced up to a particular point.

Note. When tracing to a table with Oracle, PeopleSoft does not perform optimizer traces on %UpdateStats and %TruncateTable unless the latter resolves into a Delete statement. Alternatively, outputting the Oracle TKPROF utility to file handles both the Analyze and Truncate commands.

Microsoft SQL Server

When you output the trace to a file, Application Engine writes the optimizer trace to the following location: %TEMP%\psms<queueid><spid>.trc. To read the trace, you use the SQL Server Profiler utility.

Note. The trace file is written to the server directory when you’ve specified the trace on the client. If the client has %Temp% set to a drive or directory that does not exist on the server, Application Engine does not generate a trace file.

When you output to a table, Application Engine writes the trace data to the dbo.PS_OPTIMIZER_TRC table. PeopleTools creates the table automatically when you run the trace for the first time. The trace data written to the table is identical to the data appearing in the optimizer trace file.

You also need to use the SQL Server Profiler utility to view the optimizer results. To view the populated trace table, specify the current server and database on the Source Table dialog box. The Owner value must be dbo, and the Table value PS_OPTIMIZER_TRC.

In the trace, you find information regarding text, duration, and start time for the following:

• Execution plans.

• Remote procedure calls.

• Insert statements (Update, Delete, and Select statements).

• PeopleSoft-generated user events associating trace data with a PeopleSoft SQL identifier.

If the Application Engine program terminates while you are using this trace option, check that Application Engine was not tracing a SQL statement at the moment the program terminated. If it was tracing a SQL statement at that time, you must manually kill the trace. Otherwise the trace thread on the server continues to run and lock the trace file, and each time that server process ID (SPID) is reused by the server, new information is appended to the locked trace file.

To stop the trace manually, submit the following command from Query Analyzer:

xp_trace_destroyqueue ​queueid

The queueid in the file name %TEMP%\psms_queueid_spid.trc is the ID corresponding to the queue used for the first SQL statement that the system profiled. Because this trace is only designed to trace Application Engine SQL (not PeopleTools SQL), the queue is closed after every statement profiled. Therefore, the queue that must be destroyed may not be the queue ID used in the trace file.

Note. If the %TEMP% variable is set to a location that does not exist, Application Engine does not generate a trace file.

Informix

For Informix, you can only output the trace to a file. The trace file location depends on the operating system on which your database server runs.

• UNIX.

  For UNIX, Application Engine writes the plan to the sqexplain.out file. If the client program runs on the same machine as the database server, the sqexplain.out file appears in the current directory. When the current database is on another computer, the sqexplain.out file is written to the PeopleSoft owner's directory on the remote host.

• Microsoft Windows NT.

  For Microsoft Windows NT, Application Engine writes the plan to the following file: INFORMIXDIR%\sqexpln\username.out.

DB2 for OS/390

For DB2 for OS/390, you can only output the optimizer trace to a table. PeopleSoft has implemented the following to facilitate this trace:

• PeopleSoft selects the maximum query number from the PLAN_TABLE table, increments it by 1000 to avoid clashing with other processes, and then increments it by 1 for every SQL statement traced.

• PeopleSoft sets the SET REMARKS parameter to the following value: ApplId.Section.Step.Type-RunControlId(ProcessInstance)

Note. Before using the Database Optimizer Trace, you must first create a DB2 PLAN_TABLE. Refer to your DB2 UDB for OS/390 and z/OS Administration Guide for the proper format and instructions on creating the PLAN_TABLE.

DB2 for UNIX

For DB2 for UNIX, you can only output the optimizer trace to a table. To facilitate this trace for DB2/UNIX, PeopleSoft has implemented:

EXPLAIN ALL SET QUERYNO =ProcessInstance SET QUERYTAG = 'Section.Step' FOR sql stmt

Note. Before using the Database Optimizer Trace, you must first create the DB2 explain tables.

Database Optimizer Trace and Performance

While the database optimizer trace is enabled, performance may be affected. Typically, you turn on this trace only when you are collecting detailed performance metrics. When you are not tuning your performance, turn off the optimizer trace.

To prevent an administrator, or perhaps a user, from unwittingly turning the optimizer trace on or leaving it on after doing performance tuning, you can disable the database optimizer trace for an entire database.

For example, suppose you have a production and a development database, you might want to enable the optimizer trace for the development database while disabling the optimizer trace for the production database.

On the PeopleTools Options page, clear the Allow DB Optimizer Trace option to disable the optimizer trace for the database.

Enabling Application Engine Tracing

By default, all Application Engine traces are turned off. To see a trace or a combination of traces, set trace options before you execute the program.

This section discusses how to:

• Set command line options.

• Set parameters in server configuration files.

• Set options in Configuration Manager.

Setting Command Line Options

The command line option is available for Microsoft Windows NT and UNIX, but it is not available when calling Application Engine programs from PeopleCode.

To enable tracing from the command line, specify the −TRACE option within the command line that you submit to PSAE.EXE. For example:

n:\pt840\bin\client\winx86\psae.exe -CT MICROSFT -CD PT800GES -CO PTDMO?
 -CP PTDMO -R PT8GES -AI AETESTPROG −I 45 -TRACE 2

The following table describes the available TRACE option parameter values:

To specify traces on the command line, you enter the sum of the desired trace options. This is similar to adding the trace values using PSADMIN, such as the COBOL statement timings or the SQL statement trace value. To specify a combination of traces, enter the sum of the corresponding trace values. For example, to enable the step (1), the SQL (2), and the statement timings (128) traces, you would enter 131—the sum of 1, 2, and 128.

To disable tracing, explicitly specify −TRACE 0. If you don’t include the −TRACE flag in the command line, Application Engine uses the value specified in the Process Scheduler configuration file or in Configuration Manager. Otherwise, the command-line parameters override any trace settings that may be set in Configuration Manager.

Setting Parameters in Server Configuration Files

You can also enable traces in the configuration files for both the application server and the PeopleSoft Process Scheduler server.

For programs invoked by PeopleCode and run on the application server, set the TraceAE parameter in the Trace section of the Application Server configuration file (PSAPPSRV.CFG). You can use PSADMIN to set this parameter.

In the PeopleSoft Process Scheduler configuration file, set the TraceAE parameter in the Trace section to indicate a level of tracing. You can use PSADMIN to set this parameter.

This option is available on Microsoft Windows NT and UNIX, and applies only to Application Engine programs invoked in batch mode.

Note. The TraceFile parameter does not specify the location of the Application Engine trace file; it applies only to the generic PeopleTools SQL and PeopleCode traces.

Setting Options in PeopleSoft Configuration Manager

For processes running on a Microsoft Windows workstation, you can set trace options using PeopleSoft Configuration Manager. This procedure is valid only if you are running Application Engine programs on a Microsoft Windows workstation—the development environment.

To set Application Engine traces:

1. Start Configuration Manager, and select the Trace tab.

2. Select appropriate trace options.

   You can select any combination of the options.

3. Click either the Apply or OK buttons to set trace options.

Locating Trace Files

Where you look for the generated trace file depends on how you invoked the program and the operating system on which the program runs, as shown in the following table:

When a program includes a process instance, Application Engine names the trace file according to the following convention: AE_Program_name_Process_Instance.AET. When the program does not include a process instance, Application Engine names the file according to this convention: AE_Date/Time_Stamp_OS_PID.AET. The date and time stamp is in the format month, day, hour, minute, second, with two values for each date element and no punctuation between elements. For example, August 12 at 5:09 p.m. and 30 seconds would be 0812170930.

Note. For an Application Engine program running on a server, PeopleTools writes the generic PeopleTools trace for SQL and PeopleCode trace files to the same directories as the AET traces. The prefix of the trace file name is also the same, and the suffix is trc. On the Windows workstation, the trace is written to the file specified in the People Tools Trace File field on the Trace tab of PeopleSoft Configuration Manager.