Trace File Sections

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:

Column	Description
SQL Statement	Application Engine SQL actions and stored SQL objects always have a statement ID. The SQL Statement column shows the statement ID so that you can attribute trace values to individual SQL statements. In the case of SQLExec SQL, a portion of the SQL statement appears in the first column to help you identify it. For SQL objects, use the TraceName property in the Create SQL so that you can uniquely identify it in the traces.
Compile Column	This column shows how many times the system compiled a SQL statement and how long the compilation took. The term compiled refers to the SQL statement being sent to the database to be parsed and optimized, and it also includes the time required for the first resolution of any PeopleSoft meta-SQL.
Execute Column	This column shows how many times the system executed the SQL statement and the time consumed doing so. The term executed refers to the system sending the compiled SQL to the database server to be run against the database.
Fetch Column	This column applies to Select statements. It shows how many rows your program fetched from the database and how much time this consumed. The system must first execute a Select statement against the database to find the relevant rows and generate an active set. After the set exists, the program must still fetch the rows. Some database APIs have buffered fetches, which means that the fetch may include more than one row. Therefore, subsequent fetches are free until the buffer becomes empty.
Total Column	This column shows the sum of the compile, execute, and fetch times of the SQL statement. Some database application programming interfaces (APIs may defer a compile to the execute phase or defer an execute to the first fetch operation.
PeopleCode SQL	This subsection is for SQL run from PeopleCode actions. Compile counts and times for such SQL is included in execute count and times because you do not explicitly control the ReUse feature. To determine whether ReUse is occurring, you must do a program run after enabling the generic PeopleTools trace for SQL statements, API calls, and so on. As a starting point, use a trace value of 31.
Application Engine SQL	This subsection reveals the time attributed to Application Engine overhead that is not directly related to the SQL within your program. For example, the values in this section represent the SQL generated for checkpoints, commits, and so on. If there are Commit statements without checkpoints, it indicates that restart has been disabled, or a restartable program has called a non-restartable program. If the time consumed performing a checkpoint or committing seems more than expected, you should try to reduce it if possible by setting the commit frequency of the steps containing Do loops.
AE Program: program_name	This subsection shows SQL actions for a particular program. The action properties that affect performance are flagged. For example, BulkInsert. ReUse is not flagged because it is self-evident when the Execute count is higher than the compile count.

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:

Column	Description
PeopleCode	The names of the PeopleCode actions in your program.
Call	How many times each PeopleCode action is called during a program run.
Non-SQL	The time spent running non-SQL actions.
SQL	Time spent running SQL. The total SQL time should be similar to that of the PeopleCode SQL subsection in the first section of the trace file.
Total	The cumulative amount of time spent on an action.

Note:

The system rounds to the first decimal place (tenths), but only after it calculates 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 the 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 provide an overview of the program run without providing too many details.

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

Column	Description
Total run time	The overall amount of time a program required to complete from start to finish.
Time in application SQL	The time that your program spent executing SQL. This value includes SQL run by both PeopleCode and SQL actions.
Percent time in application SQL	The percentage of time spent running SQL compared to the entire program run.
Time in PeopleCode	The time the program spent running PeopleCode. Time in PeopleCode excludes SQL run from within PeopleCode.
Percent time in PeopleCode	The percentage of time spent running PeopleCode compared to the entire program run.
Total time in Cache	The amount of time the program spent retrieving objects from the cache or refreshing the cache. Total time in cache includes all memory cache access, file cache access, and SQL run to load managed objects such as Application Engine program components, metadata, and so on. Time varies according to where Application Engine finds an object. For instance, retrieving an object that the system cached during a previous run is faster than retrieving it from the database.
Number of calls to Cache	The actual number of calls the program made to the cache. The number of calls to the cache remains constant for the same Application Engine program processing the same data.

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 set.

Each trace produces an unavoidable degree of overhead. As a result, 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 information about:

SQL traces.
PeopleCode traces.
Application Engine traces.
Application Engine DbFlags (%UpdateStats).