Performance logging is a general record tracing and logging mechanism that is built into the Storyboard engine. This functionality allows the capture of fine grained execution information about operations being performed within the engine. This can be enabled by enabling performance logging in the Storyboard Simulator Configurations under logger (.plog file).
Each performance record is made up of three pieces of identifying information along with the timestamp of when the record was generated and in certain cases the duration of the operation represented by the record. The three pieces of identifying information represent the payload of the performance records and provide context to the overall record stream:
-
A class identifies the classification of the record. An example of a class might be an event, an action or a control.
-
An operation identifies the record within the class in terms of context. For example events can be queued or they can be dispatched, both are examples of operations within the event class. Similarly the control class identifies the allocation, destruction and rendering operations that take place with controls.
-
The value or name of the record is the final piece of data. This field has context based on the class and operation of the record. The field may include information such as the name of the event in the case of an event dispatch or queue operation or the name of the resource being loaded for a resource load record.
The class, operation and value fields can be represented hierarchically as not all operations apply to all classes.
The new plotting functionality allows these records to be filtered, analyzed and visualized within the context of a Storyboard application execution timeline.
A number of predefined record plots are included that represent common analysis scenarios and a custom plotting mechanism gives you the ability to perform record filtering that is contextual to the problem you may be trying to investigate with your own application.
A number of predefined plots have already been defined that align with common filtering and analysis that are both common and useful. For example displaying the screen rendering time, resource load times or CPU usage information.
Not all of these plots may be applicable for the performance log that you are analyzing, for example CPU and memory metrics are only available if the trace information contains those records. On some engine platforms all metric information is not always available.
Each of the pre-configured plots contains a description of the metric that is being generated and plotted and further description of how you might use these plots is described below.
The custom metric plot dialog provides an advanced functionality to create custom filters and match criteria for various records in the event log. A number of statistical operations are available to be applied to the filtered records in order to generate plottable data.
A basic operation can involve counting the number of instances of a record, for example running animations, or determining the current, total or average time for a particular action such as Lua.
You can select a record match criteria that will cause records to be included in the statistical operation set as well as a reset criteria that will cause the statistical operation to reset and start over. A common reset operation would be to reset at every screen transition to gain insight on per-screen costs. Altogether this provides a very powerful mechanism that you can create visual plots of data for different contexts.
The performance log also contains records that describe the state of animations that are executed during the course of the log capture. More specifically the variables used in those animations and the values that are being changed over the course of the animations execution. A separate pre-configured animation plot dialog shows these variables and allows their values to be plotted on the application timeline against other plots.
Here are some quick analysis scenarios that you can take leverage with your performance logging plots.
Visual Accountability
How an application renders can be greatly influenced by a large number of external factors. On all systems it is possible for the rendering time to be measured and plotted. This is included as the Redraw pre-configured plot and is one of the default record plots that will be shown.
In general redraw time will correlate to the complexity and composition of the visual scene and the goal is for it to remain below certain thresholds such as 60fps (~16ms/redraw), 30fps (~33ms/redraw) or 15fps (~66ms/redraw).
If you observe spikes in the rendering time, it may be due to an external influence interrupting the operation of the rendering engine or it may be due to an internal application factor such as a new resource being loaded on demand or additional complexity of a scene by way of more content being rendered. Overlaying on top of the redraw plot you can use the pre-defined plot for resource load count to identify when resources are being loaded and if they correlate to a rendering delay or use the rendered control count pre-defined plot to determine if the number of rendered elements on the screen have increased. With this information you can take corrective action in your application such as pre-loading resources or merging control content together at design time rather than engine render time.
CPU Accountability
Another first thing you might want to do is to take a look at the CPU profile of your application where it is available. For this you need to ensure that you are logging with metrics enabled. The pre-defined CPU usage plot will indicate what your average CPU usage over the application and how that usage correlates to various screens of operation.
Similar to the redraw time, loading of resources can cause a spike in CPU usage, but so can the processing of different kinds of events and as such the action processing time for those events may be something you want to correlate. For this the pre-defined action duration plot will be helpful to allow you to understand what actions or what stream of events are correlated to your CPU bursts and take corrective action if required.
Memory Accountability
Similarly to CPU accountability, the memory usage information is captured when metrics are enabled (on some platforms). This memory profile offers insight to dynamic behaviour of an application and the goal with this plot is for an initial growth to be observed and then a relatively flat plot for repetitive parts of the user interface as the application enters a steady state.
Memory is typically used by resources such as fonts and images and these are loaded on-demand. If you see that your memory usage is continuously climbing then you might want to correlate that with some of the rendering activity. It could be that you are experiencing a dynamic resource leak. Dynamic resources include controls and groups that are cloned, tables that are resized and not virtualized as well as timers and animations that are created from Lua. You can use the pre-configured resource count plot to see whether or not these resources collectively are growing. If they are then further investigation may lead you to look at what kind of resources are being created and to ensure that they are being properly cleaned up within the application.
External Data Source Accountability
Storyboard is an event-driven system and as such interfaces with external applications using events. It may be that the frequency of events arriving from outside sources may be affecting the operation of the UI. This might manifest itself as longer render times as they're observed in the render time pre-configured plot. In order to visualize the number of events that are being generated of any particular type you can use the custom metric plot and specify the events that you are interested in and plot either count or duration as a cumulative value on a per screen or application basis.
The Chart also has the ability to enable or disable vertical line markers that allows users to visualize the event on each screen. As Storyboard is entirely event driven, it provides the essential ability for a user to be able to determine which screen has a cluster of event activity and how it relates to some of the other metrics discussed in the sections above.
The plot selector tool allows a user to select which plots are to be shown or hidden in the plot area. Adding plots from the animation, custom record, and predefined record plots will appear in this view. The plots that are currently in that view can also be deleted.
The Tool Bar
The left tool-bar consists of the tools discussed in the sections above (from left to right):
-
The Plot Selector Tool
-
The Preconfigured Analysis Plots Tool
-
The New Animation Plot Tool
-
The New Metric Plot Tool
-
The Event Lines Toggle Tool
The right tool-bar consists of the tools that take actions on the appearance of the charts (from left to right):
-
The Zoom-In Tool
-
The Zoom-Out Tool
-
The Reset-View Tool
The Right Click Menu Items
The user also has the ability to use some of the functions to “Zoom In”, “Zoom Out” and “Zoom to Selection” abilities from the menu items below.
“Jump to this Event in the Log” provides the user the ability to jump to the specified event in the Log tab. From here, a user has the ability to look at the grouped performance record involving that single event or group of events in the case that there were multiple events for that particular time instance.
“Export Selection to CSV File” provides an export functionality to extract the records between a selection range of the gathered trace. The user can select the selection range that they wish to investigate by clicking and dragging horizontally across the plot area to start the selection. This is shown in the image below. They can then right click and export the selection to their desired location.