This is Part II. You may like to see
Part I.
In Part I, we showed you how to trace an ABAP program using STAD to show the single record statistics of the response times for a transaction/program.
In this part, we will go through and decipher the statistics to help you decide where the problem may lie in your slow performing program.
Following Part I, we saw the STAD screen output. Below is a snapshot of the right hand side of the screen showing the “standard” view fields:
The “Response time (ms)” field shows the total response time for the dialog step (or summary of steps if you have chosen not to expand the left tree).
As a reminder, SAP says (https://help.sap.com/saphelp_nw70ehp1/helpdata/en/21/2c8f38c7215428e10000009b38f8cf/content.htm
):
“Response time = wait time + execution time
where: execution time =
Generation time during the run
+ Load time for programs, screens, and graphical user interfaces
+ Roll times for rolling in the work data
+ ABAP processing time
+ Database time
+ Enqueue time for logical SAP lock processes
+ CPIC/RFC time
+ Roll wait time (excluding task types RFC/CPIC/ALE).“
So if we take a look at our initial screen of values, the example below shows that the “DB req time (ms)” is one of the larger values (4929):
The total database request time (time taken for database work to be done for this step) is more than 92% of the total response time for the step.
If the database time IS NOT a significant percentage of total response time, then you should check the other parts that make up the total response time, for clues.
At this point, it’s better to change the screen columns so that you can see all the timings.
The best view is the “Time Analysis” view. Switch views by clicking the “Sel. fields” button:
Click “Time Analysis“:
You will now see more timing fields
The fields highlighted are responsible for the total response time calculation.
In our example, TOTAL RESPONSE TIME = Wait Time + DB Req Time + Processing Time + Load Time + Generating Time + Roll In Time + Roll Wait Time + Enqueue Time.
=> 5330 = 0 + 4929 + 122 + 17 + 0 + 262 + 0
(5330 / 1000 = 5.3 seconds total response time)
You should check each of the fields, looking for disproportionate response times.
The “Wait time (ms)” indicates the amount of time the dialog step was waiting to be processed by a dialog work process. High values indicate that the overall system performance is degraded. Maybe a lack of memory, CPU or I/O performance at the O/S layer could be causing issues. Check the dispatcher queue.
The “Time in WPs (ms)” indicates the time that the dialog step was being actively serviced by a work process and not by any other type of process (BTC, UPD, UPD2 etc). Check “SM51 -> Goto -> Server Name -> Information -> Queue Information” and SM66 to see how busy the system is.
The “Processing time (ms)” indicates the amount of time the individual components spent processing (working) and not idle or sleeping or waiting. Check SM50 and SM66 to see how busy the system is.
Use ST06 (O/S monitor) to check CPU usage and system load.
The “Load time (ms)” indicates the amount of time taken to load the program code into memory buffers.
A problem here could indicate the program buffer is not large enough (see ST02). You should check the CPU time if the load time value is large.
Values for “Generating time (ms)” show the time spent compiling the ABAP source code. You will see a value here if the code has not already been compiled through SGEN. Any large values here for programs already generated could mean a problem in the database with the code storage tables.
Large values for “Roll (i+w) time (ms)” indicates that the Roll-In and Roll-Wait times are being affected.
Roll-In is the process of moving the users session context into the work process so that it can be used to execute the dialog step. High values could indicate that the roll buffer is too small (see ST02) or that the user has a very large set of roles and profiles and is consuming too much memory.
Values for “Enqueue time (ms)” show the time waited for a logical database lock to be performed.
A high value here could indicate excessive contention (someone else doing the same work) in the SAP system or the underlying database. Maybe check SM13.
If we look at a CPU time example, a high value here would indicate a large amount of overall processing causing the WP to use more CPU.
Maybe a rogue loop, or a large internal table operation.
The example below shows a high CPU time for a background job performing a lot of RFC calls.
Notice how the processing time (just off the screen shot, sorry) has increased too (some component has to do the work):
Could be that a lot of data/work was transfered by RFC call.
Summary:
If you see high database time in your analysis, Part III will show you how to perform an SQL trace to see what the database is doing for so long.
If you have high CPU/processing time, then in Part IV you will be shown how to find where exactly in the ABAP program is causing the most response time.
