- SAP Managed Tags:
Introduction
From 2402 Release, SAP S/4HANA Cloud Public Edition added a new system monitoring capability, collectively called the Technical Monitoring Cockpit for monitoring the ABAP system. The Cockpit provides a seamless connection between your system workload and single ABAP statistics records (main records and sub-records) down to SQL statements and their prepared plan. Now you have a good starting point to conduct performance analysis on the SAP S/4HANA system in case of high response times, especially when you are an administrator or a developer.
As this Technical Monitoring Cockpit is not unique to the SAP S/4HANA Cloud Public Edition, but also to the SAP S/4HANA Cloud Private Edition and the Business Technology Platform, the discussion here applies to them as well.
I plan to tackle this topic in a series of blogs in bite sizes so that you can easily consume them during your day-to-day work.
- Technical Monitoring Cockpit Introduction Series – Clicking Through: this blog provides a guided tour of the Cockpit to readers, walkthrough (clicking through) various functions and resolve some confusions.
- Technical Monitoring Cockpit Introduction Series – The Key Concepts: this blog explains what metrics we are looking for in the Cockpit, and how they can be helpful to you, especially when something seems suspicious.
- Technical Monitoring Cockpit Introduction Series – Diving into Your Own System Workload: this blog discusses the approach as an administrator/developer to analyze the system performance daily.
- Technical Monitoring Cockpit Introduction Series – Analyzing Performance with A Customized Profile (to be published): this blog discusses how to take the advantage of setting up a profile to record system data you are interested, hence analyze the data when issues surface.
In my previous two blogs of this Technical Monitoring Cockpit series, I explained how to click through these apps and the key concepts, now let’s put them into use in your own system: how to do a system analysis as an administrator/developer daily.
System Workload
When talking about the system monitoring, the first entry is the System Workload app (see my previous blog on how to access it).
The below screen System Workload: Response Time Contribution gives a glimpse on how the system is utilized in the past 24 hours (Note: my most business users are in Asia, so the heavy workload appears in my midnight to early morning since I am located in US East Coast.)
- During the past 24 hours (12 pm on Oct. 9 to 12 pm on Oct. 10), heavy workload happened around 2 am to 6 am.
- The peak Response Time Contribution reached 360 seconds.
- If I am curious on the peak Response Time Contribution, I can move the Time Slider to left. Comparing with two graphs of Oct. 8 vs. 9, we found
- The peak Response Time Contribution is about the same, 300+ seconds, although they occurred at a different time slot.
- When focusing on the highest Response Time Contribution, the pattern is similar with three high components: the Roll Wait Time, the ABAP Processing Time and the HANA Execution Time.
The Peak Response Time Contribution from 12 pm to 12 pm on Oct. 9
The Peak Response Time Contribution from 12 pm to 12 pm on Oct. 8
Now let’s narrow the time range to 2:30 – 3:15 am. I want to find out the reason of high Roll Wait Time, ABAP Processing Time and HANA Execution Time. By clicking on Roll Wait Time in the Legend, we can see the Remote Function Call (RFC) is the main contributor, almost 93% ((56.36+56.24+49.39+8.99+8.97+8.27)/201.76). The top three programs are QDEST_RUN, QDEST_RUN_DESTINATION and ARFC_RUN_NOWAIT.
Explore the Cause of Long Roll Wait Time
The Roll Wait Time represents a time for which the roll context was rolled out. In the below figure, it is a major contributor to an RFC Process or waiting time until the results are returned from an external system. This matches with the nature of an RFC call, i.e., you have no control over an external system on how fast it returns the result to you.
Contributors to the Server Response Time in a Synchronous RFC Processing (from SAP Help)
Now I click on the ABAP Processing Time in the Legend, the top ten contributors are listed in the table. The top one is to run a program called /sap/opu/odata/sap/ESH_SEARCH_SRV/DataSources in an OData V2 type request.
Explore the Cause of Long ABAP Processing Time
Go to the details (right most > button of the record), we can see this program was run seven times as listed in the table. The processing time is quite even, between 1.46 to 2.04 seconds.
ABAP Processing Time of Running Program /sap/opu/odata/sap/ESH_SEARCH_SRV/DataSources (At 10-Minute Intervals)
In the blog Technical Monitoring Cockpit Introduction Series – Key Concepts, I explained how the ABAP Statistics Data are collected: one minute at a time on those completed work processes (look back), and data are aggregated. How about we look at the data in a different granularity? For example, select As Collected? That is a different view (see below). However, we still cannot pin down which vertical purple bar belongs to which of these seven runs.
ABAP Processing Time of Running Program /sap/opu/odata/sap/ESH_SEARCH_SRV/DataSources (As Collected)
To get the details of each run, I click on the Details button at the right of the top row. This brings me to the ABAP Statistics Record screen with more information about this record.
In the tab Server Response Time Contribution, it provides all the metric data of this program. The large portion of the time is spent on the ABAP Processing and HANA Execution.
ABAP Statistics Record – Server Response Time Contribution
When I see the Database Network Time is 148.54 milliseconds, it tells me there are many trips to the database. I want to explore further by clicking on the tab Data Connections. There are 26,326 database calls. This confirms a lot of trips were made to the database.
By clicking on the Details button again, we can see the Database Connection Details screen. Although there are 26,326 logical database requests, only 333 physical database requests happened. From database point of view, it is efficient as most data are cached.
Database Connection Details
You can also explore the SQL statements associated with this long ABAP Processing Time by clicking on the tab SQL Statements. When clicking on the first row of the program, you can see the details of this SQL statement.
SQL Statement Details
Sampled Work Process Data
In the blog Technical Monitoring Cockpit Introduction Series – Key Concepts, I discussed there are two perspectives of exploring system performance. One is the System Workload, which has data at every minute on those completed work processes. Another one is called Sampled Work Process Data. It is looking at data at every second including those currently running work processes. I use this perspective to identify the running programs after I notice a peak resource consumption from System Workload. Let me explain that.
The below figure displays the Sampled Work Process Data at the same time range as above, from 12 pm on Oct. 8 to 12 pm on Oct. 9.
Sampled Work Process Data (from 12 pm on Oct. 8 to 12 pm on Oct. 9)
It is tricky to isolate these colorful bars around 3 am. If you try to narrow down to 2:30 – 3:15 am, you don’t see any data. So, you have to enlarge the time range, for example 18:15 – 8:37. After applying filter of OData V2, I got the below chart and table.
Sampled Work Process Data: ABAP CPU Time (18:15 – 8:37)
In the previous section, I was investigating a high ABAP CPU Time with the following information:
- Request Entry Type: OData V2
- Request Entry Name: /SAP/ESH_SEARCH_SRV/0001
- Program Context: /sap/opu/odata/sap/ESH_SEARCH_SRV/DataSources
- Start Time: 2024-10-09 02:34:57.92458200
Now I click on the first row with the same - Request Entry Name: /SAP/ESH_SEARCH_SRV/0001. A new screen opens with a time series of this Program Context but different Program Name. When I focus on the time range of 2:34:57.92458200, there are three programs running in that vicinity, namely:
- /IWCOR/CL_DS_EP_HELPER========CP
- CL_ACMRT_KERNEL_PROXY=========CP
- /IWCOR/CL_DS_EP_HELPER========CP
Request Entry Point: OData V2 and /SAP/ESH_SEARCH_SRV/0001
Take the last program /IWCOR/CL_DS_EP_HELPER========CP as an example. I click on the Details button on the right. It reveals the Single Work Process Sample screen. I can review the Response Time and other information.
Single Work Process Sample – Work Process Metrics
When clicking the “ABAP Statistics Record” button, the ABAP Statistics for this Request Entry Point becomes available. Please keep in mind that this Record is an aggregated information of this Request Entry Point in the past minute, no longer at that second. But it is still good enough for you to isolate the program you are interested in.
ABAP Statistics Record for Program /IWCOR/CL_DS_EP_HELPER========CP
You can do the same for other two programs: /IWCOR/CL_DS_EP_HELPER========CP and CL_ACMRT_KERNEL_PROXY=========CP.
Conclusion
This blog discusses a daily routine work for an administrator or a developer on how to discover a high resource consumption activity, and find out the program causes that by using both the System Workload and Sampled Work Process apps.
References
- SAP Help: Monitoring the System Workload
- Blog: Technical Monitoring Cockpit Introduction Series – Clicking Through
- Blog: Technical Monitoring Cockpit Introduction Series – The Key Concepts
- Blog: Technical Monitoring Cockpit Introduction Series – Diving into Your Own System Workload
- Blog: Analyzing performance degradations in the ABAP environment in the Cloud
