Friday, February 27, 2009

Performance Benefits of ReUse Statement Flag in Application Engine

I have achieved some significant performance improvements in some Application Engine programs by just enabling the ReUse Statement flag on certain steps. I thought I would share a recent example of how effective this can be.

I don't think I can improve on the description of this feature in PeopleBooks:
"One of the key performance features of PeopleSoft Application Engine is the ability to reuse SQL statements by dedicating a persistent cursor to that statement.

Unless you select the ReUse property for a SQL action, %BIND fields are substituted with literal values in the SQL statement. The database has to recompile the statement every time it is executed.

However, selecting ReUse converts any %BIND fields into real bind variables (:1, :2, and so on), enabling PeopleSoft Application Engine to compile the statement once, dedicate a cursor, and re-execute it with new data multiple times. This reduction in compile time can result in dramatic improvements to performance.

In addition, some databases have SQL statement caching. Every time they receive SQL, they compare it against their cache of previously executed statements to see if they have seen it before. If so, they can reuse the old query plan. This works only if the SQL text matches exactly. This is unlikely with literals instead of bind variables."

In fact most databases do this, and Oracle certainly does.

On Oracle, you could enable CURSOR_SHARING. Then Oracle effectively replaces the literals with bind variables at parse time. However, I certainly would not recommend doing this database-wide. Whenever I have tried this on a PeopleSoft system, it has had severe negative effects elsewhere. I have enabled cursor sharing at session level for specific batch programs (using a trigger), but even then it is not always beneficial.

Instead, I do recommend using the ReUse Statement flag wherever possible. It cannot just be turned on indiscriminately, the same section in PeopleBooks goes on to describe some limitations (which is probably why the default value for the flag is false).

To illustrate the kind of improvement you can obtain, here is a real-life example. This is an extract from the batch timings report at the end of the Application Engine trace file. We are interested in statements with the high compile count.

ReUse Statement is not enabled on these 4 steps. They account for more that 50% of the overall execution time.

                          PeopleSoft Application Engine Timings
(All timings in seconds)

C o m p i l e E x e c u t e F e t c h Total
SQL Statement Count Time Count Time Count Time Time
------------------------------ ------- -------- ------- -------- ------- -------- --------
99XxxXxx.Step02.S 8453 2.8 8453 685.6 0 0.0 688.4
99XxxXxx.Step03.S 8453 5.0 8453 2718.8 0 0.0 2723.8
99XxxXxx.Step05.S 8453 0.9 8453 888.4 0 0.0 889.3
99XxxXxx.Step06.S 8453 0.4 8453 17.4 0 0.0 17.8

------------------------------------------------------------------------------------------
Total run time : 8416.4
Total time in application SQL : 8195.0 Percent time in application SQL : 97.4%
Total time in PeopleCode : 192.7 Percent time in PeopleCode : 2.3%
Total time in cache : 8.7 Number of calls to cache : 8542
------------------------------------------------------------------------------------------

Now, I have enabled ReUse Statement on these steps. I have not changed anything else.

                         C o m p i l e    E x e c u t e    F e t c h        Total
SQL Statement Count Time Count Time Count Time Time
------------------------------ ------- -------- ------- -------- ------- -------- --------
99XxxXxx.Step02.S 1 0.0 8453 342.3 0 0.0 342.3
99XxxXxx.Step03.S 1 0.0 8453 83.3 0 0.0 83.3
99XxxXxx.Step05.S 1 0.0 8453 8.7 0 0.0 8.7
99XxxXxx.Step06.S 1 0.0 8453 7.6 0 0.0 7.6
------------------------------------------------------------------------------------------
Total run time : 5534.1
Total time in application SQL : 5341.7 Percent time in application SQL : 96.5%
Total time in PeopleCode : 190.8 Percent time in PeopleCode : 3.4%
Total time in cache : 1.1 Number of calls to cache : 90
------------------------------------------------------------------------------------------

Notice that:
  • The number of compilations for each step has gone down to 1, though the number of executions remains the same
  • The execution time for the first three statements has fallen by nearly 90%.
  • The improvement in the 4th statement is quite modest because it did not contain any bind variables, but clearly some of the time reported as execution time by Application Engine is associated with the preparation of a new SQL statement.
To emphasise the point, lets look at the effect on the database. The following are extracts from the TKPROF output for Oracle SQL trace files for these processes.

First the TKPROF without ReUse Statement:

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 101063 2600.60 2602.83 6197 661559 4 0
Execute 101232 1817.96 3787.17 1572333 73729207 10617830 4770112
Fetch 96186 385.41 1101.47 374425 25986600 0 96285
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 298481 4803.97 7491.48 1952955 100377366 10617834 4866397

Misses in library cache during parse: 25498
Misses in library cache during execute: 90

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1199472 0.36 2601.83
SQL*Net message from client 130345 1.57 296.50
db file scattered read 8816 0.39 171.47

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 100002 13.51 13.57 17 820 94 0
Execute 131495 30.00 31.31 7025 29277 21164 74315
Fetch 141837 218.77 295.49 159969 3039304 12 519406
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 373334 262.28 340.38 167011 3069401 21270 593721

160446 user SQL statements in session.

70478 internal SQL statements in session.
230924 SQL statements in session.

And now with ReUse Statement set on only those four steps

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 67238 10.24 10.75 47 4415 9 0
Execute 101160 1650.25 4040.88 1766325 129765633 11160830 4781797
Fetch 96123 385.50 1024.50 372737 26097251 0 103844
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 264521 2045.99 5076.14 2139109 155867299 11160839 4885641

Misses in library cache during parse: 73
Misses in library cache during execute: 21

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 1506834 0.61 2839.19
SQL*Net message from client 130312 1.53 258.81
db file scattered read 8782 0.37 147.01

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1331 0.46 0.46 0 173 16 0
Execute 4044 2.72 5.82 12923 33374 24353 113323
Fetch 5697 8.38 13.43 15550 55431 12 13449
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11072 11.56 19.72 28473 88978 24381 126772

67425 user SQL statements in session.

3154 internal SQL statements in session.
70579 SQL statements in session.

  • Nearly all the saving is in parse time of non-recursive statements, the rest is the reduction of recursive SQL because there is less parsing.
  • There is less parsing, because there are fewer different SQL statements submitted by Application Engine. The number of user statements has fallen from 160446 to 67425.
  • The number of misses on the library cache has fallen from 25498 to just 73.
  • There has been a reduction in SQL*Net message from client (database idle time) from 296 seconds to 253 because the Application Engine program spends less time compiling SQL statements.
Conclusion

Enabling ReUse Statement can have a very significant effect on the performance of Application Engine batches. It is most effective when SQL statements with %BIND() variables are executed within loops. Otherwise, for each execution of the loop, Application Engine must recompile the SQL statement with different bind variable values, which the database will treat as a new statement that must be parsed.

SQL parsing is CPU intensive. Reducing excessive parse also reduces CPU consumption on the database server. It can also reduce physical I/O to the database catalogue. On PeopleSoft 8.x applications that use Unicode, the overhead of parsing is magnified by the use of length checking constraints on all character columns. This is no longer an issue in version 9 applications which use character semantics.

If you use Oracle's Automatic Memory Management, excessive parsing can cause the database to allocate more memory to the Shared Pool at the expense of the Block Buffer Cache. This in turn can increase physical I/O and can degrade query performance.

Bind Variables are a good thing. You should use them. Therefore, ReUse Statement is also a good thing. You should use that too!

Thursday, February 26, 2009

Do You Need More Temporary Table Instances?

When an Application Engine loads a program prior to execution, it attempts to allocate an instance of each temporary record specified in the program to itself. If the allocation of a table fails because there are no available instances, Application Engine is will use the shared instance (unless the program is configured to abort if non-shared tables cannot be assigned). In this case it will write an entry to the message log to warn that the shared instance of the record has been used.

When processes use the shared tables performance is likely to be degraded by contention on the table. The %TruncateTable() PeopleCode macro generates a DELETE by process instance on the shared table instead of a TRUNCATE command.

The problem is that unless you look in the message log, you will not know that this is happening. However, it easy to write a query that will look at the message log table and report whenever this has occurred.

select  p.message_parm recname, r.prcsname
, count(*) occurances
, max(l.dttm_stamp_sec) last_occurance
, max(p.process_instance) process_instance
from ps_message_log l
, ps_message_logparm p
left outer join psprcsrqst r
on r.prcsinstance = p.process_instance
where l.message_set_nbr = 108
and l.message_nbr = 544
and p.process_instance = l.process_instance
and p.message_seq = l.message_seq
and l.dttm_stamp_sec >= sysdate - 7
group by p.message_parm, r.prcsname
order by 1,2
/

This report tells you which programs failed to allocated instances of which record, how many times that has happened within the last 7 days.

            Processes Unable to Allocate Non-Shared Temporary Record

Last
Record Process Last Process
Name Name Occurrences Occurrence Instance
--------------- ------------ ----------- ------------------- ----------
TL_ABS_WRK TL_TIMEADMIN 4 08:24:39 01/01/2009 12345
TL_ATTND_HST1 TL_TIMEADMIN 10 08:23:40 01/01/2009 12345
TL_COMP_BAL TL_TIMEADMIN 11 08:23:40 01/01/2009 12345
...

NB: Just because an Application Engine could not allocate a non-shared table, does not automatically imply that you need more instances of that record. It could be that other processes had failed, but the temporary tables are still allocated to the process until the process is either restarted and completes successfully, or the process is deleted or cancelled.

You might choose to create some spare instances of records to allow for failed processes, but if you do not clear failed processes you will eventually run out of instances.

Wednesday, February 11, 2009

UKOUG PeopleSoft Conference 2009 - Call for Papers

Building on the success of the inaugural UKOUG PeopleSoft Conference & Exhibition in 2008, this Conference, presented by UKOUG and GPUG, will provide a forum for the presentation and exchange of ideas and practical experiences within the areas of PeopleSoft Financials, HCM/HR and Technology. The multi-stream agenda will feature keynote presentations, technical and non-technical sessions, roundtables, panel discussions and more.
If you are interested in sharing your experience of using PeopleSoft technology and applications, here is your chance as the call for papers is now open.

Deadlines are tight.  Submit your abstracts now at: www.oug.org/peoplesoft

Closing date for submissions: Friday 27th February.

The review panel, comprised of PeopleSoft community members, will evaluate all abstracts submitted by the closing date. The authors of accepted abstracts will receive confirmation at the beginning of March.