One of the first things I noticed when I began investigating the performance of remoted lists is that the delay between the time the load starts and time the data becomes accessible can be broken in to two parts. The first is the time between the remote method call and the result handler of that call. During this time the mouse icon is a spinning clock, but the application is still responsive. Within the result handler all the data from the list seems to be available. The second part of the load happens after the result handler. During this time, the application becomes unresponsive. It is only after this time that any visual changes to the application caused by the new data will appear (though the delay exists even if there is no change to the display). It is this time that exhibits the strange behavior. Since I can't explain what the application is doing during this time, I've dubbed it the mystery time.

My test case involves a simple remote object called TestRemote:

package test;

import java.io.*;
import java.util.*;

public class TestRemote implements Serializable
{
   public List getObjects( int number, int mapSize, int references )
   {
      List data = new ArrayList();
      Random rnd = new Random();
  
      TestParent parent = new TestParent( Integer.toString(rnd.nextInt()), rnd.nextInt(), "Test Object " + rnd.nextInt(), testMap(mapSize, rnd) );
      TestParent parent2 = new TestParent( Integer.toString(rnd.nextInt()), rnd.nextInt(), "Test Object " + rnd.nextInt(), testMap(mapSize, rnd) );
      for ( int i=0; i < number; i++ )
        data.add( new TestRemotingObject( Integer.toString(rnd.nextInt()), rnd.nextInt(),
                  "Test Object " + rnd.nextInt(), testMap(mapSize, rnd), 
  				( references > 0 ? parent : null ), (references > 1 ? parent2 : null ) ) );
      return data;
    }
 
   private Map testMap(int mapSize, Random rnd)
   {
      Map testData = new HashMap();
      for ( int j=0; j < mapSize; j++ )
        testData.put( "key" + rnd.nextInt(), "value" + rnd.nextInt() );
      return testData;
    }
 
   public static class TestRemotingObject extends TestParent
   {
      public TestParent parent = null; public TestParent parent2 = null;
      public TestRemotingObject( String id, int number, String name, Map testData, TestParent parent, TestParent parent2 )
      {
         super( id, number, name, testData );
         this.parent = parent;
         this.parent2 = parent2;
       }
    }
 
   public static class TestParent
   {
      public String id; public int number; public String name; public Map testData;
      public TestParent( String id, int number, String name, Map testData )
      {
         this.id = id;
         this.number = number;
         this.name = name;
         this.testData = testData;
       }
    }
}

<mx:Application xmlns:mx="http://www.macromedia.com/2003/mxml" xmlns:tops="*" pageTitle="Test Peformance" backgroundColor="white">
  <mx:Script><![CDATA[
    import mx.core.*;
    import mx.utils.*;

    var MAX_ITEM_COUNT = 1000;
    var ITEM_COUNT_INCREMENT = 20;
    var MAP_SIZE = 10;
	var REFERENCES = 0;

    var timesData : Array = [];
    var loadStart : Date;
    var loadMiddle : Date;
    var itemCount : Number = 0;

    public function loadData()
    {
       if ( loadStart != null )
       {
          var timeNow = new Date();
          timesData.push( { items:itemCount, loadTime:(loadMiddle.getTime() - loadStart.getTime()), mysteryTime:(timeNow.getTime()-loadMiddle.getTime()), cumulativeTime:(timeNow.getTime()-loadStart.getTime()) } );
          timesChart.executeBindings();
        }
 
       itemCount += ITEM_COUNT_INCREMENT;
       if ( itemCount > MAX_ITEM_COUNT ) return;
 
       loadStart = new Date();
       var contentCall = remoteService.getObjects( itemCount, MAP_SIZE, REFERENCES );
       contentCall.resultHandler = Delegate.create(this,function( result )
       {
          trace(result[itemCount - 1].name);
          loadMiddle = new Date();
          doLater(this, "loadData");
        });
     }
  ]]></mx:Script>
  <mx:RemoteObject id="remoteService" named="TestRemote" showBusyCursor="true" concurrency="multiple" result="event.call.resultHandler( event.result );"/>
  <mx:Button label="load" click="loadData();"/>
  <mx:LineChart id="timesChart" marginLeft="5" height="100%" width="100%"
      marginRight="5" dataProvider="{timesData}" showDataTips="true">
      <mx:horizontalAxis><mx:CategoryAxis dataProvider="{timesData}" categoryField="items"/></mx:horizontalAxis>
      <mx:series>
          <mx:Array>
            <mx:LineSeries yField="loadTime" form="curve" name="Load Time"/>
            <mx:LineSeries yField="mysteryTime" form="curve" name="Mystery Time"/>
            <mx:LineSeries yField="cumulativeTime" form="curve" name="Cumulative Time"/>
          </mx:Array>
      </mx:series>
  </mx:LineChart>
  <mx:Legend dataProvider="timesChart" direction="horizontal"/>
</mx:Application>

The loadData() function of this MXML file is a little strange. The mystery time only occurs after the remote call's result handler has completed execution, so we need to time between the end of the method and then next time we can execute code. It turns out that Flash's doLater() method makes this easy. It executes the given method during the next frame of the flash movie, and the mystery time must complete before the next frame is drawn/executed. So the loadData() function records the time since the last call started, increments the item count (and stops if its reached the limit), calls the remote method, and assingns a result handler that will restart the loop by calling loadData() in a doLater() function.

Armed with this code, we can begin analysing the mystery time. I ran many tests with different item counts, map sizes, and object references, but this graph seems to say most everything that I can say with any confidence about the problem. The load time is the time between the remote call and the result handler. It increases linearly with list size as we'd expect (bigger list size = bigger download = increased time). Remember that the result of the remote call is fully available at the end of the load time, so this curve represents the request to the server, the server call itself, the serialization to a remoting response, the streaming of that response, and (it appears) the deserialization of that response into Actionscript objects.

The mystery time is the time between the call to the result handler and the display refresh (measured as the time between the result handler and the next frame). It's a little difficult to see, but there's a slight increase in slope at around 15 to 30 items. You can also see that after around 60 items, the mystery time provides the majority of the delay between the the remote request and the response to the user.

In this graph, the mystery time has a spike at around 188 items. That's common, the peaks sometimes appear in the load time as well. It could be many things, including garbage collection in the flash player, garbage collection in the app server (since I'm running it on the same machine), or an entirely separate process. At any rate, I'm ignoring the spikes.

The most interesting curve is the time per 100 items. If the cumumlative time were linear, this curve would be a horizontal line. As you can see, it starts high and quickly decreases to a minimum. This accounts for the overhead involved in making many many small requests as opposed to a single larger one. The minimum of this curve it the ideal (or at least fastest) paging size. Unfortunately, it isn't consistent across tests, even with the same parameters. It ranges from about 20 to 60, but is usually on the low side. Between 50 and 100 items, the curve rises quickly, meaning the performance for the high side of 100 items is much worse than on the low side. It's not so easy to see in this graph, but the curve continues to rise gradually after 100, but slope seems to diminish as the item count continues to rise.

A curiosity of the mystery time, is that it seems to be nearly invariant over the size of the objects in the list. In this test, the item count was kept constant at 100 as the size of the map in each object was incremented. The load time increases linearly as we'd expect, but the mystery time increases only slightly between 0 and 25 map entries, and then remains constant. I've observed this for different types of objects as well.

While the mystery time does not depend on the size of the objects, it does seem to depend on the structure of the object graph. Specifically, references to parent objects (i.e. each object in the list referencing a single instance of a container object) seems to increase the mystery time well out of proportion to the actual number of items (N+1) when the item count is high (>> 100). Since we've already established that the page size needs to be < 100, I'm not going to elaborate on this oddity.

The conclusions are: 1) the mystery time takes a significant if not dominant proportion of the total request time, 2) The mystery time increases non-linearly with respect to list size and remains constant with respect to object instance size, and 3) optimum paging size seems to be between 20 and 50. I'm at a loss to explain what the mystery time is. It's doesn't seem to be deserialization because the content is available before the mystery time starts. It may be garbage collection, but it seems far to predictable for any garbage collection scheme I know of. At any rate, I'd love to hear some theories about what's going on here.