17 June 2013
Adobe Scout gives you a ton of beautiful data to look at, but interpreting it isn't always straightforward. This article describes the data Scout gathers behind the scenes and how it uses that data to create all the pretty pictures, so you can more easily understand what's going on.
When you start a profiling session, Flash Player (or Adobe AIR) opens a socket connection to Scout and begins sending data. Most of the data that is represented in Scout's main panels are the names and timing details of defined activities. (Besides activities there are also trace statements, Stage3D commands and textures, and some other things.) Scout parses the activity details and generates its charts and graphs.
Note: For simplicity, this article refers to data sent by Flash Player to Scout, but it also applies to data sent by Adobe AIR to Scout.
In Scout, an activity is a block of time associated with a specific functionality. Activities in Scout have the following features:
If you've looked at Scout's custom telemetry APIs, which I previously covered in Custom telemetry with Adobe Scout, activities are much like custom span metrics, with some small differences in how they're handled.
Suppose that Flash Player sends the activity data in Table 1 to Scout.
Note: To be absolutely precise, Flash Player doesn't send Scout start and end times for each activity, but rather end times and durations. The result is the same though.
Table 1. Example activity data sent to Scout
Scout will use this data to calculate self times and total times as shown in Table 2.
Table 2. Example data as you'll see it in Scout's interface
|Name||Self time||Total time|
As you can see, Scout infers that activity B is a child of activity A from the timing data. Incidentally, if you use the custom span metric API to define activities that don't nest (for example, B starts during A but ends afterwards), viewing the data in Scout will generate an error or the data will just not display. So, when defining your own nested metrics,be careful to end them in the reverse order that you started them.
With the previous explanation in mind, the data that shows up in Scout should now be a little easier to interpret. First, in the Activity Sequence panel, all the activities Scout knows about for a single frame are listed, with their nested relationships intact (see Figure 1).
You can even see each activity's start time, though this is turned off by default because it's usually not useful. (Right-click the column titles to change which ones are visible.)
Note: Scout normally filters out any activity with a total time of less than 0.5 ms. To toggle this behavior click the Hide Small Items button, shown at the far upper left in Figure 1.
The Top Activities panel, on the other hand, ignores the activities' start times and nesting relationships so that it can show aggregate data over multiple frames. In this panel multiple instances of the same activity are grouped (by activity name) rather than showing up multiple times as in the Activity Sequence panel, so Scout gives a count of how many times they occurred during the selected span (see Figure 2).
The data behind the two panels is identical; it's just marshalled and displayed differently. Understanding the data behind the panels helps make the implications more obvious. For example, when an ActionScript function calls
BitmapData.draw() or a similar API, the Flash Player renderer is invoked. Since that rendering starts after, and ends before, the ActionScript execution, Scout will consider it to be a child activity of the ActionScript activity. But you'll only see this if you check in the Activity Sequence panel, where nesting is preserved. If you check the Top Activities panel, all the rendering activities will be grouped together, whether they were triggered by ActionScript or were done by Flash Player automatically.
Lastly, it may not be immediately obvious but the times shown for each entry in the Summary panel are the self times of the related activity (see Figure 3). The Summary panel groups activities into predefined categories and displays the sum of the self times for each. (The easiest way to see which activity name belongs to which category is to look at the colors Scout uses.)
The data shown in the Scout ActionScript panel is a completely different animal from everything discussed so far. This is because profiling overhead would slow processing to a crawl if Flash Player sent an activity to Scout every time an ActionScript3 function was called. So instead, Flash Player samples the call stack every millisecond or so, and Scout guesses what's going on. For example, consider a scenario in which Flash Player sent the data represented in Table 3.
|1000 ms||FunctionA -> FunctionB|
|1001 ms||FunctionA -> FunctionB -> FunctionC|
|1002 ms||FunctionA -> FunctionB -> FunctionC|
|1003 ms||FunctionA -> FunctionB|
From this data Scout can estimate that FunctionC was executing for around 2 ms. But whether it executed once or dozens of times during that time isn't known—Scout only knows that it was on the top of the call stack for two consecutive samples. Furthermore, FunctionC may have called FunctionD between two of the samples (if FunctionD returned quickly). This is why the ActionScript panel gives somewhat approximate results, and why you should select a long time span if you want to get more accurate results. The more samples Scout looks at, the more accurate the results will be.
Now that you know more about the data that Scout uses, you may want to read Understanding Flash Player with Adobe Scout, which explains how Scout can help you understand what's going on inside Flash Player. Happy profiling!
Comments are currently closed as we migrate to a new commenting system. In the interim, please provide any feedback using our feedback form. Thank you for your patience.