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.
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).
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.
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.
Conclusion
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.
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
------------------------------ ------- -------- ------- -------- ------- -------- --------
PeopleCode
Record.SelectByKey PSDBFIELD 8 0.1 8 0.0 0.1
SELECT PSPRCSRQST 2 0.1 2 0.0 0.1
SELECT PSXPTMPLDEFN 3 0.1 3 0.0 0.1
--------
0.3
AE Program: PSXPQRYRPT
MAIN.ExecRpt.H 1 0.0 1 0.0 1 0.0 0.0
--------
0.0
------------------------------------------------------------------------------------------
Call Non-SQL SQL Total
PeopleCode Count Time Time Time
------------------------------ ------- -------- -------- --------
AE Program: PSXPQRYRPT
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.
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
FROM (
SELECT x.prcsinstance
, x.filename
, COUNT(DISTINCT x.prcsinstance) processes
, COUNT(*) reports
, SUM(x.secs) secs
FROM (
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
ORDER BY secs DESC
/
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 XXX_HRAM_CON QRY XXX_HRPD_CNT_AMD_RPT_QRY 92 92 2,677 27 108.4 XXX_CKOUT_RP QRY XXX_CHECKOUT_REPORT 47 47 2,043 41 347.7 XXX_BNK_RPT QRY XXX_BNK_DTLS_SCH_QRY 1 75 141 141 0.0 …
Conclusion
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.
@go-faster.co.uk on BlueSky
Posts
