Month: January 2010

Quick Note

Just noticed this on the Apress site, looks like can expect a new book from Tom Kyte in the summer … Thought he had been quiet recently.

Has there been a big change in data volume ?

Ever get requests from users/developers complaining that queries or feeds are suddenly running slower – and claiming nothing has changed ?  Are you  pretty sure its just going to data volume or some sort of change in table statistics? One of the useful features introduced in 10g was DBMS_STATS automatically saving old statistics before it […]

Performance Metrics and XML Reporting in PeopleSoft

I am working with a PeopleSoft system that makes extensive use of XML Publisher reporting.  Generally these reports are based on SQL queries that are defined in the PeopleSoft PS/Query utility. 

These queries are run by an Application Engine program PSXPQRYRPT that runs the SQL query and produces the report in a single process.  This is a generic application engine program that runs any XML report.  Line 45 (in PeopleTools 8.49) of step MAIN.ExecRPT executes the report with the ProcessReport PeopleCode command.

&oRptDefn.ProcessReport(&TemplateId, &Languaged, &AsOfDate, &oRptDefn.GetOutDestFormatString(&OutDestFormat));

Batch Timings
Analysis of the Application Engine batch timings indicate that nearly all the time in this Application Engine program is spent in PeopleCode, and that this not SQL execution time.  This is misleading.  The ProcessReport command is PeopleCode, but behind the scenes it also issues the SQL in the report data source.  Not all the time is SQL, but the Application Engine Batch Timings does not count any of this as SQL because it is not in the PeopleCode SQL Class. 

Let’s look at an example Batch Timings report (I have edited it down, removing zero and insignificant timings).

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
------------------------------ ------- -------- ------- -------- ------- -------- --------
Record.SelectByKey PSDBFIELD 8 0.1 8 0.0 0.1
SELECT PSPRCSRQST 2 0.1 2 0.0 0.1
MAIN.ExecRpt.H 1 0.0 1 0.0 1 0.0 0.0
Call Non-SQL SQL Total
PeopleCode Count Time Time Time
------------------------------ ------- -------- -------- --------
MAIN.ExecRpt 1 643.2 0.3 643.5
-------- -------- --------
643.2 0.3 643.5
E x e c u t e
PEOPLECODE Builtin/Method Count Time
------------------------------------------------------- ------- --------
Boolean(Type 5) BuiltIns 90 0.1
DateTime(Type 11) BuiltIns 1 0.1
SQL(Type 524290) Methods 19 0.1
SQL(Type 524290) BuiltIns 9 0.1
Record(Type 524291) Methods 1104 0.1
Session(Type 524303) Methods 207 633.2
JavaObject(Type 524315) BuiltIns 6 2.2
PostReport(Type 524324) Methods 2 0.7
Total run time : 644.0
Total time in application SQL : 0.3 Percent time in application SQL : 0.0%
Total time in PeopleCode : 643.2 Percent time in PeopleCode : 99.9%
  • The total execution time of is 644 seconds.
  • 643.2s are reported as being in PeopleCode, and as coming from the MAIN.ExecRpt step.
  • Only 0.3s of that is SQL time, and that comes from PeopleCode functions in the SQL Class  (CreateRecord , CreateSQL etc.)
  • The ProcessReport method does not appear in the PeopleCode SQL analysis section of the report, because it is not classed as SQL.

Identifying the Report ID and Report Source
So, the next question is how can I find out which report this process is running.  Different instances of this report may be running different queries.

You can get the list files generated by a process from the Content Management PeopleTools table PS_CDM_FILE_LIST.  Application Engine processes usually produce various log files (with extensions .aet, .trc and .log), the name of the other file is the same as the name of the report followed by an extension that will vary depending on format.

You can look at the report definition on-line under Reporting Tools -> XML Publisher -> Report Definition, and that will show you the Data Source ID

The Data Source is defined in a component accessible from the previous entry in the same menu.

Analysing Execution Times
I have written this query to aggregate execution time for PSXPQRYRPT by output file name. 

  • PSPRCSRQST is the process request table, from which I get the run time of the process.
  • PS_CDM_FILE_LIST lists the files generated by the process which would be posted to the Report Repository. If I exclude the usual trace files, I am left with the report ID.
  • PSXPRPTDEFN is the report definition record, from which I can get the data source ID
  • PSXPDATSRC specifies the data source.  A data source type (DS_TYPE) of QRY indicates a PeopleSoft PS/Query.  If it is a private query, the OPRID will have a value.
column report_defn_id heading 'Report ID'      format a12 
column ds_type heading 'Type' format a4
column ds_id heading 'Data Source ID' format a30
column oprid heading 'Owner' format a10
column processes heading 'Prcs' format 990
column reprots heading 'Reps' format 9,990
column secs heading 'Total|Seconds' format 999,990
column median heading 'Median|Seconds' format 999,990
column variance heading 'Variance' format 9990.0
SELECT d.report_defn_id, d.ds_type, d.ds_id, d.oprid
, SUM(y.processes) processes
, SUM(y.reports) reports
, SUM(y.secs) secs
, median(y.secs) median
, variance(y.secs) variance
SELECT x.prcsinstance
, x.filename
, COUNT(DISTINCT x.prcsinstance) processes
, COUNT(*) reports
, SUM(x.secs) secs
SELECT r.prcsinstance
, f.filename
, 86400*(r.enddttm-r.begindttm)*ratio_to_report(1) over (partition by r.prcsinstance) secs
FROM sysadm.psprcsrqst r
, sysadm.ps_cdm_file_list f
WHERE r.prcsname = 'PSXPQRYRPT'
AND r.prcsinstance = f.prcsinstance
AND NOT f.cdm_file_type IN('AET','TRC','LOG')
AND r.begindttm >= TRUNC(SYSDATE)
) x
GROUP BY x.prcsinstance, x.filename
) y
, sysadm.psxprptdefn d
WHERE d.report_defn_id = SUBSTR(y.filename,1,instr(y.filename,'.')-1)
GROUP BY d.report_defn_id, d.ds_type, d.ds_id, d.oprid

I can now see which report process has been executed run how many times, how many copies of the report have been produced, and where the processing time is being spent, and so which one I should look at first.

Total   Median
Report ID Type Data Source ID Owner Prcs Reps Seconds Seconds Variance
------------ ---- ------------------------------ ---------- ---- ------ -------- -------- --------
XXX_WK_LATE QRY XXX_WKLY_LATENESS_RPT 20 20 2,973 148 3702.9


If you have a SQL performance problem with an XML report because the source PS/Query performs poorly, the batch timings will lead you to believe that you have a PeopleCode problem and not a SQL problem. 

Beware, this may not be the case.

Most of the execution time for XML Reports sourced from PS/Queries is almost certain to be SQL execution time.  The above query will tell you which queries are consuming how much time, and so inform your tuning effort.

Not So Read Only …

I’ve always assume making a tablespace READ ONLY meant NO changes could happen to its contents.  So for example if I create new tablespace, put a table in it and set it to be READ ONLY … So I can’t change the rows in the table, good … But I can drop the table ! […]

Miracle Åben Verden and other presentation news

I have several presentations coming up, but due to a dramatic set of circumstances in Denmark, I will be posting about them in reverse order. Miracle OpenWorld has been renamed due to possible ‘mark’ infringements on the term ‘OpenWorld’.Therefore, I am pleased to announce that I will be giving a presentation on ‘Measuring for Robust Performance’ in April at Miracle Åben Verden! You can hear all

TEL/電話+86 13764045638
QQ 47079569