Understanding Profiling and Statistics in Design Studio

After some discussions with internal colleagues and customers, I see that many of you are facing some performance questions of your applications. I try to collect the information which you can find in the statistics file with possible actions you can take to improve the performance by changes in scripting.

Basics

If you already know HOW to execute pfofiling in design studio, you can continue with this blog.

If you do not know, see Design Studio Tips and Tricks: Measuring Performance (Martin) or Measuring the Performance of Design Studio Application with an Example (Muralikrishnan).

Execution.

Whatever you want to measure, make yourself always a package containing:

• the downloaded bi_statistics.txt file
• the downloaded bi_statistics.csv file
• the application *.biapp file

This will help you analyzing the content and scripts and see the effects on runtime.

Starting Investigations.

We start with the “bi_statistics.txt” file. Just open it.

Big Blocks – First Request

In the file, you can see following big blocks:

• (1) XX ms: Process page command SET_TEMPLATE (12608)
• (2) XX/YY ms: Process commands before rendering <APP-NAME> (12604)
• (3) XX ms: Process rendering <APP-NAME> (12602)

This is the main structure. What is the meaning of those blocks?

(1) Process page command SET_TEMPLATE

This is the part of setting up all objects required for the application. The performance of this part is influenced by

• Number of Components used in the Application (low influence)
• Number of Data Sources used in the Application (high influence)

What can you do?

• try to reduce number of components and data sources

(2) Process commands before rendering <APP-NAME>

This part is the complete execution of onStartup script. The performance here is dependent on the content / script which is coded in onStartup event.

What you can do?

• Reduce the content in onStartup event
• Reduce duplicates (same code)
• Use variables in scripts to keep some values
  

  eg.

  bad (DS_1 is asked twice for the same information!):

  DS_2.setFilterExt(DS_1.getFilterExt());

  DS_3.setFilterExt(DS_1.getFilterExt());

  better:

  var filter = DS_1.getFilterExt();
  

  DS_2.setFilterExt(filter);

  DS_2.setFilterExt(filter);

• Try to prepare some components for the first visualization to avoid setters in onStartup
• move some to onBackgroundProcessing
• Big impact has variable processing, avoid following scripts:
  • setVariableValue()
  • setVariableValueExt()

(3) Process rendering <APP-NAME>

This part is the rendering of your application. You will see here time required by all components and also all data requests. This part should be already quite good optimized, the result sets are only requested if really someone needs it.

What you can do (not much)?

• Reduce number of components
• Reduce number of data sources
• Parallel Data Source processing will help here, especially in combination with data binding (as those are paralleled)

Big Blocks – More Request(s)

Do you see already in the first execution more than one request?

If yes, it means you are using onBackgroundProcessing event. In this case, check what is happening there – perhaps something is not necessary already in the startup phase, but first when the used goes to the visualization?

What you can do?

• Reduce the script in on background processing
• Reduce the number of requests / steps in the background
• Do not make again any changes in variables
• In case you are instantiating data sources, perhaps variable unbind is better?
  

Some Search Hints

Now, some help for the “analysis-by-search” of the statistic.txt file. Just search for the given content and see if it is applying for you. If you need a count of the events, you can also use the CSV file and filter by the column (text contains..).

Process page command CREATE_DATA_PROVIDER (12608)

This is creation of the Data Source object, once per Data Source.

Process page command CREATE_ITEM (12608)

This is creation of the Components, once per Component.

Important to Know!

In normal cases, you should see here 0ms as time spend on this step.

If you see 1ms, then your server could be slow (as I have already seen servers with 0ms in this step).

I am quite convinced, that you have a good potential of better performance when you see 1ms on this event.

BUT.. there are 3 important conditions to know:

* this event is thrown for every component you have in your application. And if SOME of those evens are listed with 1ms it does not need yet that you have a slow server. For example, you have 300 components, and 10 of those are with 1ms, the server should be ok.

* there is a rounding implemented in these statistics, as those are designed as “first way of checking” – it is not a real profiling tool, also the activated statistics are bringing overhead. For example, your server is processing the event in time between 0.9 and 1.1 ms, then sometimes it can popup in the statistics, sometimes not.

* in default setting, events with 0ms are omitted in display and download, you have to activate them to check how many events are thrown and then you can see if those listed with 1ms are making 1% or 90%.

This is pure processing of the component creation, there is actually nothing what can influence the time. if the server has better CPU, this time is 0ms.

Question: actually, there should be one “CREATE_ITEM” per component, why I see more items in an application with only one BUTTON?

Answer: Design Studio has to instantiate also some technical items, those are inserted automatically into runtime. If you download the statistics, you can see something like this… (example from the app with only one button.

Rules:

* Items starting with __ are technical (you cannot create such in the designer)

* the entry “Initialize item” is giving you the name of the item (you need to download the text file with option “Download All” (will be available again in SP1 of 1.5, currently it has been removed to reduce the content)

* The number of those technical items is constant.

// some technical items

              1 ms: Process page command CREATE_ITEM (12608)

                1 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __HTMLITEM (14100)

                  0 ms: Do init HtmlAttributes

              1 ms: Process page command CREATE_ITEM (12608)

                1 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __JAVASCRIPTHEADER (14100)

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __BODYITEM (14100)

                  0 ms: Do init BodyAttributes

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __JAVASCRIPTBODY (14100)

              1 ms: Process page command CREATE_ITEM (12608)

                1 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __BUTTON__0 (14100)

// holder for the global script variables and other propoerties on application level

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item TEMPLATE_PARAMETERS (14100)

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item APPLICATION_PROPERTIES (14100)

// root container (implicit)

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item ROOT (14100)

                  0 ms: Do init UiItem

// your content

             1 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item BUTTON_1 (14100)

                  0 ms: Do init UiItem

// items from the non-layout area

              1 ms: Process page command CREATE_ITEM (12608)

                1 ms: Create service PAGE_OBJECT

                0 ms: Initialize item CONTEXT_MENU (14100)

                  0 ms: Do init UiItem

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item MESSAGE (14100)

                  0 ms: Do init UiItem

              1 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item ZEN_PROFILING (14100)

                  0 ms: Do init UiItem

              0 ms: Process page command CREATE_ITEM (12608)

                0 ms: Create service PAGE_OBJECT

                0 ms: Initialize item __BUTTON__1 (14100)

Get connection

This is the time required for opening the BW / HANA / Universe connection. If you see here many seconds, something is wrong with your network. In general, you should see some time spend on it for the first occurrence for the same system, then it should be 0ms.

RFC BICS_PROV_OPEN (10000)

Every data source needs to be opened (example for BW). The time required for this is dependent on the query definition, only what you can do is to change the query.

RFC BICS_PROV_VAR_GET_VARIABLES

This is requesting the variables, in most cases should not take too much.

RFC BICS_PROV_SUBMIT_VARIABLES

Submit of the variables. This one is interesting one, check how many you see – ideally only one. If you see some “complex structures”, I mean submit, then something else and again sumbit in one navigation step, this is in many cases indication of “bad scripting”. it can be caused by crazy sequences in script – setting vatiables, then asking for something (like getData) and again setting variables. The getData ask is submitting variables implicitly.

RFC BICS_PROV_GET_MEMBERS

Those calls are “heavy”, members requested from BW system can take a while. Perhaps you do not need them in startup, perhaps better make it in onBackgroundProcessing? This is caused by the script call “getMembers()”. You can also try to bind such calls in one method, using the variable to avoid multiple calls (as not all can and are cached by the BICS data layer)

Render Ui Item

For those small calls, you should not see any long time spend. The majority should be 0ms, some can be higher. If one is extra high, there is something suspicious.

Process page command SET_ITEM_PARAMETERS

Keep in mind, every .set<Something>() method for component needs to change the component state. It means, you should avoid to call setters in mass-style. as example, when you want to hide 10 components, bind them in one panel (a panel is cheap) and then change the visibility of the panel, not of every single component. you reduce the server internal processing of this action by 10.

Get result set

I think this is the final event for this blog, here you can only improve backend to make it quicker. It is the request of resultset of the query. the smaller (better filters) the better for performance.

More Events…

When I get more examples, I will try to add more content here.

Other Links:

Design Studio Performance Best-Practices (Martin)

Design Studio 1.5 – The Performance Release (Martin)