Interpreting Strobe performance profile for a CA Gen application
This section describes how to read the Strobe Performance Profile as it relates to CA Gen applications. For a complete description of the Strobe Performance Profile, refer to the Using-the-Strobe-Application-Performance-Measurement-System. For a description of analyzing a Performance Profile using iStrobe, see Interpreting-iStrobe-performance-profile-for-a-CA-Gen-application.
This section describes the following steps for interpreting the information in the Performance Profile:
- Verifying the measurement session information
- Choosing between the execution and wait reports
- Finding significant activity in a CA Gen application
- Identifying performance improvement opportunities.
About the Application
The examples in this section refer to the Performance Profile produced after the measurement of a COBOL application generated using CA Gen and running under a TSO session accessing a Db2 database. The application stores and tracks information about potential customers and is intended for use by the Sales and Marketing division of a small software company. The application is currently in the test phase of development. In the course of testing the application, the developers measured it to identify any opportunities for performance improvement.
Verifying the Measurement Session Information
The starting point for analyzing any Performance Profile is the first report in the Performance Profile, the Measurement Session Data report (Measurement Session Data Report). This report describes the environment during a measurement session and provides some overall measurement statistics.
A number of fields on this report can help you to determine that the Performance Profile is valid, and also to determine which reports in the Performance Profile to analyze.
To verify that the Performance Profile is valid, look at the following fields:
- In the JOB ENVIRONMENT column, ensure that the PROGRAM MEASURED, DATE OF SESSION, and TIME OF SESSION are what you expect.
- In the MEASUREMENT PARAMETERS column, ensure that the appropriate version of CA Gen appears in the SUBSYSTEM field.
The format of the SUBSYSTEM field varies, depending on the number of different CA Gen releases running in the measured address space. The SUBSYSTEM field identifies the release level of CA Gen that was used to generate the application running in the measured address space. The formats are as follows:
Value in SUBSYSTEM field (followed by release number)
Release of CA Gen
COOLGEN
COOL:Gen
ADVNTG_GEN
Advantage Gen
ALLFUSIONGEN
AllFusion Gen (CA Gen)
In Measurement Session Data Report, the SUBSYSTEM field shows that one release of CA Gen is running in the measured address space. The report additionally indicates that the Db2 Feature was invoked in conjunction with Strobe for CA Gen by also showing the name and release level of Db2 in the SUBSYSTEM field.
- In the MEASUREMENT STATISTICS column, examine the RUN MARGIN OF ERROR PCT and the CPU MARGIN OF ERROR PCT fields. A run-time margin of error of less than 2% usually reflects a reliable measurement. If you find that the Performance Profile you are creating has margin of error rates higher than 2%, increase the target sample size and measure the application again. A high CPU margin of error does not mean that the Performance Profile is invalid. Rather, it indicates to focus your analysis on the reports that detail run time.
Having verified that the Performance Profile is valid, your next step is to determine which reports in the Performance Profile to analyze.
Measurement Session Data Report
Choosing Between Execution and Wait Reports
You typically do not need to examine all of the reports in the Performance Profile. To determine whether to examine the CPU execution or wait reports in the Performance Profile, look under the MEASUREMENT STATISTICS column at the values reported for the EXEC TIME PERCENT (the percentage of time that one or more CPUs were active) and WAIT TIME PERCENT fields.
In this example, examine the execution reports to determine opportunities for improvement in execution time. Execution time is the run time during which the central processing subsystem (consisting of one or more CPUs) was in use by application tasks executing within the measured job step.
In Measurement Session Data Report, the EXEC TIME PERCENT value of a little over 56% suggests that performance might be improved by reducing CPU usage. The WAIT TIME PERCENT value of almost 44% indicates that trying to curtail wait time might also improve performance.
If the value for WAIT TIME PERCENT is very high, then examine the following wait reports to determine where the application is waiting:
- Resource Distribution Demand
- Wait Time by Module
- I/O Facility Utilization Summary
- Data Set Characteristics
- Action Diagram Wait Summary
- Wait Time by IEF Statement
- Attribution of CPU Wait Time.
Having verified that the Performance Profile is valid, and having determined to examine the execution reports for performance improvement opportunities, next look at the CPU summary reports to find out what modules are consuming the most CPU or run time. This approach would be the same if you were examining the wait reports. Essentially, start with the summary reports, isolate specific modules to examine, and then refer to the detail reports for those modules.
In this example, notice that the most CPU activity appears in action diagrams. Therefore, focus on the reports specific to action diagrams and the statements within the action diagrams.
Finding Significant Activity in a CA Gen Application
The first step in finding significant activity in a CA Gen application is to examine the summary report for the action diagrams.
The Action Diagram CPU Summary and the CPU Usage by Action Diagram Statement reports show which action diagrams and, within an action diagram, which CA Gen statements are responsible for CPU activity. Turn to these reports when most of the CPU activity occurs in action diagrams.
Examine is the Action Diagram CPU Summary report (See the following figure) first.
Action Diagram CPU Summary Report
Action Diagram CPU Summary Report shows the action diagram names for this load module and, at the far right of each action diagram name, the percent of CPU consumed. Because action diagram TIMEFUNC consumed the largest amount of CPU, focus your attention there.
To view a list of the CA Gen statements that consumed the most CPU for this action diagram, turn to the CPU Usage by Action Diagram Statement report (CPU Usage by Action Statement Report) for action diagram TIMEFUNC. This report breaks out the CPU use for the action diagram by CA Gen statement number. The statement numbers appear to the far left of the report.
This report always shows the CA Gen statement numbers and the percentage of CPU use associated with each statement. The report can also show other information, such as SQL statement numbers and COBOL statement numbers and text, depending on how you created the Performance Profile.
In addition to the subparameters described in Controlling the Level of Detail in the Reports, you can also suppress the display of SQL statement numbers associated with CA Gen statements. Specifying NOSQL on the IEF reporting parameter results in a more concise report. (The default is to display the SQL statement numbers.).
For this report, identify “spikes” of activity or control sections generating the highest CPU activity. These spikes are the areas of the action to focus on for possible performance improvement opportunities. As shown in the following figure, statements 10 and 17 within action diagram TIMEFUNC are both relatively heavy users of CPU time.
CPU Usage by Action Statement Report
At this point, you can examine statement text for a particular CA Gen statement, or you can look at the SQL text associated with a particular statement if SQL statement numbers are displayed and that seems to be where the activity is centered.
If you were to examine the SQL statement text, you would refer to the CPU Use by SQL Statement report for the DBRM referenced at the top of the CPU Usage by Action Diagram Statement report. For more information, see Additional Reports to Examine.
Identifying Performance Improvement Opportunities
The CPU Usage by Action Diagram Statement report shown in CPU Usage by Action Statement Report indicates that most of the CPU activity seems to be located at statement numbers 10 and 17. The text for the statements consuming the most CPU time is shown near the top of the report. For this example, examine the activity for statement 10.
To identify potential opportunities for performance improvement, look at not only the statement text, but also the actual action diagram code. Because you are examining the activity for the IEF statements around statement 10, look at the text for both statements 10 and 11 and then examine the action diagram code around these statements.
As shown in the following figure, the text for statement 10 indicates that one or more customer records are being read. Looking at the text for statement 11, notice a SET assignment action, indicating that the action diagram is assigning a value to some attribute view. SET assignment actions either establish an initial value for a view or change an existing value.
Action Diagram Code
Looking at the code (Action Diagram Code) around statement 10, notice that statement 7 is the beginning of a loop. This WHILE statement reads one or more customer records and eventually calls a CA Gen-supplied time function, (CURRENT_TIMESTAMP) shown in statement 11, storing the result in the time_value field.
By turning to the Attribution of CPU Execution Time Report (See the following figure), and scanning through the reports, verify that the current time routine being called is in fact consuming a significant amount of CPU time.
Attribution of CPU Execution Time Report
This action diagram populates a current time field on one of the data entry panels of the application. Each time a new customer record is created or updated, this current time routine is invoked, consuming additional CPU time. This repetition could become a performance problem when the use of this routine is high.
Examining the Attribution of CPU Execution Time Report shows that the current time routine TIRDAT2 is consuming almost 14% of the total CPU time for the application. This represents a possible performance improvement opportunity: remove the call to the time function from the loop.
The following figure shows a possible solution to this problem. You have moved the call to the current time routine outside of the WHILE loop. As shown in the example, the call is now made once (in statement 4) and the result is saved in the CA Gen-supplied local work view time_value, eliminating subsequent calls to the time routine.
Revised Action Diagram
After completing the changes to the action diagram, and reinstalling the application on the host, measure the application again to see how effective the changes were. Execute the application again, performing the same tasks as in the earlier example.
Measurement Session Data Report (After)
Comparing the Measurement Session Data reports for both measurements (Measurement Session Data Report and Measurement Session Data Report (After)), you see a significant reduction in CPU time as well as an overall decrease in elapsed time.
By examining and comparing the CPU TIME fields, we see a total decrease in CPU time of about 39 seconds.
Additional Reports to Examine
Our example in the previous sections focused on the reports associated with IEF statements within an action diagram. However, you may also find that performance improvement opportunities exist in the way that your application accesses and uses system service routines, and in the way that it accesses Db2 data. Strobe provides additional reports that display this type of information. This section describes these reports.
In addition to examining the reports that are specific to action diagrams and statements, you may also want to see the SQL statement text generated on behalf of a particular IEF statement. If there are SQL statements associated with an action diagram statement, the SQL statement numbers appear on the CPU Usage by Action Diagram Statement report, as shown in the following figure.
As you can see in this report, SQL statement number 1078 is the highest consumer of CPU time.
CPU Usage by Action Diagram Statement Report (With SQL Statement Numbers)
To view the SQL statement text, and the CPU activity associated with the statement, locate the DBRM name noted at the top of the CPU Usage by Action Diagram Statement report. The DBRM name in our example is DATEFUNC, as shown in CPU Usage by Action Diagram Statement Report (With SQL Statement Numbers). Then, refer to the CPU Use by SQL Statement report (See the following figure) for the DBRM.
CPU Usage by SQL Statement Report
Examining these additional reports can reveal performance improvement opportunities other than the ones uncovered by examining the action diagram statement text. Because the SQL statement numbers and the CPU activity associated with them are identified on the CPU Usage by Action Diagram Statement report, it is relatively easy to identify which SQL statements within an action diagram are consuming the most resources. You are then able to focus your attention on a few SQL statements, possibly out of hundreds for a very large application.
For example, you may have identified a number of SQL statements on the CPU Usage by IEF Statement report that are consuming a relatively large amount of CPU time. By examining the text for these statements, you discover that they are all SELECT statements that have WHERE clauses requiring data from multiple tables, resulting in a JOIN operation. This operation can be expensive in terms of CPU time. Further investigation of the action diagram code reveals that several of these JOIN operations are unnecessary.
With this information, you could then explore other coding alternatives that may offer a performance improvement. In this case, it may be possible to revise the views defined in the action diagram, eliminating the unnecessary JOINs.
For more information on interpreting the SQL statement reports, see the Strobe-for-Db2 section of this space.