The Purpose In the following SAP Community blog post which is published in the last month, we’d like to demonstrate the basic usage of the new tool “profile data analyzer” with two SM21 examples. With these examples, we can see that the profile data analyzer not only helps us to analyze the performance issue systematically and find out the most expensive parts of a program in a graphic and interactive way, but also helps us to understand the program logic, including getting an overall picture quickly and drilling down to the details easily. SAP Community blog post: Analyze ABAP Performance Traces with the Profile Data Analyzer Understanding the program logic is helpful not just for performance optimization but also benefiting other tasks, for example, ◉ Development task: We want to do some custom development or enhancement which is similar to a standard T-code, then it is helpful if we can understand the logic of the standard T-Code quickly. ◉ Troubleshooting task: Sometimes we need to troubleshoot an error for maintenance or support tasks. Understanding the program logic can help us to drill down to the root cause quickly. ◉ Maintenance task: Sometimes we need to customize or change a feature of an existing program, or explain the program behavior to end-users or other stakeholders. Understanding the program logic can also benefit these scenarios. So compared to the SM21 examples in the previous blog post, this post will use a more complex example to demonstrate how to understand the program logic with the profile data analyzer and benefit the above real-world tasks. In this post, we will use SU01 as an example to show the tips because it is complex enough like we are working with real business codes, and it is also common enough for all user roles (e.g. application developers, system administrators, and support engineers). Let’s suppose we know nothing about the SU01 program logic, and we use the profile data analyzer to find out the answers to the following questions: ◉ When we change some user information, how it is saved into the database? Which method is responsible for the change? SU01 also saves change log information for audit purposes, and how these changelogs are updated? ◉ We face “Authorization profile AAAA does not exist or is inactive” error in SU01. How to find out the root cause of this error? ◉ We face “The passwords specified must be identical” error in SU01. How to find out the root cause of this error? We’d also want to make sure that you already know the basic usage of the profile data analyzer(e.g. how to read and interact with below SU01 performance flame graph) which could be found in this blog post as mentioned previously before going through the following parts. (Tip: Please zoom this page in your browser to view the details of the flame graph. In my laptop, the ideal zoom level is 200% or higher in which the flame graph display can make use of the whole screen.) The Brief Introduction to SU01 Before starting the analysis, let’s have a quick look at SU01 to make sure everyone is clear about the answers we want to find and the problem we want to solve. First of all, here is the screenshot for the user changelog which can be accessed by “SU01 => menu ‘Information’ => Change Documents for Users” or report RSUSR100N directly. Here are the screenshots for the error message “Authorization profile AAAA does not exist or is inactive” and “The passwords specified must be identical” when we input some wrong data and click the save button in SU01. Understanding the SU01 Logic with Profile Data Analyzer Part 01: Understanding How the User Data is Updated and Saved First, let’s trace SU01 for the user information update scenario in SE30/SAT following KBA 2881237, and then generate the flame graph with the “Show technical details” option. Now let’s start the analysis, and the first thing is to find some places to start. If we know SAP Change Documents(BC-SRV-ASF-CHD), then perhaps we already know that “CDHDR|CDPOS” is a good regular expression to search in the graph. CDHDR and CDPOS are the tables for change documents, and we will find the following records(highlighted in purple) by searching “CDHDR|CDPOS”. It is not a problem if we do not know table CDHDR and CDPOS, because it is always a good idea to search “CHANGE|SAVE” in the graph as a try. Then we will find similar call stacks like the screenshot below. Zoom to these purple call stacks by clicking the related methods in the graph, then we can find that both “CDHDR|CDPOS” and “CHANGE|SAVE” will guide us to the same call stack in the following four screenshots. There are several interesting points in these four screenshots and the focus view to “LCL_IDENTITY_WRAPPER.DO_SAVE”. Now let’s have a look at them in detail one by one. Here are the conclusions we could get from the 1st screenshot of the above four screenshots. ( Tip: Here I would like to suggest to open 2 browser tabs. One tab stays here and another tab stays on the 1st screenshot. Let’s also zoom the browser to make sure that the screenshot is big enough to check.) ◉ “LCL_IDENTITY_WRAPPER.DO_SAVE” is the most important method to save the change into the database. ◉ The “PERFORM (ext) %_COMMIT()” is responsible for ABAP statement “commit work.”, and the “SAPMSSY4” is the report to execute update task(like SAPMSSY1 for RFC task, and we can check more detailed information about SAPMSSY4 in SE38). ◉ Function module “SUID_IDENTITY_SAVE_TO_DB” is an update function module, because it is called in “SAPMSSY4”. ◉ Based on the above information and the call stack, we could confirm that the “commit work.” is called at “LCL_IDENTITY_WRAPPER.DO_SAVE”. This could be confirmed by the following code. (note: the following code screenshot is from ABAP in Eclipse.) Here are the conclusions we can get in the 2nd screenshot. ◉ “_DB.Exec VBMOD” is called by “CL_IDENTITY_DB_PERSISTENCE.IF_SUID_PERSISTENCE_MODIFY~MODIFY”. ◉ “VBMOD” is the table to save update request(SM13) information. By the way, “VBDATA” is also the table for update requests, but because its runtime is short, the name of “VBDATA” is not shown completely in the view of the 2nd screenshot. ◉ Based on the above information, the update function module “SUID_IDENTITY_SAVE_TO_DB” should be called in “CL_IDENTITY_DB_PERSISTENCE.IF_SUID_PERSISTENCE_MODIFY~MODIFY”, and this be confirmed by the following source code. ◉ As the next step, we can also search the keyword “in update task” in “CL_IDENTITY_DB_PERSISTENCE.IF_SUID_PERSISTENCE_MODIFY~MODIFY”, then we will find other update function modules related to SU01. There are if statements, so different conditions may call different update function modules. Click and zoom to “CALL FUNCTION IDENTITY_WRITE_DOCUMENT()” which is called by function module “SUID_IDENTITY_SAVE_TO_DB”, then we will get the 3rd screenshot. Here are the conclusions we can get in the 3rd screenshot. ◉ The update function module “SUID_IDENTITY_SAVE_TO_DB” calls “IDENTITY_WRITE_DOCUMENT”. ◉ The function module “IDENTITY_WRITE_DOCUMENT” will call the following function modules to update the SU01 change log into “CDHDR” and “CDPOS”. ◉ CHANGEDOCUMENT_OPEN ◉ CHANGEDOCUMENT_MULTIPLE_CASE ◉ CHANGEDOCUMENT_CLOSE In the 4th screenshot(the last screenshot), we can see that the database table “USR02” is also updated by update function module “SUID_IDENTITY_SAVE_TO_DB” in this example, which is the main table for the user logon data and we can confirm this point in T-Code SE11. The above tips and steps are the information about how to find out the answer to the first question (save and update logic of SU01) by the profile data analyzer. The last remark in this part is about why we enable and use the “Show technical details” option during the analysis. Let’s have a look at the SU01 flame graph with the default filter as the following screenshot. In the filtered graph, we can see that the system records like “PERFORM (ext) %_COMMIT()” for “commit work.” statement is not shown, as a result, the “Program SAPMSSY4” is shown directly on top of “LCL_IDENTITY_WRAPPER.DO_SAVE”. This is why we enable the “Show technical details” option to make the logic clear and avoid misleading. Part 02: Understanding the Error “Authorization profile AAAA does not exist or is inactive” Now let’s move to part 02 and show how the profile data analyzer can help to analyze and find out the root cause for the error message “Authorization profile AAAA does not exist or is inactive”. This error can be reproduced by setting a not existing profile to an existing user. Again let’s take a trace for this scenario in SE30/SAT and check it with the profile data analyzer. This time we could use the default filter in profile data analyzer to understand the SU01 logic. Let’s suppose we are not familiar with SU01’s code (if we are familiar with the code, we can go to the code directly, and there is no need to take the trace). So now the first thing is also to find out some places to start. Because the error is related with “PROFILE”, let’s try to search “PROF” in the flame graph at the very beginning. Luckily, we can find some methods by the “PROF” keyword. There are mainly 2 big parts as shown in the following screenshot. Now let’s drill down into these two parts (the right part and the left part) one by one to check the details. Here is the focus view of the right part. Because of the “PBO” and “ALV” entries shown in the following screenshot, it looks like these call stacks are responsible for displaying the error message as a result but not the place where the error message is generated. So the error message should already be generated in some other places, and we decided to skip this part and have a look at the left part. Here is the screenshot of the focus view to the left part. We can find out the following information in this view, so this time we are lucky, and here is just the place where the error message is triggered. ◉ The method “SET_PROFILES” is called to try to update the profile. ◉ And finally, the method “CHECK_EXISTENCE_PROFILE” is called to check the profile, and the related authorization profile table is “USR10”. ◉ In “CHECK_PROFILES_INTERNAL”, if an error or problem is found, “ADD_OBJECT_MESSAGE_SYMSG” is called to add an error message. Now we already know the place where the error message is generated. For the next step, we can go to the debugger and confirm the above conclusions like the following screenshots. Part 03: Understanding the Error “The passwords specified must be identical” Similar to part 02, let’s reproduce the error “The passwords specified must be identical” and take a trace. This error can be reproduced by setting the new password with two different values. Then let’s follow the same method as the troubleshooting steps for error “Authorization profile AAAA does not exist or is inactive”, and firstly try to search “PASS” in the flame graph for the password. Here is the screenshot for the searching result. I highlighted the call stacks for “PASS” because I know where they are, but as we can see, the searching result is not so visible like “PROFILE”. The reason why these call stacks for the “PASS” keyword are not so visible like the “PROFILE” is that. ◉ When SU01 verifies a profile, at least SU01 needs to access the database table to check whether the profile is valid or not. So usually the runtime is long, and it is visible in the flame graph. ◉ When SU01 verifies whether the new password and the repeated password are the same, SU01 only needs to do a simple string comparison. So usually the runtime is short, and it is not so visible in the flame graph. (Although some other actions are also executed, e.g. update and add the error message.) In such situations, we can always export the ABAP trace to *.prf file and check the details in SAP JVM Profiler following KBA 2891307. Here is the screenshot by searching “PASS” in “Performance Hotspot Trace => Method(Flat)” in SAP JVM Profiler. Again we find out the interesting method “LCL_IDENTITY_WRAPPER.SET_PASSWORD()”. Based on its name, SU01 must try to set the password in this method but fail with the error message. Here is the view in SAP JVM Profiler about the methods called by “SET_PASSWORD”, and the method(call stack) who calls “SET_PASSWORD”. By the way, here the *.prf file is exported with default filter. If the trace is exported with the “Show technical details” option, more detailed information will be shown in SAP JVM Profiler (e.g. the hidden system calls). At last, let’s set a breakpoint in “LCL_IDENTITY_WRAPPER.SET_PASSWORD()” to confirm the conclusion we get from the profile data analyzer like what we do in part 02. In the following screenshots, we can confirm that “LCL_IDENTITY_WRAPPER.SET_PASSWORD()” is just the place where the error “The passwords specified must be identical” is triggered and the root cause is that the new password and the repeated password are not the same with each other. Part 04: Other Information We Can Get about SU01’s Implementation Logic by Profile Data Analyzer Based on the information in part 01, part 02, part 03, and the source codes we checked, we can find out the following implementation logic when SU01 wants to change or save something. ◉ The class “LCL_IDENTITY_WRAPPER” is the wrapper to “CL_IDENTITY”, which is the main part who is responsible for the change. ◉ Both “LCL_IDENTITY_WRAPPER” and “CL_IDENTITY” have many SET methods to update different kinds of user information. ◉ Both “LCL_IDENTITY_WRAPPER” and “CL_IDENTITY” also have DO_SAVE method, DO_CHECK method, and many GET Methods. ◉ If the input data is not correct, the SET methods will trigger the error messages. ◉ The method “LCL_IDENTITY_WRAPPER.DO_SAVE” is responsible for the user information update. The “commit work.” statement is called in this method, and it will also delegate its work to “CL_IDENTITY.DO_SAVE” who will finally call the update function modules. Here is the screenshot for the SET methods in “LCL_IDENTITY_WRAPPER”. Here is the screenshot for other methods(e.g. DO_SAVE method, DO_CHECK method, and GET Methods) in “LCL_IDENTITY_WRAPPER”