Measuring runtime consumption with ABAP Profiling

Objectives
After completing this lesson, you will be able to:

After completing this lesson, you will be able to:

  • Profile an ABAP program
  • Detect Sequential reads using ABAP Profiling

The ABAP Profiler Tool

Starting the ABAP Profiler

You can start the ABAP Profiler for an individual ABAP program directly from the ABAP source code editor or from the Project Explorer view. Watch the demo "How to Profile an ABAP Program and Analyze the Result" later in this lesson to learn how to do this.

Trace Parameters

Using the trace parameters, you influence the size and granularity of the trace result. As shown in the figure, the most important settings are:

Aggregation Settings

In this section you specify how the profiler handles repeated executions, for example, repeated calls of the same method. The more the profiler aggregates, the less space is needed to store the trace result. As a kind of a drawback, some analysis tools are not available on aggregated trace results.

You can choose from three options:

  • No aggregation, largest file size, all tools available.
  • Partial aggregation (per call statement) , medium file size, Call Sequence not available.
  • Full aggregation, smallest file size, Aggregated Call Tree not available.

Statement Granularity

In this section, you can specify how granular the measurement will be. You can choose from three popular presets or, by choosing Custom Statements, enter your own selection under Details.

Again, your choice has an influence on the file size and the informative value of the trace result.

The following presets exist:

  • Only procedural units – small file size, the runtime of all statements is attributed to the surrounding procedural unit (method).
  • Procedural units, SQL – medium file size, the runtime of database accesses is traced separately and not attributed to the surrounding procedural.
  • Procedural units, SQL, internal tables – large file size, the runtime of database accesses and operations on internal tables are traced separately and not attributed to the surrounding procedural.

Start option

In this section, you can choose when you want to start the trace. You have the following options:

  • Immediately – the entire program execution will be traced.
  • Explicit switch on and off – the program execution starts with the trace switched off. When the program reaches a breakpoint, you can choose Switch ABAP Trace On/Off from the context menu for the breakpoint.

The ABAP Profiling Perspective

Profiling an ABAP Program is best done in the ABAP Profiling perspective. Watch the demo "How to Profile an ABAP Program and Analyze the Result" later in this lesson to learn how to do this.

In its standard configuration, the Profiling perspective consists of three parts:

Editor Area

The editor area is identical to the editor area in the ABAP perspective and the Debugger perspective. When you open a trace result, it will be displayed in this area on a new tab.

Trace Area

By default, this area consists of the following views:

The ABAP Traces view displays the trace results, organized by project and filtered by your user.

On the ABAP Trace Requests view, you can manage your requests and create new ones.

Details Area

By default, this area contains the Properties view. If in the Editor area the focus lies on a repository object, the properties view displays the metadata of this repository object.

When analyzing a trace result, the properties view is used to display the properties of a runtime measurement.

The Trace Overview

When you double-click on an entry in the ABAP Traces view, the ABAP trace result opens on a new tab in the editor area.

By default, the focus lies on the Overview tab. This is the starting point for further analysis. The trace overview consists of the following parts:

General Information

In the general Information section, you find administrative information about this trace result:

When was the trace created? who created it? With which aggregation settings? And, so on.

Runtime Distribution

The runtime distribution provides you with an information of how the traced runtime was distributed across the following ABAP components.

  • ABAP – the run time spent processing ABAP code, not including ABAP system programs.
  • Dababase – The run time spent in the database, performing database operations.
  • System – The run time spent processing ABAP code in system programs.

Analysis Tools

This section gives you a short description of the analysis tools integrated into the trace result display. Choose one of the links to navigate into the respective tool. Alternatively, you can navigate using the tabs below the Overview display.

ABAP Trace Analysis Tools

The Condensed Hit List

The Condensed Hit List allows you to find the most expensive procedural units, for example, methods.

This list displays runtime measurements for trace events. It is called condensed because it restricts itself to procedural units. Database accesses and other trace events are not listed here.

Hint
If you are interested in all trace events, refer to the Hit List instead.

The list displays the data in aggregated form. Each procedural unit appears only once, no matter how often it was called and in how many different places. Columns Executions and Callers display the overall number of executions and the number of distinguishable direct call positions for this unit.

Column Total Time displays the amount of runtime in microseconds from the start to the finish of the call. If the unit was called more than once, the column displays the sum of the individual calls. Total Time lets you see the total contribution of the procedure calls. In the example, the program spent a total of 15,485 µs executing method MAIN( ) and a total of 3,451 µs executing method GET_FLIGHTS( ) .

Column Own Time (Specified and Unspecified ABAP Statements) displays the amount of runtime in microseconds without the time spent waiting for other procedural units. Let's have a closer look at method MAIN( ) . Although the total time is 15,485 µs , the value in this column is only 18 µs. This means that the method did hardly any processing itself but spent most of the time waiting for methods it called.

Column Own Time displays the amount of runtime in microseconds without the time spent waiting - not only for called procedural units but also for ABAP statements specified in the trace parameters. In the example, method GT_FLIGHTS( ) does not call any other methods therefore the value in Own Time (Specified and Unspecified ABAP Statements) is the same as the total time. But the value in Own Time is only 4 µs because the method spent almost all its time waiting for a database access.

The Aggregated Call Tree

The Aggregated Call Tree allows you to analyze the sequence in which procedural units were called.

If a call of a procedural is repeated (for example, in a loop), then the call only appears once in the aggregated Call Tree. The number in column Executions displays the number of repetitions.

Hint
If you are interested in an unaggregated display, refer to the Call Sequence instead.

In the example, method GET_FLIGHTS( ) was called by method MAIN( ) but did not call any other procedural units. Method WRITE( ) was also called by method MAIN( ), and it called method EXEC_WRITE( ), which in turn called method GET_NAME( ) and so on.

How to Profile an ABAP Program and Analyze the Result

In this demonstration, you will see how to profile an ABAP application and analyze the results.

Prerequisites

  • You have an ABAP (Cloud) Project, a transport request, package ZS4D401_00.

  • Your package contains global class ZCL_S4D401_PROFILING_1, and the class is active.

  • You display the source code of global class ZCL_S4D401_PROFILING_1 (tab Global Class).

Timeline Tools

The Aggregated Timeline

The Call Timeline allows you to visualize the call sequence and time consumed in the form of a diagram.

The diagram consists of two parts: An overview of the whole trace at the bottom and an enlarged detail on top. A toolbar on the left allows you to zoom in or out and to move the focus.

The ruler above the details diagram indicates the time going from left to right. Each bar illustrates one trace event with its start end time. The wider a bar is the more time was consumed by that trace event.

Left-click a bar to display its details in the Details Section of the Profiling Perspective. This way, you can find out the trace event a certain bar represents.

The diagram uses colors to distinguish different types of trace events : grey in different shades for system programs, green in different shades for procedural units, orange for database access, and so on.

Hint
Open the context menu anywhere on the diagram to show or hide the color legend. In our example, we hid the legend to keep the graphic simple.

Let's have a look at an example:

First row

The long grey bar at the very top represents the runtime analysis.

Second Row

In the second row, we see that the runtime analysis performs two preparatory database accesses before it calls the MAIN( ) method of the application.

Third Row

In the third row, we see that the MAIN( ) method calls two methods, the GET_FLIGHTS( ) method and the WRITE( ) method.

Fourth Row

The fourth row reveals the structure of methods GET_FLIGHTS( ) and WRITE( ). We can see that GET_FLIGHTS( ) does not call any procedural units (no green below the bar representing this method), but performs a single database access (one orange bar). The WRITE( ) method on the other hand does nothing else but call a single other method. This method is represented by the green bar below the bar that represents the WRITE method.

Repeated Database Accesses in the Call Timeline

The graphical display in the Call timeline is a very good way to identify repeated database accesses.

Let's have a look at an example: The regular, comb-like pattern in the forth and fifth row hints at an iteration. The orange color makes it obvious that is not just ABAP coding but involves a repeated database access.

Database Accesses

The Database Accesses tool allows you to find the database objects that were accessed and to identify the top consumers among database accesses. It is also a good way to identify repeated selects from the same database table.

The Database Accesses tool only displays trace events related to the database. For repeated database accesses, the runtime is aggregated. You find the number of executions in column Executions.

In the example, two tables were accessed: /DMO/AIRPORT and /DMO/CONNECTION. The one SELECT statement reading data from /DMO/CONNECTION took 16,525 µs, which was 5 % of the overall runtime, and the 40 executions of a SELECT SINGLE statement reading from /DMO/AIRPORT consumed 59,894 µs, or 18 % of the overall runtime.

How to Detect Sequential Selects using ABAP Profiling

In this demonstration, you will see how to analyze a program containing repeated SELECT statements.

Prerequisites

  • You have an ABAP (Cloud) Project, a transport request, package ZS4D401_00.

  • Your package contains global class ZCL_S4D401_PROFILING_2 and the class is active.

  • You display the source code of global class ZCL_S4D401_PROFILING_2 (tab Global Class).

Save progress to your learning plan by logging in or creating an account