Skip to Content
Technical Articles
Author's profile photo Qiansheng Wang

Analyze ABAP Performance Traces with the Profile Data Analyzer

In this blog post, we would like to introduce the “profile data analyzer”, a new standalone tool to analyze performance trace, including the idea behind it and the analysis steps. The profile data analyzer supports both ABAP performance trace and SAP JVM Profiler performance trace (*.prf format) as documented in KBA 2879724, but we will focus on the analysis of ABAP performance trace in this blog post.

The profile data analyzer is inspired by Brendan Gregg’s FlameGraphs. It provides additional graphic and interactive views comparing to SAT/SE30/ST12 to make the performance analysis easy, for example, in the following scenarios.

    • Get an overall picture of the traced program, including the program logic and how the time is spent.
    • Find out the bottleneck in large and complex traces, especially when the time is averagely spent on different methods.
    • Compare two traces in the graph view. Sometimes it is helpful to compare two traces, for example, to understand why there is a performance downgrade after a support package upgrade.

In the following parts of this blog post, we will demonstrate how to use the profile data analyzer to understand both the performance bottleneck and the program logic for optimization.

“The real problem is that programmers have spent far too much time worrying about efficiency in the wrong places and at the wrong times; premature optimization is the root of all evil (or at least most of it) in programming.”
–   Donald Knuth, “Computer Programming as an Art (1974)

Getting Started

To start the analysis, we only need 2 prerequisites

    • Download the profile data analyzer from here following KBA 2879724. The profile data analyzer is a standalone jar file which needs Java 8 or higher. It can be run on Windows, Linux, and macOS environments by double-clicking or command java -jar ProfileDataAnalyzer.jar.
    • Collect a performance trace following KBA 2881237.  Profile data analyzer needs the ABAP trace without aggregation or aggregated by call stack which has more information than aggregation by call position. The file name is “AT*”.  We could get this file from OS level on the the dialog instance data folder( /usr/sap/<System-ID>/<Instance>/data) or by SE30 following KBA 2881237

This blog will use two SM21 traces as examples to show the usage of the profile data analyzer. The main difference between these two SM21 traces is the data volume. We will show how to use the profile data analyzer to understand SM21’s logic and the performance of these two traces, including their difference.

    • The short SM21 trace. Change the selection criteria in SM21(e.g. time) to make sure that no log entry is shown on the screen.
    • The long SM21 trace.  Change the selection criteria in SM21(e.g. time) to make sure that many log entries are shown on the screen.

Now we could drag and drop the collected ABAP trace into the profile data analyzer and click the “Analysis Report” button to show the report and flame graph.

Flame Graph for Performance trace

Here is the flame graph with the default setting for the short SM21 trace (Tip: Please zoom this page in your browser to view the details of the flame graph). In the flame graph

    • Every column is a call stack. The main program is at the bottom (e.g. Transaction SM21 on the following picture). The lower method calls the upper method.
    • The width in the graph is proportional to the actual time used by that call stack.
    • We could zoom in or zoom out in the graphic view by clicking a method on the call stack.
    • Special method types have dedicated colors. For example, DB methods are blue.
    • We could search a keyword with the “Search” button with regular expressions. The search results will be highlighted in purple.
    • The call count of a call stack is shown like “Calls: XXX” on top of the call stack.

Understanding the short SM21 performance trace

Looking at the above flame graph for the short SM21 trace, the following methods are highlighted in purple by searching with “MAIN|RSLG_DISPLAY|GET_INSTANCE_BY_FILTER”

    • PERFORM MAIN
    • CALL FUNCTION RSLG_DISPLAY
    • CL_SYSLOG.GET_INSTANCE_BY_FILTER

In the above graph, we could find that

    • The form MAIN is the main part of Program RSYSLOG / TRANSACTION SM21.
    • In form MAIN, the important calls are function module “RSLG_DISPLAY” and class method “CL_SYSLOG.GET_INSTANCE_BY_FILTER”.
    • Because “RSLG_DISPLAY” has a long execution time than “GET_INSTANCE_BY_FILTER”, it is wider and longer in the flame graph.
    • Move the mouse to a method, the tooltip will show the detailed time information.

We can click “CL_SYSLOG.GET_INSTANCE_BY_FILTER” to focus on the details of “GET_INSTANCE_BY_FILTER” and hide other parts. Here is the focused view for “GET_INSTANCE_BY_FILTER”. In this focused view, we could find that

    • “GET_INSTANCE_BY_FILTER” calls other methods and function modules, e.g. “READ_ENTRIES” and “RSLG_READ_SLG” which is used to read the system log entries.

Another interesting part in this example is that, there are some “Not shown methods” on top of “RSLG_DISPLAY” and “CALL_SCREEN”. They are some SYSTEM programs that are filtered. The filter rule is the same as the default SAT setting. We could show these filtered methods by checking the “Show technical details” option.

Check the “Show technical details” option and click the “Analysis Report” button again, we will get the following un-filtered graph. In this graph, we could find that

    • “RSLG_DISPLAY” will call some screen function modules and finally use RFC “OLE_FLUSH_CALL” to communicate with SAPGUI.
    • Usually the percentage of “Not shown methods” is low, because most of the cases, the application programs use more time. We recommend using the default profile data analyzer options as the very beginning, and only check the “Show technical details” option when the time of “Not shown methods” is long.

Understanding the long SM21 performance trace by diff

Now let’s understand the long SM21 trace. Here is the flame graph of the long SM21 trace. In this graph, we could find out that

    • “GET_INSTANCE_BY_FILTER” is longer than the short SM21 trace because we select more data in the long SM21 trace.

Look at the above graph, it is also not so clear about the exact difference with the short SM21 trace. To improve it, we developed the diff function. We could compare the two SM21 traces with the following steps.

    • Drag and drop the short SM21 trace into the profile data analyzer. The first trace will be used as the benchmark.
    • Click the “Diff …” button and then select the long SM21 trace. The second one is the performance trace to analysis.
    • Then the diff report will be shown in your browser automatically.

Here is the flame graph in the diff report, and the tips to read this diff graph.

    • In the diff graph, The increased time is shown in green and marked with “+”. Reduced time is shown in red and marked with “-“.
    • To understand which methods spend more time in the second trace compared to the benchmark, we should check the green parts with “+” (increased time).

In the above diff graph, we could find out that the time of both “RSLG_DISPLAY” and “CL_SYSLOG.GET_INSTANCE_BY_FILTER” is increased (see the green parts). Let’s take “GET_INSTANCE_BY_FILTER” for example. Here is the focused graph for “GET_INSTANCE_BY_FILTER” by clicking it. In this graph, we could find that

    • Most of the increased time in “GET_INSTANCE_BY_FILTER” is because of “CL_SYSLOG.APPEND_ENTRY”.
    • In the short SM21 trace,  “CL_SYSLOG.APPEND_ENTRY” is not visible. This is because  “CL_SYSLOG.APPEND_ENTRY” is not called, or its execution time is too short.
    • In the long SM21 trace,  “CL_SYSLOG.APPEND_ENTRY” is longer. Its execution time and call counts (“Calls: XXX” on top of a call stack) are shown in the graph.

Now let’s have a look at the class “CL_SYSLOG” in SE24. Comparing to the short SM21 trace (no trace entry is selected and displayed), the long SM21 trace need to call “APPEND_ENTRY” many times to append entries and also call “DETERMINE_SYSLOG_TEXT” to determine the system log entry’s text, and as a consequence, the long SM21 trace runs longer than the short SM21 trace.

Allocation Analysis

If memory information is collected in SE30/SAT trace, the “Allocations” information will be shown in the analysis report, otherwise, it will be hidden. The “With memory use” in the following picture is the option to control whether memory information will be collected. KBA 2881237 contains more detailed information about the trace variant.

Here is an example of the allocation stack flame by tracing SM21, including the normal view and diff view. The allocation flame graph follows the same analysis rules as the performance flame graph.

    • Focus on the widest flame in the graph. The width in the graph is proportional to the actual memory allocated in that call stack.
    • The tooltip of a method shows details, such as allocation information.
    • Zoom in or zoom out in the graphic view by clicking a method on the call stack.
    • Search a keyword with the “Search” button with regular expressions. The search results will be highlighted in purple in the flame graph.
    • In diff graph, comparing to the first benchmark trace, the increased memory allocation is shown in green and marked with “+”, and the reduced memory allocation is shown in red and marked with “-”.

Advanced Analysis: Convert ABAP trace to *.PRF file and analyze it in SAP JVM Profiler

For advanced analysis, the ABAP traces can be converted to the SAP JVM Profiler format(*.prf) via the export button and then analyzed via SAP JVM Profiler.

The detailed information and analysis steps could be found in the following documents.

Here we only list some screenshots to show the general idea about analyzing the converted ABAP trace in SAP JVM Profiler.

Feedback

Please feel free to post any feedback to the profile data analyzer on this blog post. In case the profile data analyzer is not working as expected or needs to be fixed, please let us know. Thanks!

Assigned Tags

      19 Comments
      You must be Logged on to comment or reply to a post.
      Author's profile photo Wouter Peeters
      Wouter Peeters

      Hi,

      I'm trying out the tool with a SE30 trace file:

      • ABAPTraceFile

      When I load it in the tool, he shows progress updates like 'read abap records ' etc

      But then a popup with error is shown:

      Error C:\Users\myusername\AppData\Local\Temp\8\ABAPTraceFile.prf (The system cannot find the path specified)

       

      The subtle difference in filename .prf makes me assume he makes a local .prf file based on the abap trace file, but it is unclear to me why he can't find it anymore afterwards. Perhaps Security settings on my laptop?

       

      Can you help? Or should I create a message?

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Wouter, thank you very much for your interest and for sharing the first comment!
      How about the current status? Is this issue solved?

      About this issue, yes you are right. This tool will make a local temp .prf file based on the ABAP trace file. This temp file will also be removed when the profile data analyzer is closed. So I am also thinking it may be related to some security settings.

      If the issue is still there, I would like to check some detailed information.
      Would you mind send me an email to “qiansheng.wang AT sap.com”.
      You can always reach me via email, and I think the email will be easy for you.

      Thanks very much.

      Best regards,
      Qiansheng Wang

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Wouter, I hope everything is working well now. Because I did not get an email from you, I guess this issue is already solved. Please feel free to send me an email if there is any other issue at any time. You are welcome, and your feedback is always important and appreciated.

      Thanks, and regards,
      Qiansheng Wang

       

       

      Author's profile photo Ayesha Ahmed
      Ayesha Ahmed

      Performance  check gives me better idea to understand. Thank you Mr. Wang. Do you need particular tool in the cockpit to check or execute the tcode: SM21.

      Then there certain code: CN30/ CJ30. ME21N, gATP, FB50, etc,. will have a highier impact? How to do all at one time so when run the batch job can sequence so the system process availability and the order of the operation can be sequenced. Postings etc will take time and external file update.

      Regards,

      Ayesha.

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Mr. Ayesha Ahmed, thank you very much for your interest. I think you mean how to collect the performance trace, for example, whether we need to execute SM21 in a special tool to collect the performance trace.

      For short, the profile data analyzer does not collect the performance trace by itself. The performance trace can be collected by SAP standard tools for both ABAP and Java. No other special tools are needed to collect the performance trace. I documented the detailed steps in the following KBA about how to collect the performance traces.

        • KBA 2881237 – How to collect performance trace for the profile data analyzer

      For ABAP, the trace can be collected or scheduled via SE30, SAT or ABAP in Eclipse. For background jobs, I’m not sure how long your job will be, but the trace size will be big in the “no aggregation” option. So, I would like to suggest trying the “aggregated by Call Stack” option as documented in KBA 2881237 at the very beginning, and/or starting from small data volume to make the job short and understand the possible trace size. This KBA will also guide you to other online help pages or other resources about this topic. I hope it is helpful.

      At last, after the performance trace is collected, the profile data analyzer does not need to connect to other tools or backend ABAP/Java systems (e.g. where the performance trace is collected) to get more information for analysis or checking purposes. It is a standalone tool that only needs the performance trace (ABAP: AT*, Java: *.prf).

      Hope this information is helpful. : )

      Thanks, and regards,
      Qiansheng Wang

      Author's profile photo Ayesha Ahmed
      Ayesha Ahmed

      Hello Qiansheng, Thanks for the response. I It helps.

       

      Best Regards,

      Ayesha.

      Author's profile photo Pavlo Astashonok
      Pavlo Astashonok

      there are some “Not shown methods” on top

      I see no "not shown methods" in my traces. Why? As I got it this stub is showed with disabled tech details in settings, and with enabled they should unfold into real method names. And I see neither of two

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Pavel, thank you very much for trying the profile data analyzer!

      Yes, You are right. The option "Show Technical Details" will unfold the filtered records. For short, the default behavior is the same with T-Code SAT that the SYSTEM methods and "Memory/Runtime Management" methods will not be shown.

      Take the SM21 traces in this blog as examples, most of the hidden SYSTEM methods are responsible for the communication to SAPGUI, which might not be so interesting when we want to improve the ABAP program's performance itself.

      Together with ProfileDataAnalyzer.jar, there is a PDF document "Profile_Data_Analyzer.pdf" in the SCN download package. More detailed information and screenshots could be found by searching "Show Technical Details" in this PDF file or in this blog post.

      To be honest, I think this option should work, and at this moment, I did not think of some reasons which could make it fail. After we change the option "Show Technical Details", we only need to click the "Analysis Report" button again. Would you mind send me more information if you still have the problem, for example, your ABAP trace and screenshots? I would like to check the details.

      Here is my email “qiansheng.wang AT sap.com”.

      BTW, the idea of "Show Technical Details" it to make the default behavior similar and consistent with existing tools, and do not give end users surprise, especially when end users are working together with the existing tools.

      Best regards,
      Qiansheng Wang

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Pavel,

      Another comment for your scenario. Only certain methods are filtered (such as the communication with SAPGUI as shown in the SM21 example in this blog. The rule is the same with SAT default).

      In case your program is not executing these kinds of methods, then there is no difference in the resulting flame graph (independent of whether you've selected "Show Technical Details").

      Best regards,
      Qiansheng Wang

      Author's profile photo Pavlo Astashonok
      Pavlo Astashonok

      Do you know about call timeline in the Eclipse tools?

      It's representativeness is somewhat the same as Flame Graphs so mainly overlaps with the functionality of your tool.

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Pavel,

      Thank you very much for trying profile data analyzer and for raising this discussion to me! This is a very interesting topic, and I would like to highlight two main differences. : )

      For the second point, I would like to quote the following comment from Brendan Gregg(the author of the Flame Graph), which explains the difference between time-ordered visualization and flame graph visualization.

      https://bugzilla.mozilla.org/show_bug.cgi?id=1123495

      The time-ordered visualization solves many problems: it shows very slow code paths, and time-based patterns.

      However, faster and changing code paths may be rendered as thin icicles, without enough horizontal space to draw the function names. Understanding this profile requires the user to zoom. This can be both time consuming, and the user can lose notion of the big picture.

      For these cases, by switching the x-axis sort order from time-based to alphabetical for the stack (origin to leaf, which in the icicle plot is top-down), all thin icicles of the same code path are merged. This allows a quick visual appreciation for where time is spent, at the sacrifice of time-ordered patterns. The alphabetical sort is called a “flame graph” (http://www.slideshare.net/brendangregg/blazing-performance-with-flame-graphs/35).

      Here are some tips highlighted by me about how to read and get information from the profile data analyzer flame graph. These tips can also show the difference between “Call Timeline” and profile data analyzer.

        • Every column is a call stack. The main program is at the bottom. The lower method calls the upper method.
        • The width in the graph is proportional to the actual time used by that call stack.
        • To find out the most expensive part of a program, we could just focus on the widest column in the graph. Because if a short code path(call stack) is executed many times in different timestamps, they will be merged together in the flame graph.
        • The call count is shown in the graph. Currently, it is shown as “Calls: XXX”, in the future it will also be shown in the tooltip.
        • We could zoom in or zoom out in the graphic view by clicking a method on the call stack, to focus on special code paths(call stacks) or show the hidden columns again.

       

      Best regards,
      Qiansheng Wang

      Author's profile photo Tony_S0002689259 Bramhill
      Tony_S0002689259 Bramhill

      I am trying the tool with a measurement file from SAT, downloaded to my local pc. But when I try to import the file, I get this error message: 'Trace.xml is not a valid profile file'.

      But this trace file was generated normally by SAT, no aggregation. What could be the cause?

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Tony,  thank you very much for your interest and the feedback.

      The reason is that the tool needs the original binary format currently. And the XML format is not supported at this moment, because the original binary format contains more helpful details for the analysis than the XML format.

      To solve it, there are 2 ways to get the original binary ABAP trace file.

        • Go to SE30 (old SE30, not SAT) => Click the "Other File..." button => Search and select the target trace => Click the "copy to local file..." button to download it.
          • The detailed steps with screenshots could be found in the following KBA by searching the keyword "download".
          • KBA 2881237 - How to collect performance trace for the profile data analyzer
        • Go to the OS level and get it directly if OS accessing is possible. The binary trace file is saved in the data folder of the dialog instance ( /usr/sap/<System-ID>/<Instance>/data ), and its filename starts with "AT".

      BTW, the following documents might also be interesting for some other resources or tips.

      At last, hope this issue will be solved, and you will enjoy the profile data analyzer. Please feel free to send me an email to “qiansheng.wang AT sap.com” in case of any other feedback or I am not able to reply here in time.

      Thanks and best regards,
      Qiansheng Wang

       

      Author's profile photo jianfeng zhang
      jianfeng zhang

      Hi,

      I'm trying out the tool with a SE30 trace file.

      When I load it in the tool, it shows error:

       

      Please help.

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Jianfeng, thank you very much for your interest and the feedback.

      Currently, I think there might be two possible reasons.

      I hope the above 2 directions could solve this issue. Just in case not, it might be fast to send me some screenshots or the example ABAP trace (if it is OK for you) to my email “qiansheng.wang AT sap.com”.

      At last, here are another 2 comments which might be interesting for you.

        • The following KBA might be helpful for this topic.
          KBA 2881237 - How to collect performance trace for the profile data analyzer
        • If you are working on an ABAP system in the new release. It is also possible to enable the "Call Stack Aggregation(ADT)" aggregation in the SAT variant.

      Thanks and best regards,
      Qiansheng Wang

      Author's profile photo Christoph Weyd
      Christoph Weyd

      Great Tool - Thanks very much!!

      One question however - you mention in this blog transaction ST12 - can I download that ST12 traces files to be processed by profile data analyzer?

      Kind Regards
      Christoph

      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Christoph, thank you very much!

      Profile data analyzer does not support the ABAP trace collected via ST12, because ST12 only supports the aggregation "Full" and "Per Call Position", and does not support the aggregation "None" and "Call Stack aggregation (ADT)"(KBA 2881237).

      The tool profile data analyzer will visualize the ABAP call stack, but the available options in ST12 do not have the completed ABAP call stack information in the ABAP trace. This is why the ABAP trace in ST12 is not supported by profile data analyzer.

      Best regards,
      Qiansheng Wang

      Author's profile photo Philippe Lagas
      Philippe Lagas

      Hi Qiansheng, thanks for this tool. Would there be any possibility to reduce memory usage of the tool? With trace files larger than 100MB, many gigabytes or RAM are required to run the tool. Often a system with 64GB or more is not available for a developer. A speedup would also be nice but not very necessary as we can run the program over night.

      Here is a wrapper script that adds:
      1. time spend and memory usage with /bin/usr/time
      2. headless CLI mode with xvfb and -Djava.awt.headless=true (you need to install the xvfb package for this to work)
      3. memory reduction my using the JVM Shenandoah Garbage Collector
      4. Thread usage can be configured with -XX:ActiveProcessorCount= or left out (adjust as necessary)
      5. A best effort to limit max memory usage with -Xmx${MEM_AVAILABLE_KB}k to prevent other processes running out of memory

      #!/usr/bin/env bash
      
      # Normal usage: abap_flamegraph -d . -s AT000000 -f output.html
      
      set -euo pipefail
      
      if [ $# -eq 0 ]; then
      xvfb-run -e /home/user/profile_data_analyzer_20210222/xvfb_error.log java -Djava.awt.headless=true -jar /home/user/profile_data_analyzer_20210222/ProfileDataAnalyzer.jar --help
      exit 1
      fi
      
      MEM_AVAILABLE_KB=$(awk '/MemAvailable/ { printf "%d\n", $2 }' /proc/meminfo)
      
      /usr/bin/time xvfb-run -e /home/user/profile_data_analyzer_20210222/xvfb_error.log java -Djava.awt.headless=true -XX:ActiveProcessorCount=8 -XX:+UseShenandoahGC -XX:+UnlockExperimentalVMOptions -XX:ShenandoahUncommitDelay=1000 -XX:ShenandoahGuaranteedGCInterval=10000 -Xmx${MEM_AVAILABLE_KB}k -jar /home/user/profile_data_analyzer_20210222/ProfileDataAnalyzer.jar $@
      Author's profile photo Qiansheng Wang
      Qiansheng Wang
      Blog Post Author

      Hi Philippe,

      Thank you very much for sharing. I completely agree that it does not make sense that a developer needs more than 64GB memory to analyze the ABAP traces with a size of approximately 100 MB.

      I have some colleagues who use PCs with 16 GB or 32 GB memory, and they are able to analyze similar-sized ABAP traces (around 100 MB) without experiencing an OOM error.

      The memory usage is not only related to the size of the ABAP trace. It can also depend on the complexity of the ABAP call stacks or other structures. If it is possible, I would like to check your examples. Would you please send me an email to “qiansheng.wang AT sap.com”? So I could create a container for you and then we could investigate this further.

      Thank you very much for your feedback again.

      Best regards,
      Qiansheng Wang