What is your resultFormat? If it isn’t e4x, the data has to be converted to the resultFormat, which can be quite expensive.
Yes, it's e4x. What do you expect as a maximum time for ten lines of XML returned?
What does the performance profiler say is going on during that time?
That's why I'm confused - the performance profiler doesn't say anything - [enterFrameEvent] has the longest Cumulative Time of 336ms. Everything looks normal to me. I'm wondering if the portion of the asynchronous event that is having a problem is outside the view of the profiler, or maybe I'm doing something wrong.
First, make sure you’ve checked the memory profiling box as well (counterintuitive isn’t it?) and turned off all filters in the profiling UI.
You might use a network monitor to see when the request goes out and response comes back and log some current times in SWF so you can build up a timeline of what is happening.
That does give more data, although it's not clear to me what I'm seeing:
(my result received) 383ms
DirectHTTP MessageResponder.completeHandler 393ms (method stats show nothing)
AsyncRequest.acknowledge 392ms (method calls DirectHTTPMessageResponder)
Responder.result 390ms (method shows nothing)
HTTPOperation 384ms (method shows nothing)
there are about 1600 dispatch events that fire when the app starts up. The method is EventDispatcher.dispatchEventFunction, 422ms.
The Callees are
DirectHTTP MessageResponder.completeHandler 393ms
I assume these cumulative numbers would add up to the 5 seconds I'm seeing on some calls, but it looks more like they add up to around 1.2s.
The DirectHTTP MessageResponder.completeHandler doesn't indicate that my result received is a callee, but I'm going to move that logic out of the result received to isolate the performance data.
I'm assuming the flex contribution is 393 + 390 + 384 since each method is not a callee of the other. This still seems long. If you add in my result of 383, we're still less than two seconds. Still much less than the 5 seconds max I'm seeing.
I would assume the cumulative callees of the dispatchEvent would have more than just those three above. I'm not filtering anything.
Post a screen capture of the top 20 by cumulative time.
Make sure you are clearing all samples before clicking a button to make the request. I would also do the logging and output timestamps at various points and use a network monitor to watch activity so you can build out the timeline.
I was measuring time using Timer which I believe is a mistake, seems too inaccurate. I'm switching to capturing DateTime. The maximum response I get from the server over all responses using a network monitor is 1.8 sec. I'm going to map each request in more detail using DateTime measurements and will post the results. Below is the performance report.
The profiler is a sampling profiler, and only profiles actionscript processing and a few player things which show up in  like and . If you are running in the browser and do a network request, the player actually asks the browser to do the request and then only responds when the browser says the response has been returned. That’s why a network monitor and logging can help pin down what is happening when. I would use the Date() class in Actionscript and compare to the time stamps in a network monitor output. The browser could be trying to allocate memory, or be slowed down trying to cache the request in a very full cache, a memory scan from your virus scanner can get kicked off, etc.
Do you know how big the responses are? How many MB? How many XML nodes? How many attributes per node?
Also, when are you ending the profile? On the result event or when you see the data on screen? Are you converting the XML to objects? Tracing out the result?
I’m quite suspicious of the call count for ArrayCollection/set source. That’s way too high and quite expensive, even though it isn’t showing up on profiler. I would explore there. Normally, if you are working with XML you should convert it to an array of objects and only set the source once. Or just handle it as XML and not need ArrayCollection.
I see - I do see the browser absolute best minimum time (~.125s) always faster than the minimum for flex (~.274s). Example response that I am testing with, I'm sending ten consecutive requests:
Request: 525 bytes
Response: 1136 bytes
Total: 1661 bytes
Response Time: 0.576 seconds
There are on average 5 XML children per item. There are no more than two attributes per child, most have none. I'm trying to keep it low so that I can get absolute best numbers.
I'm really not ending a profile. I insert control buttons to control when HTTPServices would be launched. Unfortunately the results I posted do not stop at the result received, it goes through the build process. I am converting XML to objects, but the measurement of time is outside of that window. However, that process takes under 20ms when I measured it separately. I'm assuming that the profile data long pole is the access. I do trace the result, and my network monitor can store both flex traces and browser requests.
There are 389 instances of ArrayCollection - all these are in the value objects built from the server objects, none are in the builders. Some are in view instances. It does seem high though.
Try to put together the timeline using Date() and a network monitor.