Understanding Peoplesoft Trace

最新推荐文章于 2024-11-15 18:38:47 发布

weixin_30545285

最新推荐文章于 2024-11-15 18:38:47 发布

阅读量112

点赞数

文章标签：数据库

原文链接：http://www.cnblogs.com/xiangliqi/p/5717290.html

版权

Here are the steps to generate application and Application Engine traces, to troubleshoot any application issues.
Before you start generating traces, you need to make sure that the following parameters are set in the Configuration Files.

TracePCMask=4095
TraceSqlMask=12319

Once you have generated the traces, if you are working with Global Support Center, you can send the zipped trace file to the analyst working your case.

1) Trace for PIA Session -

(i) Generate the application trace for a single user

When logging on to PIA/browser, append &trace=y to the regular URL on the address bar:

Check the following options on the login window:
Under SQL trace Settings
-SQL Statements
-SQL Statement Variables

Under Peoplecode trace settings
-Program starts
-Each Statement

Now log in to the application and reach the page/menu where the problem lies and go and delete the trace that is created thus far(for location of trace see below). This will remove all the non relevant peopletools part for this application troubleshooting. Now, perform exact steps to simulate the error/problem.

A log file will be created on the application server, logs directory(\appserv\\LOGS).
The name of the file usually has the user name used to log in to the application session
followed by the machine name or IPAddress. (Eg:PS_AVARSHNE090.tracesql) with an extension of tracesql or trc.

*********TRACE OPTIONS FOR PERFORMANCE*********************
Under SQL trace Settings
� SQL Trace:
� SQL statement
� SQL statement variables.
� Connect, disconnect, rollback and commit.
� Row Fetch.
� All Other API calls except Bind variables.

Under Peoplecode trace settings
-Program starts

*********TRACE OPTIONS FOR PERFORMANCE*********************

(ii) Generate the trace for all users using the Application.
Trace setting in Application Configuration files, set following parameters for SQL and PeopleCode, respectively
TraceSQL=3
TracePC=2048
Once this is done, you need to bounce the application Server for the values to come in-effect

2) Application Engine traces
The normal application trace (*.tracesql) will not contain the Application Engine Program traces. For that AE Trace parameters (TraceAE, TracePC and TraceSQL) are to be set differently. You can set them either in the configurations files or from PIA.

(i) PIA: This ensures that the Traces will be generated only for specific AE program.
Navigation:
CRM 8.0 -Home > PeopleTools > Process Scheduler Manager > Use > Process Definitions
CRM 8.4, 8.8, 8.9 -PeopleTools> Process Scheduler> Processes
And Pick up the Process you want to Trace like RB_SRCH_BLD
Go to the Override Tab, Set Override Options in Parameter List (Choose Append in drop down) as example

-TRACE 135 -TOOLSTRACEPC 2048 -TOOLSTRACESQL 7
You can set the numbers per your requirement.

(ii) Configuration File: This applies to every User and every Process.
Set below parameters in psappsrv.cfg and psprcs.cfg files
TraceSQL=0,
TraceAE=135,
TracePC=2048.

Configuration files are located under:
<ps_home>\Appserv\\psappsrv.cfg
<ps_home>\Appserv\prcs\\psprcs.cfg
After making these changes you need to restart application server and process scheduler.

You will find the traces under:
From Application - Process Monitor, Details -> View Log/Trace link
Server - \appserv\prcs\\log_output\AE__\.....
If Report Repository is set then under Webserver\psreports_weblogic (for our GSC environments it will be here).

To decide what numbers you want to set for each parameters.
***********************************************************
Add the bits for the type of trace you want, this is applicable to both application as well as AE trace

; SQL Tracing Bitfield
;
; Bit Type of tracing
; --- ---------------
; 1 - SQL statements
; 2 - SQL statement variables
; 4 - SQL connect, disconnect, commit and rollback
; 8 - Row Fetch (indicates that it occurred, not data)
; 16 - All other API calls except ssb
; 32 - Set Select Buffers (identifies the attributes of columns
; to be selected).
; 64 - Database API specific calls
; 128 - COBOL statement timings
; 256 - Sybase Bind information
; 512 - Sybase Fetch information
; 4096 - Manager information
; 8192 - Mapcore information
; Dynamic change allowed for TraceSql and TraceSqlMask
TraceSql=0
TraceSqlMask=12319

;-------------------------------------------------------------------------
; PeopleCode Tracing Bitfield
;
; Bit Type of tracing
; --- ---------------
; 1 - Trace Evaluator instructions (not recommended)
; 2 - List Evaluator program (not recommended)
; 4 - Show assignments to variables
; 8 - Show fetched values
; 16 - Show stack
; 64 - Trace start of programs
; 128 - Trace external function calls
; 256 - Trace internal function calls
; 512 - Show parameter values
; 1024 - Show function return value
; 2048 - Trace each statement in program (recommended)
; Dynamic change allowed for TracePC and TracePCMask
TracePC=0
TracePCMask=4095

Here is how to interpret a trace:
**************************************

The trace on the following page shows two things being traced: SQL and PeopleCode.

SQL Trace:

The SQL Trace traces API calls. While there are many different API calls used, Ill cover the relevant ones. API call description
COM Compile/prepare a SQL statement
CEX Compile and execute a SQL statement
EXE Execute a compiled SQL statement
Fetch Fetch a single row.
Bind Bind a parameter (this is for bind variables)
Connect If this is for cursor 1, then this will result in a physical connection to the database and it will allocate a cursor. If this is for cursor > 1, then this will simply allocate a new cursor.
Disconnect This will close a cursor. If this is for cursor 1, then this will terminate the connection to the database.
Commit Commit the Unit of Work.

PeopleCode Trace:

The PeopleCode trace shows the starting and ending of programs. It also shows the calling of any child programs.
� Start = The start of a Program.
� End = The end of a Program.
� Start-ext = The start of a child Program.
� End-ext = The end of a child program.
.

Trace Examples
This trace is for PeopleTools 8.0.

1-23339 18.22.07 0.020 Cur#1.OM800DVL RC=0 Dur=0.010 COM Stmt=SELECT OPRID, NAME1, BUSINESS_UNIT, SETID, LEDGER, LEDGER_GROUP, SOURCE, (CONVERT(CHAR(10),AS_OF_DATE,121)), LC_CNTRY, ALT_CHAR_ENABLED, DR_CR_VISIBLE_FLG FROM PS_OPR_DEF_TBL_FS WHERE OPRID=:1 ORDER BY OPRID
1-23340 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Bind-1 type=2 length=3 value=VP1
1-23341 18.22.07 0.010 Cur#1.OM800DVL RC=0 Dur=0.010 EXE
1-23342 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Fetch
1-23343 18.22.07 0.010 >>> start Nest=00 . EG_DISP_ECO_WRK.INV_ITEM_ID.RowInit
1-23344 18.22.07 0.010 >>> start-ext Nest=01 eg_set_eco_fields FUNCLIB_EGINTFC.EG_DISP_ECO.FieldFormula
1-23345 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 COM Stmt=SELECT BUSINESS_UNIT, INV_ITEM_ID, ECO_ID FROM PS_EG_ECO_DISP_FS WHERE BUSINESS_UNIT=:1 AND INV_ITEM_ID=:2 ORDER BY BUSINESS_UNIT, INV_ITEM_ID
1-23346 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Bind-1 type=2 length=3 value=M04
1-23347 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Bind-2 type=2 length=5 value=30100
1-23348 18.22.07 0.010 Cur#1.OM800DVL RC=0 Dur=0.010 EXE
1-23349 18.22.07 0.000 Cur#1.OM800DVL RC=1 Dur=0.000 Fetch
1-23350 18.22.07 0.010 Cur#1.OM800DVL RC=0 Dur=0.010 COM Stmt=SELECT SETID, INV_ITEM_ID, DESCR60 FROM PS_MASTER_ITEM_TBL WHERE SETID=:1 AND INV_ITEM_ID=:2 ORDER BY SETID, INV_ITEM_ID
1-23351 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Bind-1 type=2 length=3 value=MFG
1-23352 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Bind-2 type=2 length=5 value=30100
1-23353 18.22.07 0.010 Cur#1.OM800DVL RC=0 Dur=0.010 EXE
1-23354 18.22.07 0.000 Cur#1.OM800DVL RC=0 Dur=0.000 Fetch
1-23355 18.22.07 0.000 <<< end-ext Nest=01 eg_set_eco_fields FUNCLIB_EGINTFC.EG_DISP_ECO.FieldFormula Dur=0.030
1-23356 18.22.07 0.000 >>> start-ext Nest=01 eg_disp_eco FUNCLIB_EGINTFC.EG_DISP_ECO.FieldFormula
1-23357 18.22.07 0.000 <<< end-ext Nest=01 eg_disp_eco FUNCLIB_EGINTFC.EG_DISP_ECO.FieldFormula Dur=0.000
1-23358 18.22.07 0.000 <<< end Nest=00 . EG_DISP_ECO_WRK.INV_ITEM_ID.RowInit Dur=0.050
1-23359 18.22.07 0.000 >>> start Nest=00 . EN_REVISION.DATE_IN_EFFECT.RowInit
1-23360 18.22.07 0.000 <<< end Nest=00 . EN_REVISION.DATE_IN_EFFECT.RowInit Dur=0.000
1-23361 18.22.07 0.000 >>> start Nest=00 . DC_PB_WRK.DC_QRY.RowInit
1-23362 18.22.07 0.000 >>> start-ext Nest=01 Init_DC FUNCLIB_DC.DC_SETUP_PANEL.FieldFormula
1-23363 18.22.07 0.000 <<< end-ext Nest=01 Init_DC FUNCLIB_DC.DC_SETUP_PANEL.FieldFormula Dur=0.000
1-23364 18.22.07 0.000 <<< end Nest=00 . DC_PB_WRK.DC_QRY.RowInit Dur=0.000
1-23365 18.22.07 0.000 >>> start Nest=00 . DC_COPY_WRK.DC_COPY_SRC.RowInit
1-23366 18.22.07 0.000 <<< end Nest=00 . DC_COPY_WRK.DC_COPY_SRC.RowInit Dur=0.000

Understanding the Trace:

Heres how to understand the trace. Lets look at this trace line.

SQL Trace:
1-23339 18.22.07 0.020 Cur#1.OM800DVL RC=0 Dur=0.010 COM Stmt=SELECT OPRID, NAME1, BUSINESS_UNIT, SETID, LEDGER, LEDGER_GROUP, SOURCE, (CONVERT(CHAR(10),AS_OF_DATE,121)), LC_CNTRY, ALT_CHAR_ENABLED, DR_CR_VISIBLE_FLG FROM PS_OPR_DEF_TBL_FS WHERE OPRID=:1 ORDER BY OPRID

First column = 1-23339. This is a sequential line counter for that process (exe). If you have a second process running, then its line numbers will start with 2-xxx.

Second column = 18.22.07. Is the timestamp at which the trace line is written. This timestamp comes from the machine in which PeopleTools is running It does not come from the database.

Third column = 0.020. This is the time that has elapsed since the previous trace line was written. This means that line 1-23339 was written 0.020 seconds after line 1-23338. This time will be explained in more detail.

Fourth column = Cur#1. This is the cursor number for the statement. If you open a second cursor it will have a cursor number > 1.

Fifth column = OM800DVL. The PeopleSoft database in which this API call is executing.

Sixth column = RC=0. This is the return code for the associated API call.

Seventh column = Dur=0.010. This is the time to execute the assoicated API call. Depending on what the call is this might be the time to execute the statement. This will be explained in more detail.

Eight column = COM Stmt=SELECT OPRID, NAME1.. This is the database API call.

PeopleCode Trace:
If we look at these lines:
1-23361 18.22.07 0.000 >>> start Nest=00 . DC_PB_WRK.DC_QRY.RowInit
1-23362 18.22.07 0.000 >>> start-ext Nest=01 Init_DC FUNCLIB_DC.DC_SETUP_PANEL.FieldFormula
1-23363 18.22.07 0.000 <<< end-ext Nest=01 Init_DC FUNCLIB_DC.DC_SETUP_PANEL.FieldFormula Dur=0.000
1-23364 18.22.07 0.000 <<< end Nest=00 . DC_PB_WRK.DC_QRY.RowInit Dur=0.000

The first three columns are the same as they would be for a trace of an SQL event so well skip these.

Fourth Column >>> start = This indicates whether or not a PeopleCode program is starting or ending. If there is an ext following the command then this indicates that the PeopleCode program has been called from another PeopleCode program.

Fifth column = Nest=00. This indicates whether or not the PeopleCode has been called from another program. If it is Nest=00, then the PeopleCode has been triggered by an event and not by being called another program. If the numbers after the Nest are > 00, then this indicates that the program has been called by another program.

Sixth column = . DC_PB_WRK.DC_QRY.RowInit. This indicates the location of the Program. This tells you what Record.Field this Program is from (or new in 8.0, what PanelGroup, Record, Menu, etc).If a . Preceeds the name that this indicates that program has been triggered by an Event. If a function name Init preceeds the name than this indicates that this program has been called by another program.

Understanding the Trace Timers:

Understanding the trace timers is very key to diagnosing where performance issues are. There are two main timers to understand.

Seventh column = Dur=0.010. This represents the time for the API associated with the SQL statement to run. In other words, this could be the time to Prepare, Execute,

Third column = 0.020. To reiterate from above, this is the time since the previous trace line was written. So this time could represent any of the following:
� User Think Time. If the value here is very large than most likely this time is User Think Time. If the line prior to this line is a Disconnect, Commit or a Rollback then there is a very good chance that this time is User Think Time. If this is the case then, a large value here should be of no worry.
� PeopleTools processing This would be for an activity that did not result in a Trace line being written. This might be PeopleCode (providing the PeopleCode trace was NOT turned on), this could be Panel Processor, this could be PeopleTools waiting for a Remote Call (a COBOL process which runs as a whole separate process) to complete, etc. A large value due to one of these reasons is something that should definitely looked into.
� SQL Time This includes (is a superset) the SQL time
Manager Information trace

The Manager Information trace can be used to determine the location from which PeopleTools meta-data objects are retrieved. These objects reside within the database but are read into memory by each PSAPPSRV process as they are required. As of PeopleTools 7.5 some (but not all*) memory cached objects are also file cached on the application server. The file-cached objects reduce the time required to cache a newly booted PSAPPSRV process.Whenever a PSAPPSRV requires a new object it first looks in the file-cached objects before retrieving the database object.

It is important to remember that each PSAPPSRV process has its own memory cache.

To determine whether an object is retreived from memory, file cache or database, enable the Manager Information trace flag. The location are as follows:

Object retrieved from Memory:
PSPPRSRV.20997 1-101716 Get : Local RDM(VNDR_PANELS_WRK/POR)0.0.233300

Object retrieved from File -
PSPPRSRV.20997 1-101716 Get : Cache XTM(LANGUAGE_CD/ENG)0.12312.1

Object retrieved from Database -
PSPPRSRV.20997 1-101716 Get : Remote 2130647268.1.0

* Not all objects on the app server are file cached. What this means is the very first access to these objects will be from the database instead of file cache. Subsequent accesses will be from memory cache. The things that are not file cached are the infrequently accessed objects.