Another potential reason for Fiori timeout error
- My analysis process
- Final answer
- Lessons learnt
Yesterday I spent almost the whole day to resolve a timeout issue in one CRM Fiori application “My Lead”. Finally the root cause makes me not know whether to launch or to cry. I share with you this story, in case you might meet with similar issue, you do not need to spend much time to debug as I did yesterday.
In CRM “My lead” application, end user can insert several products to a lead at the same time.
User can click “+” button to open product value help, then select the products they need to add to the lead.
The issue is, when the testing colleague uses the test user ( we say user A ) to insert the products to the lead, they will meet with time out error below, when the amount of selected products exceeds 15.
Much to my surprise, when I use my own user ( user B ) to test, the issue could not be reproduced, it only took 1 seconds to finish the insertion with 20 products selected. Why?!
My analysis process
1. I debugged the insertion with test user A. The product insertion to lead is done by CRM function module CRM_ORDER_MAINTAIN. The product insertion within this FM is done via a LOOP internally, which means each product is inserted separately. For totally 20 product insertions, I trace the execution time, it took around 40 seconds to finish, which is definitely not acceptable.
2. I use transaction code SAT to trace the single product insertion with test user A, it took around 2 seconds. It seems the execution time increases linearly with the number of product to be inserted. Also the 2 seconds for a single product insertion is not acceptable – too slow!!
3. Unfortunately, through the SAT record, I cannot find a bottleneck of the execution. The complete execution, each stack, is very slow. But when I debug with my own user, each stack is very very fast.
What are possible elements which causes the difference
1. I had made assumption that the two users are testing on different Lead transaction type. Different transaction type could have different callback registered, so when the lead is saved, different program could be executed. This element is eliminated after my check – both user are working on exactly the same transaction type.
2. The backend implementation has some code like
CALL FUNCTION 'XXXXX' EXPORTING iv_user_name = sy-uname
The reason I made this assumption is since the execution differs based on user, so there must be some handling in code which is based on user name.
I did spend much time to go through the code and the answer is no.
I felt frustrated and almost gave up. Suddenly I am thinking about the possibility of user setting difference??
Bingo! The testing user has switched on One order framework event trace via the user parameter CRM_EVENT_TRACE.
This trace functionality is expensive which leads to the overhead of the whole program execution. And since it is done centrally in the one order framework, it is the reason why I didn’t find any hint in my application code.
So here is lessons learnt:
Next time if I meet with the similar issue that the performance on the same application with different users varies greatly, besides the two mentioned checkpoints in chapter “What are possible elements which causes the difference“, there is last but not least one: check whether there are different users settings between the two users( for example tcode SU01, or any other customizing in your specific area ).