Sequence Number Allocation in PeopleSoft

In PeopleSoft for the Oracle DBA Chapter 8 (p168-170) in a section called Sequence Numbers and Concurrency I discuss the implications of how this is done in HR8.4 as a part of the save time processing in PeopleCode FUNCLIB_HR.EMPLID.FieldFormula.

[FUNCLIB_HR.EMPLID.FieldFormula]
SQLExec("Update PS_INSTALLATION Set EMPLID_LAST_EMPL = EMPLID_LAST_EMPL +  1");
SQLExec("Select EMPLID_LAST_EMPL From PS_INSTALLATION", &EMPLID);
…

The problem is that while this update remains uncommitted, nobody else can obtain a new employee ID because the row is locked. This design has scalability issues. PeopleSoft applications generally get away with this because the update is performed as a part of save time processing which is committed when that is complete. Thus the lock is held for only a short time, and never waits for a human response. It executes in the application server which should be close to the database, so there is no network latency.

However, I was looking at this same PeopleCode in HR9.0 and I have noticed that is has changed. The change appears to have been introduced in HR8.8, and uses a new built-in PeopleCode function, GetNextNumberWithGapsCommit(record.field, max_number, increment [, WHERE_Clause, paramlist]), that was introduced in PeopleTools 8.44.

PeopleBooks describes the function thus:
"Use the GetNextNumberWithGapsCommit function to return the sequence number value plus increment for the given field residing in the given record. This function also enables you to specify a SQL Where clause as part of the function for maintaining multiple sequence numbers in a single record.

This function is typically used for obtaining a new sequence number for the application ... The sequence number (record.field ) is incremented right away and it doesn't hold any database internal row lock beyond the execution of this function.

Note. A secondary database connection is used to increment and retrieve record.field. The default behaviour is to keep the secondary database connection persistent in order to improve performance for the next GetNextNumberWithGapsCommit usage. If the database administrator finds the persistent connection too high an overhead for the production environment (which should not be the case since PeopleSoft uses application server to multiplex the database connection), the database administrator can change the default behaviour to use an on-demand connection method. The persistent second connection is disabled using DbFlags bit eight in the application server and process scheduler configuration files. The second connection can be completely disabled using DbFlags bit four in the application server and process scheduler configuration files

The following restrictions apply to the GetNextNumberWithGapsCommit function:

• The function is enabled for Application Engine programs running in stand-alone mode (via PSAE). This function is disabled for Application Engine programs that execute through the PeopleSoft Application Engine server (PSAESRV).
• This function is enabled for PeopleSoft Application Engine programs running under Unix System Services on z/OS.
• PeopleSoft does not recommend Using both the GetNextNumberWithGapsCommit function and the GetNextNumber function in the same application, on the same table, in the same unit of work. This can lead to lock contention or deadlocking.
• For a DB2 z/OS database, isolate the table that contains the sequence number to its own tablespace and set the locksize parameter to row."

Hence, if migrating data into a system via a Component Interface (eg. employees from a legacy system where new EMPLIDs will be allocated), and you need to do this with multiple concurrent process to achieve throughput, it is advantageous to use PSAE rather than PSAESRV processes, otherwise they are likely to serialise.

This is the PeopleTools trace produced when I added an new person to an HR system. You can see the second connection to the database is created at line 51935, and then the row is updated, queried and immediately committed. The lock is only held for only 35ms (on my laptop), instead of holding it until all the save-time processing completes.

PSAPPSRV.4180 1-51932 23.26.14 0.000000 >>> start-ext Nest=01 assign_employee_id FUNCLIB_HR.EMPLID.FieldFormula
PSAPPSRV.4180 1-51933 23.26.14 0.019000 Cur#2.4180.HCM89 RC=0 Dur=0.015000 Connect=Secondry/HCM89/SYSADM/
PSAPPSRV.4180 1-51934 23.26.14 0.000000 SamCreateSecondary ---- Successful obtain Second DB connection
PSAPPSRV.4180 1-51935 23.26.14 0.000000 Cur#2.4180.HCM89 RC=0 Dur=0.000000 COM Stmt=UPDATE PS_INSTALLATION SET EMPLID_LAST_EMPL = EMPLID_LAST_EMPL + 1
PSAPPSRV.4180 1-51936 23.26.14 0.028000 Cur#2.4180.HCM89 RC=0 Dur=0.028000 EXE
PSAPPSRV.4180 1-51937 23.26.14 0.000000 Cur#2.4180.HCM89 RC=0 Dur=0.000000 COM Stmt=SELECT EMPLID_LAST_EMPL FROM PS_INSTALLATION
PSAPPSRV.4180 1-51938 23.26.14 0.005000 Cur#2.4180.HCM89 RC=0 Dur=0.005000 EXE
PSAPPSRV.4180 1-51939 23.26.14 0.000000 Cur#2.4180.HCM89 RC=0 Dur=0.000000 Fetch
PSAPPSRV.4180 1-51940 23.26.14 0.002000 Cur#2.4180.HCM89 RC=0 Dur=0.002000 Commit
PSAPPSRV.4180 1-51941 23.26.14 0.000000 > GetNextNumberWithGapsCommit info ( INSTALLATION, EMPLID_LAST_EMPL, (null) )

This approach is certainly an improvement over the previous behaviour. It is similar to an Oracle Sequence without any caching which increments a value stored on SYS.SEQ$ in an autonomous transaction which it immediately commits without affecting the main transaction (except that Oracle does this in the same session, and here PeopleSoft have created a separate session).

Also, like an Oracle sequence, if the main transaction fails you are left with a gap in your numbers. Some of the dictionary definitions of the word sequence imply a fixed increment or decrement between values (usually 1). In some ways, it would be more helpful to think of this a way of generating a unique identifier rather than a sequence number.

By looking at v$session you can see that a second session is created for the same client process.

Session  Serial Program                          Client    Shadow
ID  Number Name                             Process   Proces
------- ------- -------------------------------- --------- ------
Client Info                                                 LOGON_TIME
----------------------------------------------------------- -------------------
147      35 PSAPPSRV.exe                     4180:7720 5824
PS,,GO-FASTER-4.london.go-faster.co.uk,HCM89,PSAPPSRV.exe,  23:08:40 18/06/2008

139     367 PSAPPSRV.exe                     4180:7720 5824
                                                  23:26:14 18/06/2008

The DbFlags field in the Application Server and Process Scheduler parameter filess controls how PSAPPSRV and PSAE in creates and terminates the secondary session.

;-------------------------------------------------------------------------
; DbFlags Bitfield
;
; Bit       Flag
; ---       ----
; 4         - Disable Second DB Connection
; 8         - Disable Persistent Secondary DB Connection
DbFlags=0

By default, the second session persists until the PSAPPSRV session terminates when either the application server is shut down or the PSAPPSRV process recycles when the number of services reaches the recycle_count specified in the application server configuration file.

Obviously, disabling the second database connection would effectively negate the advantages of this new functionality.

There is additional overhead to the second connection, and if DbFlags is set to 8 the secondary session would be shut down after the incremented sequence number has been returned. However, in a large, highly active system, where sequence numbers are requested frequently, this would lead to frequent creation of secondary sessions. The process of allocating new sequence numbers would also have to wait for the new session to be created.

Note, CLIENT_INFO is not set in the secondary session. However, it is possible to copy the CLIENT_INFO from the primary session using an ON LOGON trigger (which can also be dowloaded from the Go-Faster website).

REM second_client_info.sql
rem (c)Go-Faster Consultancy 2008

spool second_client_info

rem requires following privileges to be granted explicitly
GRANT EXECUTE ON sys.dbms_application_info TO sysadm;
GRANT SELECT  ON sys.v_$session TO sysadm;
GRANT SELECT  ON sys.v_$process TO sysadm;
GRANT SELECT  ON sys.v_$mystat  TO sysadm;

CREATE OR REPLACE TRIGGER sysadm.connect_secondary_session
AFTER LOGON
ON sysadm.schema
DECLARE
l_client_info VARCHAR2(64);
BEGIN
SELECT SUBSTR(p.client_info||'Secondary Session',1,64)
INTO   l_client_info
FROM   v$session p           --primary session
,      v$session s           --secondary session
WHERE  s.program = p.program --same program
AND    s.process = p.process --same process
AND    s.machine = p.machine --same machine
AND    s.user# = p.user#     --same user
AND    s.sid != p.sid        --different session
AND    s.client_info IS NULL --client info not already set
AND    s.sid = (SELECT m.sid
               FROM   v$mystat m
               WHERE  rownum = 1)
AND    p.logon_time < client_info="">l_client_info);
sys.dbms_application_info.set_action(action_name=>'Secondary Session');

EXCEPTION WHEN NO_DATA_FOUND THEN NULL;
END;
/

show errors

The result is that when the second session is created the trigger fires and copies the client info from the first session and appends the string ',Second'.

LOGON_TIME          Client Info
------------------- ----------------------------------------------------------------
21:44:37 26/06/2008 PS,,GO-FASTER-4.london.go-faster.co.uk,HCM89,PSAPPSRV.exe,
08:01:29 01/07/2008 PS,,GO-FASTER-4.london.go-faster.co.uk,HCM89,PSAPPSRV.exe,Second
…

Discrepancy in Timings between Application Engine and Oracle SQL Trace

I would like to draw attention to the risk of uncritically accepting performance information from either a tool or an instrumented program. It is always necessary to consider whether you can believe what you are being told, or whether something is lying to you.

In this case, I want to highlight in the Application Engine Timings report. Take the following example from Time and Labor. The AE Timings report claims that the process spends 91.5% of the execution time in SQL. This would lead you to believe that this process is affected by the performance of the SQL, and that you need to do some SQL performance tuning.

---------------------------------------------------------------------------------
Total run time                : 1411.6
Total time in application SQL : 1291.7   Percent time in application SQL :  91.5%
Total time in PeopleCode      :  119.4   Percent time in PeopleCode      :   8.5%
Total time in cache           :    0.1   Number of calls to cache        :     3
---------------------------------------------------------------------------------

However, all is not quite as it appears. Faced with a potential SQL problem, I usually turn to Oracle SQL Trace. The following is taken from a TKPROF analysis of the trace file for the same process.

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse   153883      1.80       2.41          0          4          0           0
Execute 192806    429.94     464.96       8398     276000     588543      123140
Fetch    52740      2.75       3.55        590     202419          0       15265
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total   399429    434.49     470.93       8988     478423     588543      138405

Elapsed times include waiting on following events:
Event waited on                             Times   Max. Wait  Total Waited
----------------------------------------   Waited  ----------  ------------
SQL*Net message to client                  196521        0.00          0.13
SQL*Net message from client                196521        0.32        849.98
...
SQL*Net more data to client                114884        0.00          1.91
SQL*Net more data from client              250825        0.05          1.88
...

The database reports 849.98s for the idle event SQL*Net message from client, and only 470.93s on non-idle activity. So only 36% of the total elapsed time is spent in the database, the other 64% is time that the Application Engine process is busy executing code.

Why the discrepancy?

This is certainly a very chatty process. There are nearly 200,000 round-trip SQL*net messages between AE and Oracle. It could be a network latency problem. However, very little time is spent on the SQL*Net more data events so it is unlikely that there is a significant network component.

Let's look at the statements that have the longest times in AE timing report .

                         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
------------------------------ ------- -------- ------- -------- ------- -------- --------
PeopleCode

DELETE PS_SCH_ADHOC_DTL                           36540     60.6       0      0.0     60.6
INSERT PS_SCH_ADHOC_DTL                           71887    885.6       0      0.0    885.6
Record.SelectByKey SCH_ADHOC_DTL                  36596    118.0   36596      0.0    118.0
                                                                                  --------
                                                                                    1291.7

In less than 24 minutes, some statement have been executed very frequently. So, there were lots of SQL*Net messages, because there were lots of SQL statements. These SQL statements are submitted from PeopleCode. It is very likely we are in some sort of procedural loop, and therein lies the problem.

PeopleSoft programs can only measure the time taken to execute SQL from the perspective of the client program. In this case the timings are calculated by instrumentation inside Application Engine and PeopleCode. Meanwhile, the timings in the Oracle trace are obtained from instrumentation within the Oracle kernel.

There is still a fair amount of code in PeopleSoft that executes during the time counted as execution of SQL Statements. This is not just the SQL*Net libraries. I think that the timings include most of the time it takes for sqlexec() and Row set functions to execute. The discrepancy with the Oracle time mounts with every SQL operation.

In this case, there is very little to be gained by tuning the SQL. We can't do much about the PeopleCode because it is delivered vanilla functionality. All we can do is to bring more CPU to bear upon the problem by running multiple concurrent instances of the process.

Oracle Optimizer Statistics and Optimizer Dynamic Sampling with PeopleSoft Temporary Records

PeopleSoft Temporary Records are used for working storage during Application Engine programs. Typically, AE programs truncate and repopulate the tables before using them. PeopleSoft recognised the need to keep the statistics on these tables in line with the data that they contain, and so used the %UpdateStats macro in many places in delivered programs to update the statistics.

However, frequently gathering statistics on even small tables can become time consuming. Recently, I have been working on PeopleSoft Time and Labor. This makes heavy use of temporary records. In a single execution of TL_TIMEADMIN, several tables associated with temporary records are truncated, repopulated and analyzed many times. I discussed the problem with excessive use of truncate elsewhere giving rise to Local Write Wait.

Oracle also recognised this problem, and in version 9 of the database they introduced Optimizer Dynamic Sampling, where the database samples the data to generate statistics at statement parse time.

I am still testing, but on Oracle 10gR2 (version 10.2.0.3) I have obtained improvements in performance and stability of T&L AE processes by:

1. Deleting optimizer statistics on tables associated with temporary record in order to force the optimizer to sample at parse time
2. Locking optimizer statistics to prevents the %UpdateStats macro from putting them back on. Tables with locked statistics are also omitted by GATHER_SCHEMA_STATS and GATHER_DATABASE_STATS (unless the force option is specified) and hence also by the delivered maintenance window job to refresh stale statistics.
3. Implementing alternative DDL model that uses a PL/SQL packaged function to suppress the error when attempting to collect statistics on table whose statistics are locked (see %UpdateStats() -v- Optimizer Dynamic Sampling). This also addresses the the mix-up in the DDL models
4. The final piece of the puzzle has been to set OPTIMIZER_DYNAMIC_SAMPLING to 4 at instance level. I certainly have had problems with this parameter set to the default of 2.

The dynamic sampling levels are described in the Performance Tuning Guide 14.5.6.4.

• Level 2: Apply dynamic sampling to all unanalyzed tables.
• Level 3: As Level 2, plus all tables for which standard selectivity estimation used a guess for some predicate that is a potential dynamic sampling predicate.
• Level 4: As Level 3, plus all tables that have single-table predicates that reference 2 or more columns.

So the next stage is to identify working storage records and their associated tables.
I started off looking for tables that had recently been analysed.

ttitle 'Candidate for Locking - based on recent batches'
SELECT DISTINCT r.recname
FROM   psrecdefn r
,       (
SELECT A.RECNAME
,      SUM(B.TEMPTBLINSTANCES) TEMPTBLINSTANCES
FROM   PSAEAPPLTEMPTBL A
,      PSAEAPPLDEFN B
WHERE  A.AE_APPLID = B.AE_APPLID
AND    A.AE_APPLID LIKE 'TL%'
GROUP BY A.RECNAME
) /*pstemptblcntvw*/ i
, psoptions o
, user_tables t
, (SELECT rownum-1 row_number
  FROM   all_objects WHERE ROWNUM <= 100) v   WHERE  r.rectype IN(0,7)   AND    r.recname = i.recname   AND    v.row_number           <= i.temptblinstances + o.temptblinstances   AND    t.table_name       = DECODE(r.sqltablename,' '              ,'PS_'||r.recname,r.sqltablename)||        DECODE(v.row_number*r.rectype,0,''              ,LTRIM(TO_NUMBER(v.row_number)))    AND    t.last_analyzed > SYSDATE - 1
/
ttitle off

The following script identifies all instances of temporary tables associated with temporary records, and then deletes and locks the statistics. I started by restricting it to list of specific tables, but I think it would be perfectly reasonable to take this approach with all temporary records.

BEGIN
 FOR x IN (
  SELECT /*+LEADING(o i r v)*/ t.table_name, t.last_analyzed, t.num_rows
  ,      s.stattype_locked
  FROM pstemptblcntvw i
    INNER JOIN psrecdefn r
    ON r.recname = i.recname
    AND r.rectype = '7'
  , psoptions o
  , user_tables t
     LEFT OUTER JOIN user_tab_statistics s
     ON  s.table_name = t.table_name
     AND s.partition_name IS NULL
  , (SELECT rownum row_number
     FROM   psrecdefn 
     WHERE  ROWNUM <= 100) v                 
  WHERE  v.row_number <= i.temptblinstances + o.temptblinstances
  AND    t.table_name = DECODE(r.sqltablename,' ','PS_'||r.recname,r.sqltablename)
                      ||DECODE(v.row_number*r.rectype,100,'',LTRIM(TO_NUMBER(v.row_number))) 
/*---------------------------------------------------------------------            
--AND    r.recname IN('TL_PMTCH1_TMP' --TL_TA000600.SLCTPNCH.STATS1.S…
--                   ,'TL_PMTCH2_TMP' --TL_TA000600.CALC_DUR.STATS1.S…)
-----------------------------------------------------------------------*/
  AND   (/*  t.num_rows        IS NOT NULL --not analyzed 
        OR   t.last_analyzed   IS NOT NULL --not analyzed
        OR*/ s.stattype_locked IS     NULL --stats not locked
        ) 
) LOOP
  IF x.last_analyzed IS NOT NULL THEN --delete stats
   dbms_output.put_line('Deleting Statistics on '||user||'.'||x.table_name);
   dbms_stats.delete_table_stats(ownname=>user,tabname=>x.table_name,force=>TRUE);
  END IF;
  IF x.stattype_locked IS NULL THEN --lock stats
   dbms_output.put_line('Locking Statistics on '||user||'.'||x.table_name); 
   dbms_stats.lock_table_stats(ownname=>user,tabname=>x.table_name);
  END IF;
 END LOOP;
END;
/

Updated 11.2.2009: I have updated my advice on the use of Optimiser Dynamic Sampling (see %UpdateStats -v- Optimizer Dynamic Sampling. I still consider this to be a useful feature, but I have found scenarios where Oracle has not chosen a better plan that it did choose with explicitly gathered statistics. Therefore, I still suggest locking statistics on temporary working storage record, but where batch programs have been coded to explicitly update statistics then dbms_stats should be called with the force option to override the lock. I have updated my
DDL model wrapper script accordingly.

The scripts in this posting can be downloaded from my website

Performance Tuning the Performance Monitor Archive Process

I have been working with a PeopleSoft Performance Monitor (PPM) system that is collecting data for 7 monitored systems. Three of those systems are very active. We want to keep data for a rolling 7 days. We reached the point where the PPM archive process could not rows as fast as they were arriving! I have, of course, reduced the sample frequency of events and transactions, but the PPM is receiving between 20 and 30 million rows of history data per week.

It is also worth remarking here that since the application servers, web servers and Process Schedulers were moved to commodity Intel hardware there are now a larger number of these components, and PPM is receiving more event data.

I have taken a look inside the PPM archive process. PPM history data is removed by a PeopleCode program (PSPM_ARCHIVE.ARCHIVE.GBL.default.ARCPCODE.OnExecute) that is called from the Application Engine.

Rows of transaction date to be archived are identified by the following SQL (and there is a similar one for event data):

&TransHistSQL.Open("SELECT X.PM_INSTANCE_ID, X.PM_TRANS_DEFN_SET, X.PM_TRANS_DEFN_ID, X.PM_AGENTID, X.PM_TRANS_STATUS, X.OPRID, X.PM_PERF_TRACE, X.PM_CONTEXT_VALUE1, X.PM_CONTEXT_VALUE2, X.PM_CONTEXT_VALUE3, X.PM_CONTEXTID_1, X.PM_CONTEXTID_2, X.PM_CONTEXTID_3, X.PM_PROCESS_ID, %DateTimeOut(X.PM_AGENT_STRT_DTTM), %DateTimeOut(X.PM_MON_STRT_DTTM), X.PM_TRANS_DURATION, X.PM_PARENT_INST_ID, X.PM_TOP_INST_ID, X.PM_METRIC_VALUE1, X.PM_METRIC_VALUE2, X.PM_METRIC_VALUE3, X.PM_METRIC_VALUE4, X.PM_METRIC_VALUE5, X.PM_METRIC_VALUE6, X.PM_METRIC_VALUE7, X.PM_ADDTNL_DESCR, Z.PM_ARCHIVE_MODE FROM PSPMTRANSHIST X, PSPMAGENT Y, PSPMSYSDEFN Z WHERE X.PM_AGENTID=Y.PM_AGENTID AND Y.PM_SYSTEMID=Z.PM_SYSTEMID AND (Z.PM_ARCHIVE_MODE='1' OR Z.PM_ARCHIVE_MODE='2') AND %DateTimeDiff(X.PM_MON_STRT_DTTM, %CurrentDateTimeIn) >= (PM_MAX_HIST_AGE * 24 * 60)");

Lets look at the last condition in the WHERE clause (in bold). It uses the %DateTimeDiff PeopleCode macro to calculate the age of the row of data. This expands to.

… AND ROUND((CAST(( SYSDATE) AS DATE) - CAST((X.PM_MON_STRT_DTTM) AS DATE)) * 1440, 0) >= (PM_MAX_HIST_AGE * 24 * 60)

However, putting a function around a column prevents the database from using any index on that column. In this case it is not possible to create an function-based index to satisfy this expression because it contains SYSDATE.

The reaction of Oracle's Optimizer is to full scan the PSPMTRANSHIST table. With millions of rows of data in this table, a full scan is simply not going to perform adequately.

Instead, I would rather code something simple, but Oracle specific (and if I am going to do Oracle specific date arithmetic then there is no need to use %CurrentDateTimeIn).

… AND X.PM_MON_STRT_DTTM <= SYSDATE - PM_MAX_HIST_AGE

The PeopleCode can be adjusted to be sensitive to the database platform like this.

…
/*-- SELECT THE ROWS FROM PSPMTRANSHIST ELIGLIBLE FOR ARCHIVING */
If %DbType = "ORACLE" Then /*dmk 19.5.2008 oracle specific performance tuning*/
&TransHistSQL.Open("SELECT X.PM_INSTANCE_ID, X.PM_TRANS_DEFN_SET, X.PM_TRANS_DEFN_ID, X.PM_AGENTID, X.PM_TRANS_STATUS, X.OPRID, X.PM_PERF_TRACE, X.PM_CONTEXT_VALUE1, X.PM_CONTEXT_VALUE2, X.PM_CONTEXT_VALUE3, X.PM_CONTEXTID_1, X.PM_CONTEXTID_2, X.PM_CONTEXTID_3, X.PM_PROCESS_ID, %DateTimeOut(X.PM_AGENT_STRT_DTTM), %DateTimeOut(X.PM_MON_STRT_DTTM), X.PM_TRANS_DURATION, X.PM_PARENT_INST_ID, X.PM_TOP_INST_ID, X.PM_METRIC_VALUE1, X.PM_METRIC_VALUE2, X.PM_METRIC_VALUE3, X.PM_METRIC_VALUE4, X.PM_METRIC_VALUE5, X.PM_METRIC_VALUE6, X.PM_METRIC_VALUE7, X.PM_ADDTNL_DESCR, Z.PM_ARCHIVE_MODE FROM PSPMTRANSHIST X, PSPMAGENT Y, PSPMSYSDEFN Z WHERE X.PM_AGENTID=Y.PM_AGENTID AND Y.PM_SYSTEMID=Z.PM_SYSTEMID AND (Z.PM_ARCHIVE_MODE='1' OR Z.PM_ARCHIVE_MODE='2') AND X.PM_MON_STRT_DTTM <= SYSDATE - PM_MAX_HIST_AGE

and similarly for event data

…
/*-- SELECT THE ROWS FROM PSPMEVENTHIST ELIGLIBLE FOR ARCHIVING */
If %DbType = "ORACLE" Then
/*dmk 19.5.2008 - oracle specific performance tuning*/
&EventHistSQL.Open("SELECT X.PM_INSTANCE_ID, X.PM_EVENT_DEFN_SET, X.PM_EVENT_DEFN_ID, X.PM_AGENTID, %DateTimeOut(X.PM_AGENT_DTTM), %DateTimeOut(X.PM_MON_DTTM), X.PM_PROCESS_ID, X.PM_FILTER_LEVEL,X.PM_METRIC_VALUE1, X.PM_METRIC_VALUE2, X.PM_METRIC_VALUE3, X.PM_METRIC_VALUE4, X.PM_METRIC_VALUE5, X.PM_METRIC_VALUE6, X.PM_METRIC_VALUE7, X.PM_ADDTNL_DESCR, Z.PM_ARCHIVE_MODE FROM PSPMEVENTHIST X, PSPMAGENT Y, PSPMSYSDEFN Z WHERE X.PM_AGENTID=Y.PM_AGENTID AND Y.PM_SYSTEMID=Z.PM_SYSTEMID AND (Z.PM_ARCHIVE_MODE='1' OR Z.PM_ARCHIVE_MODE='2') AND X.PM_MON_DTTM <= SYSDATE - PM_MAX_HIST_AGE

The resulting query needs an index on PM_AGENTID and PM_MON_STRT_DTTM (on both PSPMTRANSHIST and PSPMEVENTHIST). There are delivered indexes that lead on the PM_AGENTID and have PM_MON_STRT_DTTM further down, but a dedicated index is beneficial.

Enabling Oracle Database Trace on PeopleSoft processes with a Trigger (improved)

In Chapter 11 of PeopleSoft for the Oracle DBA, I suggested using a database trigger to enable Oracle's SQL Trace facility. Then, in chapter 14, I introduced a further trigger to disable trace for Application Engine processes, in case they are run with the PSAESRV process.

This was not a good idea because the cursors opened by the Application Engine program are still open when the AE program completed, and the process updates its status from 7 (processing) to 9 (success) or 3 (error). This causes the unset_trace trigger to fire and disable SQL Trace. Consequently, the STAT lines for these cursors are never emitted to the trace file. The STAT lines contain the execution plans and a wealth of other information.

Updated 26.4.2021: Instead, I have a new version of the trace trigger (trace_trigger.sql can be downloaded from my Github repository of PeopleSoft scripts).

spool trace_trigger
rem (c)Go-Faster Consultancy Ltd. 2008

rem 1.5.2008 - moved logic to disable trace from unset_trace trigger into main trigger 
rem because cursors in AE not shut until after status is changed away from processing

ROLLBACK;
----------------------------------------------------------------
REM explicit grants by sys required on following privileges
----------------------------------------------------------------
GRANT ALTER SESSION TO sysadm;
GRANT EXECUTE ON sys.dbms_monitor TO sysadm;
GRANT EXECUTE ON sys.dbms_application_info TO SYSADM;
----------------------------------------------------------------

CREATE OR REPLACE TRIGGER sysadm.set_trace
BEFORE UPDATE OF runstatus ON sysadm.psprcsrqst
FOR EACH ROW
WHEN (new.runstatus = 7 AND old.runstatus != 7 AND new.prcstype != 'PSJob')(1)
DECLARE
  l_waits BOOLEAN := TRUE;(2)
  l_binds BOOLEAN := FALSE;
BEGIN
  --set module and action whether we are tracing or not
  sys.dbms_application_info.set_module((3)
 module_name => :new.prcsname,
 action_name => 'PI='||:new.prcsinstance
  );
   
  IF ( :new.runcntlid LIKE 'TRACEME%'(5)
  ----------------------------------------------------------------
  --code conditions for enabling trace here instead of when clause
  ----------------------------------------------------------------
  --  OR (    SUBSTR(:new.prcsname,1,3) = 'TL_'
  --      AND :new.rqstdttm <= TO_DATE('20080509','YYYYMMDD'))
  ----------------------------------------------------------------
     ) THEN

    --if we are going to trace, then set tracefile identifier
    EXECUTE IMMEDIATE 'ALTER SESSION SET TRACEFILE_IDENTIFIER(4) = '''||
      TRANSLATE(:new.prcstype     ,' -','__')||'_'||
      TRANSLATE(:new.prcsname     ,' -','__')||'_'||
      :new.prcsinstance||'_'||
       TRANSLATE(:new.servernamerun,' -','__')||
       '''';

    EXECUTE IMMEDIATE 'ALTER SESSION SET TIMED_STATISTICS = TRUE';
    EXECUTE IMMEDIATE 'ALTER SESSION SET MAX_DUMP_FILE_SIZE = 2097152'; --1Gb
    EXECUTE IMMEDIATE 'ALTER SESSION SET STATISTICS_LEVEL=ALL';

    ----------------------------------------------------------------
    --logic to determine whether you want to trace binds also
    ----------------------------------------------------------------
    IF :new.runcntlid LIKE 'TRACE%BIND%' THEN(6)
      l_binds := TRUE;
    END IF;
    ----------------------------------------------------------------

    sys.dbms_monitor.session_trace_enable(waits=>TRUE,binds=>l_binds);(7)
--  EXECUTE IMMEDIATE 'ALTER SESSION SET EVENTS ''10046 TRACE NAME CONTEXT FOREVER, LEVEL 12''';

  ELSIF :new.prcstype = 'Application Engine' THEN(8)
    --explicitly disable trace if application server process
    sys.dbms_monitor.session_trace_disable;

    --reset max dump file size AFTER disabling trace
    EXECUTE IMMEDIATE 'ALTER SESSION SET MAX_DUMP_FILE_SIZE = 5M';

    --if not tracing, then reset tracefile identifier
    EXECUTE IMMEDIATE 'ALTER SESSION SET TRACEFILE_IDENTIFIER(4) = ''''';
  END IF;
EXCEPTION WHEN OTHERS THEN NULL;
END;
/

show errors

DROP TRIGGER sysadm.unset_trace;

rem test that the trigger fires by updating something
UPDATE  sysadm.psprcsrqst new
SET     runstatus = 7
WHERE   runstatus != 7
AND     new.prcstype != 'PSJob'
AND    rownum < 1
--AND 1=2
;

ROLLBACK;
spool off

1. The trigger fires when any process begins. Previously I used logic in the WHEN clause to restrict when it fired.
2. Wait events are collected in the trace by default.
3. Irrespective of whether trace is enabled, the trigger also calls the dbms_application_info package to set the module name to the PeopleSoft Process Name, and action to the PeopleSoft Process Instance number.
4. Also irrespective of whether trace is enabled, the trace file identifier is set so that the trace file name includes the Process Type, Process Name, Process Instance Number, and the name of the Process Scheduler.
(Updated 6.2.2009) Previous versions of this trigger set tracefile identifier irrespective of whether trace was enabled. Unfortunately, this causes a small trace file to be generated for every process.5. Logic in the trigger determines whether a SQL Trace will be enabled. The supplied version of the trigger traces processes whose run controls begin with 'TRACE'
6. Additional logic has been added to also enable bind variables to be captured if the run control begins with 'TRACEBIND'.
7. The dbms_monitor package is new in Oracle 10g and is the only officially supported way to enable extended trace. If using the trigger on earlier versions of the database, it should be replaced with the commented code to set event 10046.
8. If it is not required to SQL Trace a process, and the process is an Application Engine program, then trace is explicitly disabled. Thus, if a PSAESRV process has traced an AE program, trace is disabled when it next handles a request. This has the advantage that the stat lines for the cursors are written to the trace file. However, the disadvantage is that the process continues to trace between requests, and the time between requests is reported as 'SQL*Net message from client'.