Monday, August 25, 2014

To Hint or not to hint (Application Engine), that is the question

Over the years Oracle has provided a number of plan stability technologies to control how SQL statements are executed.  At the risk of over simplification, Outlines (deprecated in 11g), Profiles, Baselines and Patches work by injecting a set of hints into a SQL statement at parse time.  There is quite a lot of advice from Oracle to use these technologies to fix errant execution plans rather than hint the application.  I think it is generally good advice, however, there are times when this approach does not work well with PeopleSoft, and that is due to the behaviour and structure of PeopleSoft rather than the Oracle database.

It is possible to produce a SQL profile from a plan captured by AWR.  A part of distribution for the SQLT Diagnostic Tool (Doc ID 215187.1) is a script called coe_xfr_sql_profile.sql written by Carlos Sierra.
The only thing I would change in the delivered script, (for use with PeopleSoft and as suggested in a comment) is to create the profile with FORCE_MATCHING so that similar statements with different literal values still match. 

The Slings and Arrows of outrageous execution plans

Let's take an example of a statement (from the vanilla Financials product that has not been customised) that performed poorly because it didn't generate a good execution plan (although I have cut out most of the statement for readability.  Note, that it references instance 5 of PeopleTools temporary record CA_SUM_TAO.
INSERT INTO PS_CA_SUM_RC_TAO5 (…) SELECT
…
FROM PS_CA_PR_SUMM A, PS_CA_SUM_TAO5 B , PS_CA_SUM_IN_USE C WHERE
…
B.PROCESS_INSTANCE = 51381955 AND C.IN_USE_FLAG = 'Y'

Plan hash value: 2039212279
----------------------------------------------------------------------------------------------------
| Id  | Operation                       | Name             | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT                |                  |       |       | 14424 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL        |                  |       |       |            |          |
|   2 |   NESTED LOOPS                  |                  |       |       |            |          |
|   3 |    NESTED LOOPS                 |                  |     1 |   430 | 14424   (1)| 00:02:54 |
|   4 |     NESTED LOOPS                |                  |     1 |   318 | 14421   (1)| 00:02:54 |
|   5 |      TABLE ACCESS FULL          | PS_CA_SUM_IN_USE |     1 |    85 | 14420   (1)| 00:02:54 |
|   6 |      TABLE ACCESS BY INDEX ROWID| PS_CA_SUM_TAO5   |     1 |   233 |     1   (0)| 00:00:01 |
|   7 |       INDEX UNIQUE SCAN         | PS_CA_SUM_TAO5   |     1 |       |     0   (0)|          |
|   8 |     INDEX RANGE SCAN            | PSACA_PR_SUMM    |     1 |       |     2   (0)| 00:00:01 |
|   9 |    TABLE ACCESS BY INDEX ROWID  | PS_CA_PR_SUMM    |     1 |   112 |     3   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------
However, below is the plan we get on instance 4.  We get this plan because there is already a profile that has been applied in the past, but now we are on a different non-shared instance of the temporary table, so the profile cannot match because we are on different objects, and we get the same problem, but on different non-shared instances of the temporary record.  Different literal values, such as those for Process Instance can be handled by FORCE_MATCHING, but not different tables.  This is a totally different SQL statement.
SQL_ID 5gtxdqbx0d0c3
--------------------
INSERT INTO PS_CA_SUM_RC_TAO4 (…) SELECT 
…
FROM PS_CA_PR_SUMM A, PS_CA_SUM_TAO4 B , PS_CA_SUM_IN_USE C WHERE
…
B.PROCESS_INSTANCE = 51377796 AND C.IN_USE_FLAG = 'Y'

Plan hash value: 3552771247

---------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name             | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------------
|   0 | INSERT STATEMENT               |                  |       |       | 36361 (100)|          |
|   1 |  LOAD TABLE CONVENTIONAL       |                  |       |       |            |          |
|   2 |   HASH JOIN                    |                  |     1 |   430 | 36361   (3)| 00:07:17 |
|   3 |    TABLE ACCESS FULL           | PS_CA_SUM_IN_USE |     1 |    85 | 14347   (1)| 00:02:53 |
|   4 |    NESTED LOOPS                |                  |       |       |            |          |
|   5 |     NESTED LOOPS               |                  |     1 |   345 | 22014   (3)| 00:04:25 |
|   6 |      TABLE ACCESS FULL         | PS_CA_PR_SUMM    |  5268K|   562M| 21539   (1)| 00:04:19 |
|   7 |      INDEX UNIQUE SCAN         | PS_CA_SUM_TAO4   |     1 |       |     0   (0)|          |
|   8 |     TABLE ACCESS BY INDEX ROWID| PS_CA_SUM_TAO4   |     1 |   233 |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------

Note
-----
   - SQL profile "coe_gn3n77gs6xj2a_3552771247" used for this statement
Of course, the statement on instance 4 had a profile because it was added as a short term fix and then left in situ long term.  It worked fine until a process errored, left the non-shared instance of the temporary record allocated to that process instance, and so PeopleSoft allocated instance 5 on the next execution.
So we could just create another profile using the coe_xfr_sql_profile.sql script
SPO coe_xfr_sql_profile_5gtxdqbx0d0c3_3552771247.log;
SET ECHO ON TERM ON LIN 2000 TRIMS ON NUMF 99999999999999999999;
REM
REM $Header: 215187.1 coe_xfr_sql_profile_5gtxdqbx0d0c3_3552771247.sql 11.4.1.4 2014/08/13 csierra $
REM
REM Copyright (c) 2000-2010, Oracle Corporation. All rights reserved.
REM
REM AUTHOR
REM   carlos.sierra@oracle.com
REM
REM SCRIPT
REM   coe_xfr_sql_profile_5gtxdqbx0d0c3_3552771247.sql
REM
REM DESCRIPTION
REM   This script is generated by coe_xfr_sql_profile.sql
REM   It contains the SQL*Plus commands to create a custom
REM   SQL Profile for SQL_ID 5gtxdqbx0d0c3 based on plan hash
REM   value 3552771247.
REM   The custom SQL Profile to be created by this script
REM   will affect plans for SQL commands with signature
REM   matching the one for SQL Text below.
REM   Review SQL Text and adjust accordingly.
REM
REM PARAMETERS
REM   None.
REM
REM EXAMPLE
REM   SQL> START coe_xfr_sql_profile_5gtxdqbx0d0c3_3552771247.sql;
REM
REM NOTES
REM   1. Should be run as SYSTEM or SYSDBA.
REM   2. User must have CREATE ANY SQL PROFILE privilege.
REM   3. SOURCE and TARGET systems can be the same or similar.
REM   4. To drop this custom SQL Profile after it has been created:
REM      EXEC DBMS_SQLTUNE.DROP_SQL_PROFILE('coe_5gtxdqbx0d0c3_3552771247');
REM   5. Be aware that using DBMS_SQLTUNE requires a license
REM      for the Oracle Tuning Pack.
REM
WHENEVER SQLERROR EXIT SQL.SQLCODE;
REM
VAR signature NUMBER;
REM
DECLARE
sql_txt CLOB;
h       SYS.SQLPROF_ATTR;
BEGIN
sql_txt := q'[
INSERT INTO PS_CA_SUM_RC_TAO4 (PROCESS_INSTANCE, BUSINESS_UNIT, PROJECT_ID, ACTIVITY_ID, ANALYSIS_TYPE, RESOURCE_TYPE, RESOURCE_CATEGORY, RESOURCE_SUB_CAT, BI_DISTRIB_STATUS, GL_DISTRIB_STATUS, FOREIGN_CURRENCY, CONTRACT_CURRENCY, CONTRACT_NUM, CONTRACT_LINE_NUM, CA_FEE_STATUS, RESOURCE_QUANTITY, FOREIGN_AMOUNT_BSE, FOREIGN_AMOUNT_INC, FOREIGN_AMOUNT, CONTRACT_AMT_BSE, CONTRACT_AMT_INC, CONTRACT_AMT, MIN_TRANS_DT, MAX_TRANS_DT, CAND_MIN_TRANS_DT, CAND_MAX_TRANS_DT) SELECT B.PROCESS_INSTANCE, A.BUSINESS_UNIT, A.PROJECT_ID, A.ACTIVITY_ID, A.ANALYSIS_TYPE, A.RESOURCE_TYPE, A.RESOURCE_CATEGORY, A.RESOURCE_SUB_CAT, A.BI_DISTRIB_STATUS, A.GL_DISTRIB_STATUS,
A.FOREIGN_CURRENCY, A.CONTRACT_CURRENCY, A.CONTRACT_NUM, A.CONTRACT_LINE_NUM, A.CA_FEE_STATUS, (A.RESOURCE_QUANTITY+B.RESOURCE_QUANTITY), A.FOREIGN_AMOUNT, B.FOREIGN_AMOUNT, (A.FOREIGN_AMOUNT+B.FOREIGN_AMOUNT), A.CONTRACT_AMT, B.CONTRACT_AMT, (A.CONTRACT_AMT+B.CONTRACT_AMT), A.MIN_TRANS_DT, A.MAX_TRANS_DT, B.CAND_MIN_TRANS_DT, B.CAND_MAX_TRANS_DT FROM PS_CA_PR_SUMM A, PS_CA_SUM_TAO4 B , PS_CA_SUM_IN_USE C WHERE B.BUSINESS_UNIT = C.BUSINESS_UNIT AND B.PROJECT_ID = C.PROJECT_ID AND B.ACTIVITY_ID = C.ACTIVITY_ID AND B.ANALYSIS_TYPE = C.ANALYSIS_TYPE AND B.RESOURCE_TYPE = C.RESOURCE_TYPE AND B.RESOURCE_CATEGORY = C.RESOURCE_CATEGORY AND B.RESOURCE_SUB_CAT =
C.RESOURCE_SUB_CAT AND B.BI_DISTRIB_STATUS = C.BI_DISTRIB_STATUS AND B.GL_DISTRIB_STATUS = C.GL_DISTRIB_STATUS AND B.FOREIGN_CURRENCY = C.FOREIGN_CURRENCY AND B.CONTRACT_CURRENCY = C.CONTRACT_CURRENCY AND B.CONTRACT_NUM = C.CONTRACT_NUM AND B.CONTRACT_LINE_NUM = C.CONTRACT_LINE_NUM AND B.CA_FEE_STATUS = C.CA_FEE_STATUS AND A.BUSINESS_UNIT = B.BUSINESS_UNIT AND A.PROJECT_ID = B.PROJECT_ID AND A.ACTIVITY_ID = B.ACTIVITY_ID AND A.ANALYSIS_TYPE = B.ANALYSIS_TYPE AND A.RESOURCE_TYPE = B.RESOURCE_TYPE AND A.RESOURCE_CATEGORY = B.RESOURCE_CATEGORY AND A.RESOURCE_SUB_CAT = B.RESOURCE_SUB_CAT AND A.BI_DISTRIB_STATUS = B.BI_DISTRIB_STATUS AND A.GL_DISTRIB_STATUS =
B.GL_DISTRIB_STATUS AND A.FOREIGN_CURRENCY = B.FOREIGN_CURRENCY AND A.CONTRACT_CURRENCY = B.CONTRACT_CURRENCY AND A.CONTRACT_NUM = B.CONTRACT_NUM AND A.CONTRACT_LINE_NUM = B.CONTRACT_LINE_NUM AND A.CA_FEE_STATUS = B.CA_FEE_STATUS AND B.PROCESS_INSTANCE = 51377796 AND C.IN_USE_FLAG = 'Y'
]';
h := SYS.SQLPROF_ATTR(
q'[BEGIN_OUTLINE_DATA]',
q'[IGNORE_OPTIM_EMBEDDED_HINTS]',
q'[OPTIMIZER_FEATURES_ENABLE('11.2.0.3')]',
q'[DB_VERSION('11.2.0.3')]',
q'[OPT_PARAM('_unnest_subquery' 'false')]',
q'[OPT_PARAM('optimizer_dynamic_sampling' 4)]',
q'[OPT_PARAM('_optimizer_cost_based_transformation' 'off')]',
q'[ALL_ROWS]',
q'[OUTLINE_LEAF(@"SEL$1")]',
q'[OUTLINE_LEAF(@"INS$1")]',
q'[FULL(@"INS$1" "PS_CA_SUM_RC_TAO4"@"INS$1")]',
q'[FULL(@"SEL$1" "A"@"SEL$1")]',
q'[INDEX(@"SEL$1" "B"@"SEL$1" ("PS_CA_SUM_TAO4"."PROCESS_INSTANCE" "PS_CA_SUM_TAO4"."BUSINESS_UNIT" "PS_CA_SUM_TAO4"."PROJECT_ID" "PS_CA_SUM_TAO4"."ACTIVITY_ID" "PS_CA_SUM_TAO4"."ANALYSIS_TYPE" "PS_CA_SUM_TAO4"."RESOURCE_TYPE" "PS_CA_SUM_TAO4"."RESOURCE_CATEGORY" "PS_CA_SUM_TAO4"."RESOURCE_SUB_CAT" "PS_CA_SUM_TAO4"."BI_DISTRIB_STATUS" "PS_CA_SUM_TAO4"."GL_DISTRIB_STATUS" "PS_CA_SUM_TAO4"."FOREIGN_CURRENCY" "PS_CA_SUM_TAO4"."CONTRACT_CURRENCY" "PS_CA_SUM_TAO4"."CONTRACT_NUM" ]',
q'[    "PS_CA_SUM_TAO4"."CONTRACT_LINE_NUM" "PS_CA_SUM_TAO4"."CA_FEE_STATUS"))]',
q'[FULL(@"SEL$1" "C"@"SEL$1")]',
q'[LEADING(@"SEL$1" "A"@"SEL$1" "B"@"SEL$1" "C"@"SEL$1")]',
q'[USE_NL(@"SEL$1" "B"@"SEL$1")]',
q'[NLJ_BATCHING(@"SEL$1" "B"@"SEL$1")]',
q'[USE_HASH(@"SEL$1" "C"@"SEL$1")]',
q'[SWAP_JOIN_INPUTS(@"SEL$1" "C"@"SEL$1")]',
q'[END_OUTLINE_DATA]');
:signature := DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE(sql_txt);
DBMS_SQLTUNE.IMPORT_SQL_PROFILE (
sql_text    => sql_txt,
profile     => h,
name        => 'coe_5gtxdqbx0d0c3_3552771247',
description => 'coe 5gtxdqbx0d0c3 3552771247 '||:signature||'',
category    => 'DEFAULT',
validate    => TRUE,
replace     => TRUE,
force_match => TRUE /* TRUE:FORCE (match even when different literals in SQL). FALSE:EXACT (similar to CURSOR_SHARING) */ );
END;
/
WHENEVER SQLERROR CONTINUE
SET ECHO OFF;
PRINT signature
PRO
PRO ... manual custom SQL Profile has been created
PRO
SET TERM ON ECHO OFF LIN 80 TRIMS OFF NUMF "";
SPO OFF;
PRO
PRO COE_XFR_SQL_PROFILE_5gtxdqbx0d0c3_3552771247 completed
But then we must manually change the table and index names from 4 to 5.
DECLARE
sql_txt CLOB;
h       SYS.SQLPROF_ATTR;
BEGIN
sql_txt := q'[
INSERT INTO PS_CA_SUM_RC_TAO5 (PROCESS_INSTANCE, BUSINESS_UNIT, PROJECT_ID, ACTIVITY_ID, ANALYSIS_TYPE, RESOURCE_TYPE, RESOURCE_CATEGORY, RESOURCE_SUB_CAT, BI_DISTRIB_STATUS, GL_DISTRIB_STATUS, FOREIGN_CURRENCY, CONTRACT_CURRENCY, CONTRACT_NUM, CONTRACT_LINE_NUM, CA_FEE_STATUS, RESOURCE_QUANTITY, FOREIGN_AMOUNT_BSE, FOREIGN_AMOUNT_INC, FOREIGN_AMOUNT, CONTRACT_AMT_BSE, CONTRACT_AMT_INC, CONTRACT_AMT, MIN_TRANS_DT, MAX_TRANS_DT, CAND_MIN_TRANS_DT, CAND_MAX_TRANS_DT) SELECT B.PROCESS_INSTANCE, A.BUSINESS_UNIT, A.PROJECT_ID, A.ACTIVITY_ID, A.ANALYSIS_TYPE, A.RESOURCE_TYPE, A.RESOURCE_CATEGORY, A.RESOURCE_SUB_CAT, A.BI_DISTRIB_STATUS, A.GL_DISTRIB_STATUS,
A.FOREIGN_CURRENCY, A.CONTRACT_CURRENCY, A.CONTRACT_NUM, A.CONTRACT_LINE_NUM, A.CA_FEE_STATUS, (A.RESOURCE_QUANTITY+B.RESOURCE_QUANTITY), A.FOREIGN_AMOUNT, B.FOREIGN_AMOUNT, (A.FOREIGN_AMOUNT+B.FOREIGN_AMOUNT), A.CONTRACT_AMT, B.CONTRACT_AMT, (A.CONTRACT_AMT+B.CONTRACT_AMT), A.MIN_TRANS_DT, A.MAX_TRANS_DT, B.CAND_MIN_TRANS_DT, B.CAND_MAX_TRANS_DT FROM PS_CA_PR_SUMM A, PS_CA_SUM_TAO5 B , PS_CA_SUM_IN_USE C WHERE B.BUSINESS_UNIT = C.BUSINESS_UNIT AND B.PROJECT_ID = C.PROJECT_ID AND B.ACTIVITY_ID = C.ACTIVITY_ID AND B.ANALYSIS_TYPE = C.ANALYSIS_TYPE AND B.RESOURCE_TYPE = C.RESOURCE_TYPE AND B.RESOURCE_CATEGORY = C.RESOURCE_CATEGORY AND B.RESOURCE_SUB_CAT =
C.RESOURCE_SUB_CAT AND B.BI_DISTRIB_STATUS = C.BI_DISTRIB_STATUS AND B.GL_DISTRIB_STATUS = C.GL_DISTRIB_STATUS AND B.FOREIGN_CURRENCY = C.FOREIGN_CURRENCY AND B.CONTRACT_CURRENCY = C.CONTRACT_CURRENCY AND B.CONTRACT_NUM = C.CONTRACT_NUM AND B.CONTRACT_LINE_NUM = C.CONTRACT_LINE_NUM AND B.CA_FEE_STATUS = C.CA_FEE_STATUS AND A.BUSINESS_UNIT = B.BUSINESS_UNIT AND A.PROJECT_ID = B.PROJECT_ID AND A.ACTIVITY_ID = B.ACTIVITY_ID AND A.ANALYSIS_TYPE = B.ANALYSIS_TYPE AND A.RESOURCE_TYPE = B.RESOURCE_TYPE AND A.RESOURCE_CATEGORY = B.RESOURCE_CATEGORY AND A.RESOURCE_SUB_CAT = B.RESOURCE_SUB_CAT AND A.BI_DISTRIB_STATUS = B.BI_DISTRIB_STATUS AND A.GL_DISTRIB_STATUS =
B.GL_DISTRIB_STATUS AND A.FOREIGN_CURRENCY = B.FOREIGN_CURRENCY AND A.CONTRACT_CURRENCY = B.CONTRACT_CURRENCY AND A.CONTRACT_NUM = B.CONTRACT_NUM AND A.CONTRACT_LINE_NUM = B.CONTRACT_LINE_NUM AND A.CA_FEE_STATUS = B.CA_FEE_STATUS AND B.PROCESS_INSTANCE = 51377796 AND C.IN_USE_FLAG = 'Y'
]';
h := SYS.SQLPROF_ATTR(
q'[BEGIN_OUTLINE_DATA]',
q'[IGNORE_OPTIM_EMBEDDED_HINTS]',
q'[OPTIMIZER_FEATURES_ENABLE('11.2.0.3')]',
q'[DB_VERSION('11.2.0.3')]',
q'[OPT_PARAM('_unnest_subquery' 'false')]',
q'[OPT_PARAM('optimizer_dynamic_sampling' 4)]',
q'[OPT_PARAM('_optimizer_cost_based_transformation' 'off')]',
q'[ALL_ROWS]',
q'[OUTLINE_LEAF(@"SEL$1")]',
q'[OUTLINE_LEAF(@"INS$1")]',
q'[FULL(@"INS$1" "PS_CA_SUM_RC_TAO5"@"INS$1")]',
q'[FULL(@"SEL$1" "A"@"SEL$1")]',
q'[INDEX(@"SEL$1" "B"@"SEL$1" ("PS_CA_SUM_TAO5"."PROCESS_INSTANCE" "PS_CA_SUM_TAO5"."BUSINESS_UNIT" "PS_CA_SUM_TAO5"."PROJECT_ID" "PS_CA_SUM_TAO5"."ACTIVITY_ID" "PS_CA_SUM_TAO5"."ANALYSIS_TYPE" "PS_CA_SUM_TAO5"."RESOURCE_TYPE" "PS_CA_SUM_TAO5"."RESOURCE_CATEGORY" "PS_CA_SUM_TAO5"."RESOURCE_SUB_CAT" "PS_CA_SUM_TAO5"."BI_DISTRIB_STATUS" "PS_CA_SUM_TAO5"."GL_DISTRIB_STATUS" "PS_CA_SUM_TAO5"."FOREIGN_CURRENCY" "PS_CA_SUM_TAO5"."CONTRACT_CURRENCY" "PS_CA_SUM_TAO5"."CONTRACT_NUM" ]',
q'[    "PS_CA_SUM_TAO5"."CONTRACT_LINE_NUM" "PS_CA_SUM_TAO5"."CA_FEE_STATUS"))]',
q'[FULL(@"SEL$1" "C"@"SEL$1")]',
q'[LEADING(@"SEL$1" "A"@"SEL$1" "B"@"SEL$1" "C"@"SEL$1")]',
q'[USE_NL(@"SEL$1" "B"@"SEL$1")]',
q'[NLJ_BATCHING(@"SEL$1" "B"@"SEL$1")]',
q'[USE_HASH(@"SEL$1" "C"@"SEL$1")]',
q'[SWAP_JOIN_INPUTS(@"SEL$1" "C"@"SEL$1")]',
q'[END_OUTLINE_DATA]');
:signature := DBMS_SQLTUNE.SQLTEXT_TO_SIGNATURE(sql_txt);
DBMS_SQLTUNE.IMPORT_SQL_PROFILE (
sql_text    => sql_txt,
profile     => h,
name        => 'coe_5gtxdqbx0d0c3_3552771247',
description => 'coe 5gtxdqbx0d0c3 3552771247 '||:signature||'',
category    => 'DEFAULT',
validate    => TRUE,
replace     => TRUE,
force_match => TRUE /* TRUE:FORCE (match even when different literals in SQL). FALSE:EXACT (similar to CURSOR_SHARING) */ );
END;
/

Or to take Arms against a Sea of statements,

The profile has advantage that it can be applied quickly without a code change.  It is the perfect tool for the DBA with a production performance problem. However, there are some other considerations.
  • If applying to statement that references a PS temp record then we need to apply the profile to all instances of the record (both non-shared instances and the shared instance).
  • We were lucky that we referenced instance 5 of two temporary records. However, you could get a situation where a statement references different instances of different temporary records.  So perhaps instance 5 of one table and instance 6 of another.  In which case, you might also get instance 6 of the first table and instance 5 of the other.  A SQL profile could be needed for each permutation.
  • Bear in mind also that some areas of PeopleSoft use dynamically generated SQL.  So you get similar SQL statements which are sufficiently different for the profile not to match.  
  • Any changes to the expansion of Application Engine and PeopleCode MetaSQL on upgrading PeopleTools, or potentially even patching, will also prevent matching.
  • There is also the challenge of dealing with code changes as the system is upgraded, patched and customised.  A small code change, perhaps just an extra field in the select clause, can result in a performance regression because the profile stops matching. Of course, this challenge is not limited to PeopleSoft systems! 
Profiles are likely to be effective if there are no PeopleSoft temporary records present.  So you can generally use them in COBOL and SQR processes and the on-line application (other than in on-line Application Engine processes).

Aye, there's the rub,

I would use a profile (or a set of profiles) as a short-term temporary fix that is easier to introduce into production, and then add hints to the source code and so fix all instances of the code, not just the ones that have been profiled. Of course, that does entail a code change, and everything that goes with that.  One strong argument against making code change is that you have to change the code again to remove or change the hint if it becomes unnecessary at some time in future after a significant change, such as an Oracle upgrade.  However, on balance, I think it is better than the scenario where the profile stops working one day without warning.

The rest is silence.

Unless you add a comment.

Wednesday, July 09, 2014

Introducing the Analytic Keep Clause for Effective-Dated/Sequence Queries in PeopleSoft

Those of us who work with PeopleSoft, and especially the HCM product, are all too familiar with the concept of effect-dated data, and the need to find data that was effective at a particular date.  PeopleSoft products have always made extensive use of correlated sub-queries to determine the required rows from an effective-dated record.
The JOB record is the heart of HCM. It is both effective-dated and effective sequenced. I will use it for the demonstrations in this article. I am going to suggest an alternative, although Oracle-specific, SQL construction.
 Let's start by looking at the job data for an employee in the demo database. Employee KF0018 has 17 rows of data two concurrent jobs.  The question I am going to ask is "What was the annual salary for this employee on 11 February 1995?".  Therefore, I am interested in the rows marked below with the asterisks. 
column annual_rt format 999,999
SELECT  emplid, empl_rcd, effdt, effseq, action, deptid, currency_cd, annual_rt
FROM	ps_job j
WHERE	j.emplid = 'KF0018'
ORDER BY 1,2,3,4
/ 
EMPLID        EMPL_RCD EFFDT         EFFSEQ ACT DEPTID     CUR ANNUAL_RT
----------- ---------- --------- ---------- --- ---------- --- ---------
KF0018               0 12-JUN-83          0 HIR 13000      FRF   120,000
KF0018               0 01-JAN-84          0 PAY 13000      FRF   123,600
KF0018               0 01-JAN-85          0 PAY 13000      FRF   127,308
KF0018               0 01-JAN-86          0 PAY 13000      FRF   131,764
KF0018               0 01-JAN-87          0 PAY 13000      FRF   136,376
KF0018               0 01-JAN-88          0 PAY 13000      FRF   140,467
KF0018               0 01-JAN-89          0 PAY 13000      FRF   147,490
KF0018               0 22-JAN-95          0 PRO 13000      FRF   147,490
KF0018               0 22-JAN-95          1 PAY 13000      FRF   294,239 *
KF0018               0 22-JAN-96          0 PAY 13000      FRF   318,575
KF0018               0 01-JAN-98          0 PAY 13000      FRF   346,156
KF0018               0 01-JAN-00          0 DTA 13000      FRF   346,156
KF0018               0 01-JAN-02          0 PAY 13000      EUR    52,771
KF0018               1 01-NOV-89          0 ASG 21300      GBP    22,440
KF0018               1 31-DEC-93          0 ASC 21300      GBP    22,440
KF0018               1 01-JAN-94          0 ASG 12000      GBP    22,440 *
KF0018               1 31-DEC-95          0 ASC 10000      GBP    22,440
I will set the statistics level to ALL so I can obtain detailed information about how the SQL statements execute:
ALTER SESSION SET statistics_level = ALL;
I extracted the execution plans and execution statistics with the following command
select * from table(dbms_xplan.display_cursor(null,null,'IOSTATS')) 

Typical PeopleSoft Platform Agnostic Construction

This is the usual way to construct the query in PeopleSoft. It is also valid on all databases platforms supported by PeopleSoft, not just Oracle. 
SELECT  emplid, empl_rcd, effdt, effseq, action, deptid, currency_cd, annual_rt
FROM	ps_job j
WHERE	j.effdt = ( 
        SELECT MAX (j1.effdt) FROM ps_job j1 
        WHERE j1.emplid = j.emplid 
        AND j1.empl_rcd = j.empl_rcd 
        AND j1.effdt <= TO_DATE('19950211','YYYYMMDD')) 
AND j.effseq = ( 
        SELECT MAX (j2.effseq) FROM ps_job j2 
        WHERE j2.emplid = j.emplid 
        AND j2.empl_rcd = j.empl_rcd 
        AND j2.effdt = j.effdt)
AND j.emplid = 'KF0018'
ORDER BY 1,2,3,4
/
EMPLID        EMPL_RCD EFFDT         EFFSEQ ACT DEPTID     CUR ANNUAL_RT
----------- ---------- --------- ---------- --- ---------- --- ---------
KF0018               0 22-JAN-95          1 PAY 13000      FRF   294,239
KF0018               1 01-JAN-94          0 ASG 12000      GBP    22,440
This required three access of indexes on the PS_JOB table, and two accesses of the table, using 26 consistent reads.
Plan hash value: 2299825310
----------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name    | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
----------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                  |         |      1 |        |      2 |00:00:00.01 |      26 |      2 |
|   1 |  SORT ORDER BY                    |         |      1 |      1 |      2 |00:00:00.01 |      26 |      2 |
|   2 |   NESTED LOOPS                    |         |      1 |      1 |      2 |00:00:00.01 |      26 |      2 |
|   3 |    NESTED LOOPS                   |         |      1 |      1 |      3 |00:00:00.01 |      21 |      2 |
|   4 |     VIEW                          | VW_SQ_1 |      1 |      1 |      2 |00:00:00.01 |      14 |      2 |
|*  5 |      FILTER                       |         |      1 |        |      2 |00:00:00.01 |      14 |      2 |
|   6 |       HASH GROUP BY               |         |      1 |      1 |      2 |00:00:00.01 |      14 |      2 |
|   7 |        TABLE ACCESS BY INDEX ROWID| PS_JOB  |      1 |      1 |     12 |00:00:00.01 |      14 |      2 |
|*  8 |         INDEX RANGE SCAN          | PS_JOB  |      1 |      1 |     12 |00:00:00.01 |       2 |      2 |
|   9 |     TABLE ACCESS BY INDEX ROWID   | PS_JOB  |      2 |      1 |      3 |00:00:00.01 |       7 |      0 |
|* 10 |      INDEX RANGE SCAN             | PSAJOB  |      2 |      1 |      3 |00:00:00.01 |       4 |      0 |
|* 11 |    VIEW PUSHED PREDICATE          | VW_SQ_2 |      3 |      1 |      2 |00:00:00.01 |       5 |      0 |
|* 12 |     FILTER                        |         |      3 |        |      3 |00:00:00.01 |       5 |      0 |
|  13 |      SORT AGGREGATE               |         |      3 |      1 |      3 |00:00:00.01 |       5 |      0 |
|* 14 |       FILTER                      |         |      3 |        |      5 |00:00:00.01 |       5 |      0 |
|* 15 |        INDEX RANGE SCAN           | PSAJOB  |      3 |      1 |      5 |00:00:00.01 |       5 |      0 |
----------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   5 - filter("J1"."EMPLID"='KF0018')
   8 - access("J1"."EMPLID"='KF0018' AND "J1"."SYS_NC00164$">=HEXTORAW('883CFDF4FEF8FEFAFF') )
       filter(SYS_OP_UNDESCEND("J1"."SYS_NC00164$")<=TO_DATE(' 1995-02-11 00:00:00', 'syyyy-mm-dd
              hh24:mi:ss'))
  10 - access("J"."EMPLID"='KF0018' AND "ITEM_2"="J"."EMPL_RCD" AND
              "J"."SYS_NC00164$"=SYS_OP_DESCEND("MAX(J1.EFFDT)"))
       filter(SYS_OP_UNDESCEND("J"."SYS_NC00164$")="MAX(J1.EFFDT)")
  11 - filter(SYS_OP_UNDESCEND("J"."SYS_NC00165$")="MAX(J2.EFFSEQ)")
  12 - filter(COUNT(*)>0)
  14 - filter('KF0018'="J"."EMPLID")
  15 - access("J2"."EMPLID"='KF0018' AND "J2"."EMPL_RCD"="J"."EMPL_RCD" AND
              "J2"."SYS_NC00164$"=SYS_OP_DESCEND(SYS_OP_UNDESCEND("J"."SYS_NC00164$")))
       filter(SYS_OP_UNDESCEND("J2"."SYS_NC00164$")=SYS_OP_UNDESCEND("J"."SYS_NC00164$"))
This construction is also the reason you are required to set
_UNNEST_SUBQUERY=FALSE
on all PeopleSoft systems

Analytic Function and In-Line View/Sub-query Factor

I have seen people use a combination of analytic functions and in-line views to avoid having to use the correlated sub-query construction. This has been possible since Oracle 9i.
WITH X AS (
SELECT  emplid, empl_rcd, effdt, effseq, action, deptid, currency_cd, annual_rt
,	ROW_NUMBER() OVER (PARTITION BY emplid, empl_rcd 
                           ORDER BY effdt DESC, effseq DESC) myrowseq
FROM	ps_job j
WHERE	j.effdt <= TO_DATE('19950211','YYYYMMDD')
AND	j.emplid = 'KF0018'
)
SELECT 	emplid, empl_rcd, effdt, effseq, action, deptid, currency_cd, annual_rt
FROM 	x
WHERE	myrowseq = 1
ORDER BY 1,2,3,4
/
EMPLID        EMPL_RCD EFFDT         EFFSEQ ACT DEPTID     CUR ANNUAL_RT
----------- ---------- --------- ---------- --- ---------- --- ---------
KF0018               0 22-JAN-95          1 PAY 13000      FRF   294,239
KF0018               1 01-JAN-94          0 ASG 12000      GBP    22,440
We get the same result, but now the index is scanned just once and we only need 14 consistent reads, so it produces a significant improvement. However, it still includes a sort operation in addition to the window function. We have to create a sequence number field in the in-line view and filter by that in the final query.
Plan hash value: 1316906785
---------------------------------------------------------------------------------------------------
| Id  | Operation                      | Name   | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |        |      1 |        |      2 |00:00:00.01 |      14 |
|   1 |  SORT ORDER BY                 |        |      1 |      1 |      2 |00:00:00.01 |      14 |
|*  2 |   VIEW                         |        |      1 |      1 |      2 |00:00:00.01 |      14 |
|*  3 |    WINDOW NOSORT               |        |      1 |      1 |     12 |00:00:00.01 |      14 |
|   4 |     TABLE ACCESS BY INDEX ROWID| PS_JOB |      1 |      1 |     12 |00:00:00.01 |      14 |
|*  5 |      INDEX RANGE SCAN          | PSAJOB |      1 |      1 |     12 |00:00:00.01 |       2 |
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - filter("MYROWSEQ"=1)
   3 - filter(ROW_NUMBER() OVER ( PARTITION BY "EMPLID","EMPL_RCD" ORDER BY
              "J"."SYS_NC00164$","J"."SYS_NC00165$")<=1)
   5 - access("J"."EMPLID"='KF0018' AND "J"."SYS_NC00164$">=HEXTORAW('883CFDF4FEF8FEFAFF')
              )
       filter(SYS_OP_UNDESCEND("J"."SYS_NC00164$")<=TO_DATE(' 1995-02-11 00:00:00',
              'syyyy-mm-dd hh24:mi:ss'))

Analytic Function Keep Clause

This form of the analytic functions is documented for the first time in 12c, but is available in 10g (my thanks to Tony Hasler for introducing me to it). It works by effectively keeping a running maximum value of the columns in the order by clause within in group.
SELECT emplid, empl_rcd
, MAX(effdt) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS effdt
, MAX(effseq) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS effseq
, MAX(action) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS action
, MAX(deptid) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS deptid
, MAX(currency_cd) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS currency_cd
, MAX(annual_rt) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq) AS annual_rt
FROM ps_job j
WHERE	j.effdt <= TO_DATE('19950211','YYYYMMDD')
AND	j.emplid = 'KF0018'
GROUP BY emplid, empl_rcd
/

EMPLID        EMPL_RCD EFFDT         EFFSEQ ACT DEPTID     CUR ANNUAL_RT
----------- ---------- --------- ---------- --- ---------- --- ---------
KF0018               0 22-JAN-95          1 PAY 13000      FRF   294,239
KF0018               1 01-JAN-94          0 ASG 12000      GBP    22,440
Although this construction uses an additional consistent read, it has the advantage of not using either an inline view or a window function and does not sort the data.
Plan hash value: 1550496807
-------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name   | Starts | E-Rows | A-Rows |   A-Time   | Buffers |
-------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |        |      1 |        |      2 |00:00:00.01 |      15 |
|   1 |  SORT GROUP BY NOSORT        |        |      1 |      1 |      2 |00:00:00.01 |      15 |
|   2 |   TABLE ACCESS BY INDEX ROWID| PS_JOB |      1 |      1 |     12 |00:00:00.01 |      15 |
|*  3 |    INDEX RANGE SCAN          | PS_JOB |      1 |      1 |     12 |00:00:00.01 |       3 |
-------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   3 - access("J"."EMPLID"='KF0018' AND "J"."SYS_NC00164$">=HEXTORAW('883CFDF3FEF8FEFAFF'
              ) )
       filter(SYS_OP_UNDESCEND("J"."SYS_NC00164$")<=TO_DATE(' 1995-02-12 00:00:00',
              'syyyy-mm-dd hh24:mi:ss'))
I think this construction could be useful in PeopleSoft.  At first glance, the SQL appears more complicated, but in this example, it removed two correlated sub-queries. 

Using Analytic Functions in PS/Query

Of course, you can code it anywhere where you can simply enter SQL as text.  However, it also has the advantage over the other analytic function construction that it can be coded in the PS/Query tool.  The analytic functions in the select clause should be created in PS/Query expressions with the aggregate expression checkbox ticked.
Analytic 'Keep' function in PS/Query Aggregate Expression
Analytic Function in Aggregated Expression in Windows Client version of PS/Query 
The analytic functions can be selected in the PS/Query, and their lengths and titles can be tidied up.
Analytic PS/Query
PS/Query with Analytic 'Keep' Functions

This is the resulting SQL which is the same as before (with row-level security added by PS/Query) and produces the same results.
SELECT A.EMPLID, A.EMPL_RCD, MAX(effdt) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq)
, MAX(effseq) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq), MAX(action) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq), MAX(deptid) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq), MAX(currency_cd) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq), MAX(annual_rt) KEEP (DENSE_RANK LAST ORDER BY effdt, effseq)					
  FROM PS_JOB A, PS_EMPLMT_SRCH_QRY A1
  WHERE ( A.EMPLID = A1.EMPLID
    AND A.EMPL_RCD = A1.EMPL_RCD
    AND A1.OPRID = 'PS'
    AND ( A.EFFDT <= TO_DATE('1995-02-11','YYYY-MM-DD')
     AND A.EMPLID = 'KF0018' ) )
  GROUP BY  A.EMPLID,  A.EMPL_RCD

Friday, January 03, 2014

Date to Timestamp Conversion during PeopleTools Upgrade

This blog posting describes a script to convert Oracle date columns to Timestamps as used from PeopleTools 8.50 but only rebuilding those indexes that reference those columns, rather than drop and recreate every index in the system, thus producing a significant saving of time during the upgrade.

(A longer version of this article is available on my website)

I am working on a PeopleSoft upgrade project.  We are going from PeopleTools 8.49 to 8.53.  One of the things that happens is that some date columns in the Oracle database become timestamps.

Timestamps were introduced by Oracle in version 10g of the database, and provide the ability to store times accurate to the nanosecond (although the default is microsecond). Dates are accurate to the whole second.

There are 3 types of temporal column in PeopleSoft as defined on PSDBFIELD.  Prior to PeopleTools 8.50 they all become Oracle date columns in the database.  However, from PeopleTools 8.50; Time and DateTime fields are built as TimeStamp columns.if bit 5 of PSSTATUS.DATABASE_OPTIONS (value 32) is set.

PeopleTools Field Type
Database Column Type
PeopleTools <= 8.49 PeopleTools >= 8.50
4 Date DATE DATE
5 Time DATE TIMESTAMP
6 DateTime DATE TIMESTAMP

Timestamps must be handled differently to dates in SQL.  Some date arithmetic must be done differently, in particular the difference between two timestamps is a timestamp rather than a number of days.  Therefore this setting also controls how PeopleCode date macros expand on Oracle.

During the upgrade, PeopleSoft Change Assistant simply alters all the Time and DateTime columns from dates to timestamps.  This generally works well.  The data value doesn't appear to get longer, so the block doesn't run out of room leading to row migration, and so it isn't necessary to rebuild every table that is affected.

However, there are some limitations. If the column being converted to a timestamp falls into one of the following categories you will get an error.
  • The column is a key column in a function-based index.
  • The table or index is partitioned by the column.
The functional key index issue has not affected many customers because the upgrade template drops all the indexes before altering the tables and rebuilding them again.

However, dropping and recreating all these indexes can be very time consuming and increases the duration of the outage required to perform the upgrade.  This has been my incentive to find a better way.

Function-Based Indexes
PeopleSoft Application Designer defines some key and search fields as descending.  The rows in components and the results of search dialogue are sorted on the key fields in the order specified.  Application Designer then indexes these columns in descending order (prior to PeopleTools 8 and since PeopleTools 8.47).  If any column in an Oracle index is in descending order the index is created as a function-based index.  Consequently, there can be a lot of descending indexes in a PeopleSoft system!  HR systems are particularly affected because many tables are effective-dated, and the field EFFDT is usually a descending key field.

It is not possible to alter a column to a timestamp if it appears anywhere in a function-based index. You get the following error:
ORA-30556: functional index is defined on the column to be modified 

Partitioning
Partitioning is not something that you usually encounter in a vanilla PeopleSoft system, but it can be added by customisation.  You generate the necessary DDL yourself if you want to use it. However, from PeopleTools 8.51 Application Designer will preserve existing partitioning.

In the system on which I am working, when partitioned the audit tables by AUDIT_STAMP which is a DateTime field.
ORA-14060: data type or length of an table partitioning column may not be changed 
We have had no alternative but to rebuild these tables and repopulate the data. This has also dealt with all locally partitioned indexes.

We have also found that we have one global index partitioned on a timestamp.
ORA-14061: data type or length of an index partitioning column may not be changed 
We also have had to drop this index in order to alter the table.

My Approach
We have had no alternative but to rebuild and repopulate our partitioned audit tables which are partitioned by a DateTime field.  However, that is what we did when we first partitioned them.  The scripts are very similar to those generated by Application Designer.  The table is renamed, a new one is built, and the data is copied.  In our case these scripts are built with a PL/SQL utility.  This also addressed the need to rebuild the locally partitioned indexes..

To minimize the number of indexes which must be rebuilt I have written a PL/SQL script (http://www2.go-faster.co.uk/scripts/gfc_desc_timestamp_index.sql) that:
  • identifies the indexes that need to be dropped.
  • captures the DDL to recreate the indexes using DBMS_METADATA and stores it in a table,
  • drops the indexes,
  • alters the columns that cannot be altered with the index in place,
  • recreates the index.
The script successfully handles partitioned function-based indexes.

On this particular HR system we only rebuilt about 400 indexes instead of over 10000. Now the standard PeopleSoft upgrade template can be run without dropping or recreating any further indexes.

Thursday, January 02, 2014

Minimum Number of Recycling Server Processes

When I rebuilt my demo system (some while ago) with PeopleTools 8.52, I noticed a new message generated by ubbgen in PeopleTools 8.52 when the minimum number of recycling servers is set to 1.

WARNING: PSAPPSRV, PSSAMSRV, PSQRYSRV, PSQCKSRV, PSPPMSRV and PSANALYTICSRV are configured with Min instance set to 1. 
To avoid loss of service, configure Min instance to at least 2.

What Produces the Message?
ubbgen is the PeopleSoft utility that merges the template file (psappsrv.ubx) with the configuration file (psappsrv.cfg) file to produce the Tuxedo configuration file (psappsrv.ubb) and the environment file (psappsrv.env). It is invoked by psadmin during Tuxedo domain configuration.
ubbgen -t psappsrv.ubx -c psappsrv.cfg -o psappsrv.ubb -v psappsrv.val -q y -u PUBSUB=n/QUICKSRV=n/QUERYSRV=n/JOLT=y/JRAD=n/DBGSRV=n/RENSRV=n/MCF=n/PPM=n/ANALYTICSRV=n
The message is produced at this time.

Recycling Servers
Several servers in a PeopleSoft application Server domain recycle after they have handled a number of services. Recycling is a PeopleSoft behaviour and not a Tuxedo behaviour.  It is controlled by the Recycle Count parameter in the PeopleSoft configuration file (psappsrv.cfg).  This parameter is not referenced in the template file (psappsrv.ubx).

[PSAPPSRV]
;=========================================================================
; Settings for PSAPPSRV
;=========================================================================

;-------------------------------------------------------------------------
; UBBGEN settings
Min Instances=2
Max Instances=3
Service Timeout=0

;-------------------------------------------------------------------------
; Number of services after which PSAPPSRV will automatically restart.
; If the recycle count is set to zero, PSAPPSRV will never be recycled.
; The default value is zero.
; Dynamic change allowed for Recycle Count
Recycle Count=1000

PeopleSoft first started using BEA Tuxedo (as it was then) in PeopleTools 6 to remote call Cobol processes in the Financials product.  The Application Server was introduced in PeopleTools 7.  PSAPPSRV had recycling from the first release.  Legend has it that the engineers at Tuxedo where horrified when they heard that PeopleSoft had introduced recycling to resolve problems created by dynamic memory allocation and deallocation by the Panel Processor (now known as the component Processor).

Tuxedo servers are supposed to be robust, long lived and not require to be regularly restarted.  Hence the server restart functionality in Tuxedo is only designed to be invoked in the rare occasions when a server process crashes.  Server processes are started by the Restart Server (restartsrv), and only one process can be started concurrently.

The minimum of 2 applies to the following servers because they can both recycle and be configured to spawn additional instances on demand PSAPPSRV, PSANALYTICSRV, PSSAMSRV, PSQCKSRV, PSQRYSRV, PSPUBHND, PSSUBHND, PSBRKHND.  In the delivered configuration file for the developer domain, recycling is disabled for several servers by setting the recycle count to zero.  However, the message is produced by ubbgen irrespective of the value of recycle count.

The message handler servers can be set to have just a single instance, without producing any warning.  They only consume messages from the dispatcher processes so their temporary disappearance will not cause user errors.

What Happens When The Only Server Recycles?
Tuxedo server processes consume service requests placed on queues.  When a server starts up, it advertises its services on the Bulletin Board.  Tuxedo processes that submit requests (mostly the JSH processes, but also the message dispatcher processes, the Process Scheduler) look up on the Bulletin Board where a service is advertised and place it on the appropriate queue.

When a server process performs an orderly shutdown (as it does during a recycle) it removes the adverts for its services (the command is unadvertise).  If a process crashes the Bulletin Board Liaison process (BBL) detects the crash and cleans the Bullentin Board. When all services advertised on a queue have been unadvertised, the queue is also removed from the Bulletin Board.  If the process submitting the service request cannot find any server advertising a service it generates an error.  
074001.GO-FASTER-6!JSH.3124.5736.-2: JOLT_CAT:1043: "ERROR: tpacall() call failed, tperrno = 6"
This is why the minimum is 2.  If you recycled the only server process, it is possible for someone to produce this error (see also Minimum Number of Application Server Processes).

Should I set the minimum higher than 2?
The number of services handled by different server processes on the same queue is usually uneven because the service is handled by the first free server.  Therefore it is rare for the processes will reach the recycle count simultaneously, but it can still happen.  Even in a quiet system that doesn't have sufficient activity to justify 3 PSAPPSRVs, I prefer to set the minimum number of servers to at least 3. 

Debugger
NB: If the debugger process is enabled then PSADMIN will force the minimum and maximum number of PSAPPSRV processes to at least 2.  ubbgen will actually update psappsrv.cfg.
Warning:  PSAPPSRV Min Instances too small, setting to 2 for debugger.

Friday, November 23, 2012

PeopleTools 8.52 Application Engine sets MODULE and ACTION

Update 4.3.2015: See also Undocumented Application Engine Parameter: EnableAEMonitoring

I have written and spoken often about the huge importance of instrumentation in an application. PeopleSoft introduced internal instrumentation to PeopleTools 8.44 for its own Performance Monitor that works on any platform. Since PeopleTools 7.53, when running on an Oracle database, PeopleTools also calls the Oracle supplied package dbms_application_info package to set the module and action for the session. The values set were not particularly useful, so I wrote a PL/SQL package (psftapi) and trigger to set the module and action attributes when a process started.

In PeopleTools 8.50 this instrumentation was enhanced to set module and action to the component and page name in the PIA. These values appear in Oracle Enterprise Manager and Active Session History (ASH). They can be used to profile components.

Now, in PeopleTools 8.52 Application Engine has been enhanced to set the action to the full Application Engine step name.

To illustrate what happens, I have produced an Oracle Extended SQL Trace for the process, but I have shown only the lines in a SQL Trace file with 3 asterisks. So you can see MODULE and ACTION being set (and some other timestamp information). The lines in italic were emitted when module and action were set by my psftapi package, in which I simply set the MODULE to the Application Engine program name.
*** 2012-11-22 21:47:38.282
*** SESSION ID:(7.2237) 2012-11-22 21:47:38.282
*** CLIENT ID:(PS) 2012-11-22 21:47:38.282
*** SERVICE NAME:(HCM91) 2012-11-22 21:47:38.282
*** MODULE NAME:(PSPMCSOSUM) 2012-11-22 21:47:38.282
*** ACTION NAME:(PI=867:Processing) 2012-11-22 21:47:38.282
*** MODULE NAME:(PSAE.PSPMCSOSUM.1448) 2012-11-22 21:47:38.419
*** ACTION NAME:(PSPMCSOSUM) 2012-11-22 21:47:38.419
*** ACTION NAME:(PSPMCSOSUM.MAIN.STATS.S) 2012-11-22 21:47:38.420
*** 2012-11-22 21:47:38.588
*** ACTION NAME:(PSPMCSOSUM.MAIN.CTL.P) 2012-11-22 21:47:38.919
*** ACTION NAME:(PSPMCSOSUM.MAIN.SELECT.C) 2012-11-22 21:47:38.937
*** ACTION NAME:(PSPMCSOSUM.GETCNT.CNT.P) 2012-11-22 21:47:38.963
…
*** ACTION NAME:(PSPMCSOSUM.MAIN.SELECT.C) 2012-11-22 21:48:15.168
*** ACTION NAME:(PSPMCSOSUM.GETCNT.CNT.P) 2012-11-22 21:48:15.168
*** ACTION NAME:(PSPMCSOSUM.MAIN.Close.P) 2012-11-22 21:48:15.197
*** ACTION NAME:(PI=867:Success) 2012-11-22 21:48:15.201

Application Engine also sets the MODULE attribute.  In the above example it was set to PSAE.PSPMCSOSUM.1448.  The string is composed of three parts.
  • PSAE indicates that it was running Application Engine. It sets the same value for both stand-alone and Tuxedo server Application Engine processes.
  • PSPMCSOSUM was the name of the Application Engine Program
  • 1448 was the operating system process ID of the Application Engine process.  This value is recorded in the column SESSIONIDNUM on the table PSPRCSQUE.
The inclusion of the SESSIONIDNUM is useful because it is possible to determine the process instance.  If you have multiple instances of the same Application Engine program running concurrently, you can work out which ASH samples correspond to which process instance by matching the session ID.

SELECT  r.prcsinstance, h.module, h.action, sum(1) ash_secs
FROM v$active_Session_history h
, psprcsque q
, psprcsrqst r
WHERE r.prcsinstance = q.prcsinstance
AND h.module = 'PSAE.'||q.prcsname||'.'||q.sessionidnum
AND h.sample_time BETWEEN r.begindttm AND NVL(r.enddttm,SYSDATE)
and r.prcsinstance = 867
GROUP BY r.prcsinstance, h.module, h.action
ORDER BY ash_secs DESC
/

PRCSINSTANCE MODULE               ACTION                    ASH_SECS
------------ -------------------- ------------------------- --------
         867 PSAE.PSPMCSOSUM.1448 PSPMCSOSUM.GETCNT.CNT.P          7
         867 PSAE.PSPMCSOSUM.1448 PSPMCSOSUM.MAIN.STATS.S          1

Unfortunately, this change to MODULE also means that it is no longer possible to enable trace by setting a watchpoint (as I blogged previously).  It no longer works with Application Engine because it is not possible to predict the value of the SESSIONIDNUM in MODULE.

I am testing with 8.52.12 and have found a significant problem. Application Engine doesn't set the action on DO SELECT statements. The first statement in the trace extract below does come from PSPMCSOSUM.MAIN.CTL PeopleCode, however, the second SQL statement actually comes from PSPMCSOSUM.MAIN.SELECT.D, but the absence of another action line would lead you to believe the statement came from the preceding PeopleCode step.
*** ACTION NAME:(PSPMCSOSUM.MAIN.CTL.P) 2012-11-22 21:47:38.919
WAIT #0: nam='SQL*Net message to client' ela= 0 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220814597
WAIT #0: nam='SQL*Net message from client' ela= 740 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220815371
CLOSE #348647416:c=0,e=33,dep=0,type=1,tim=257220815447
=====================
PARSING IN CURSOR #348528704 len=98 dep=0 uid=45 oct=3 lid=45 tim=257220815496 hv=1424819941 ad='7ff2559e550' sqlid='98af7ppafu1r5'
END OF STMT
PARSE #348528704:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1148792852,tim=257220815496
EXEC #348528704:c=0,e=30,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1148792852,tim=257220815572
WAIT #348528704: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220815612
FETCH #348528704:c=0,e=2824,p=0,cr=16,cu=0,mis=0,r=1,dep=0,og=1,plh=1148792852,tim=257220818462
STAT #348528704 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=16 pr=0 pw=0 time=2828 us)'
STAT #348528704 id=2 cnt=3075 pid=1 pos=1 obj=228740 op='INDEX FULL SCAN PS_PSPMCSO_CHART (cr=16 pr=0 pw=0 time=333 us cost=0 size=13 card=1)'
WAIT #348528704: nam='SQL*Net message from client' ela= 123 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220818671
FETCH #348528704:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1148792852,tim=257220818696
WAIT #348528704: nam='SQL*Net message to client' ela= 0 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220818714
WAIT #348528704: nam='SQL*Net message from client' ela= 702 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220819434
CLOSE #349389936:c=0,e=16,dep=0,type=1,tim=257220819496
=====================
PARSING IN CURSOR #349702624 len=555 dep=0 uid=45 oct=3 lid=45 tim=257220819548 hv=1888777338 ad='7ff2559ce90' sqlid='5phgqq9s98x3u'
SELECT DISTINCT OPRID , TO_CHAR(CAST((LOGINDTTM) AS TIMESTAMP),'YYYY-MM-DD-HH24.MI.SS.FF') , TO_CHAR(CAST((LOGOUTDTTM) AS TIMESTAMP),'YYYY-MM-DD-HH24.MI.SS.FF') , PM_SIGNON_TYPE , PM_SIGNOFF_TYPE FROM PSPMCSOLOG_VW WHERE '1' <> '2' AND TO_DATE(TO_CHAR(LOGINDTTM,'YYYY-MM-DD'),'YYYY-MM-DD') >= TO_DATE('2005-07-06','YYYY-MM-DD') AND TO_DATE(TO_CHAR(LOGOUTDTTM,'YYYY-MM-DD'),'YYYY-MM-DD') >= TO_DATE('2005-07-06','YYYY-MM-DD') AND OPRID NOT IN ( SELECT OPRID FROM PSPMCSOCHRTXOP) AND LOGIPADDRESS NOT IN ( SELECT LOGIPADDRESS FROM PSPMCSOCHRTXIP) ORDER BY 2
END OF STMT
PARSE #349702624:c=0,e=35,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4226533831,tim=257220819547
EXEC #349702624:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4226533831,tim=257220819669
WAIT #349702624: nam='SQL*Net message to client' ela= 1 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220819723
WAIT #349702624: nam='SQL*Net more data to client' ela= 76 driver id=1413697536 #bytes=8145 p3=0 obj#=-40016373 tim=257220831271
FETCH #349702624:c=15600,e=11621,p=0,cr=214,cu=0,mis=0,r=201,dep=0,og=1,plh=4226533831,tim=257220831375
WAIT #349702624: nam='SQL*Net message from client' ela= 988 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220832412
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220832481
WAIT #0: nam='SQL*Net message from client' ela= 40 driver id=1413697536 #bytes=1 p3=0 obj#=-40016373 tim=257220832541
*** ACTION NAME:(PSPMCSOSUM.MAIN.SELECT.C) 2012-11-22 21:47:38.937

However, MAIN.SELECT.D duly appears in the AE batch timings report.


                               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    
------------------------------ ------- -------- ------- -------- ------- -------- --------
…
AE Program: PSPMCSOSUM

MAIN.CTL.D                           1      0.0       1      0.0       2      0.0      0.0
MAIN.SELECT.D                        1      0.0       1      0.0     556      0.0      0.0
MAIN.STATS.S                         1      0.0       1      0.5       0      0.0      0.5
…

This is a serious problem  If you profile the top SQL statements in an Application Engine (using either ASH as I have done above, or by profiling a trace file and looking for the top SQL statement by searching through the raw trace file) it will lead you to the wrong conclusion!  Time spent in PSPMCSOSUM.MAIN.SELECT.D will be accounted as having been spent in PSPMCSOSUM.GETCNT.CNT.P.  It is not until you look for the specific SQL statement in Application Designer that you realise that the source code doesn't match the instrumentation.
 
Nevertheless, this instrumentation is a very welcome and significant improvement for Application Engine. It will help to localise performance problems. However, until the omissions are fixed, you will need to be aware of their implications and avoid falling into the traps.

My thanks to Wolfgang Breitling for telling me about the feature.