The goal is to provide an info for web developers that can be used to analyze page load performance. This info should be composed from detailed timings for each network request made by the monitored page. The ideal timing info (for each request) should describe following phases: DNS Lookup: DNS Resolution time Connecting: time required to create a TCP connection. Blocking: time spent in a queue waiting for a network connection. Sending: time required to send HTTP request. Waiting: waiting for a response from the server. Receiving: time required to read entire response from the server (and/ or time required to read from cache). In case of partial cache read it should be possible to measure both times. See also a preceding discussion here: http://groups.google.com/group/mozilla.dev.platform/browse_thread/thread/af2d7784bdc33b34/d33c075c89716826?hl=en#d33c075c89716826

The states you describe are very close to states of nsSocketTransport class. It can be monitored with nsITransportEventSink (http://mxr.mozilla.org/mozilla-central/source/netwerk/base/src/nsSocketTransport2.cpp#1773). Problem is that you can assign just a single event sink and it's often already an overlaying channel (nsHttpChannel for instance) and it's probably proxied to the main thread. This definitely needs new API probably on level of nsSocketTransport.

> and it's probably proxied to the main thread. Yes, this is the problem I have described in the discussion. Also, one important thing that should be considered when designing the new APIs is that the initial request object (nsIHttpChannel in this case) must be passed into all callbacks. This allows to match all events (and compute timings) related to one specific request. This is an existing problem with current APIs, specifically with the nsIWebProgressListener.onStateChange. For images the request isn't the original nsIHttpChannel (passed e.g. to http-on-modify-request observer), but imgIRequest. Honza

One note: I had created an enhancement request to return the original nsIHttpChannel for image requests. It is Bug #394674. We need it so that we can examine HTTP Headers set on the response. The image, in this case, is generated on the fly and contains important performance information on the HTTP Headers.

(based on discussion with Boris) One possible solution for the precise timing measurement could be to remember the time when an event was put into the queue and store it into the event. This doesn't have to be necessarily so hard to implement and could be useful when measuring timings related even to non-network events. Just to notice that it still make sense to review existing events and verify/improve that it's easy to catch all phases as described in the bug summary. Honza

Problem is that there is not any event we sent, we just call a callback method with state and progress. We still need to change the API to pass time information.

I am changing the priority from [firebug-p3] to [firebug-p2] (I would use p1, but this isn't about a crash nor security issue). I have got another couple of requests during past few days to fix this problem. The fix would be really valuable for Firebug's Net panel. Is there any chance to have this fixed in Firefox 3.6? Honza

this is something that would be really important for Firebug net panel timing. Adding wanted 1.9.2 to get it on more people's radar. I'm also CC'ing Jason Duell for his kind attention.

nsHttpTransaction is the last class that receives notifications on the 'right' thread so it has accurate time information. It's using an 'activity distributor', at the moment unregistered (unimplemented) service with contract id "@mozilla.org/netwerk/protocol/http/http-activity-distributor;1", expected to implement nsIHttpActivityObserver. Firebug could implement that service and use it to collect timing information for each status of each channel. The callback gives you a channel as a parameter, useful advantage. Here is where the activity monitor is used and the interface is defined: http://mxr.mozilla.org/mozilla-central/ident?i=mActivityDistributor http://mxr.mozilla.org/mozilla-central/source/netwerk/protocol/http/public/nsIHttpActivityObserver.idl#47 Hope it helps.

This sounds like a promising solution. Anyway, some changes in the nsHttpTransaction class are necessary. If the nsHttpTransaction object passed a time stamp into the ObserveActivity method (implemented by activity-distributor, nsIHttpActivityObserver) the component could be implemented in Javascript - any delay caused by the UI queue is not a problem in that case (the correct time is passed in). The interface is marked as [scriptable] so, I believe it should not be a problem to have the implementation in JS. This is one of the places where the activity observer is called: http://mxr.mozilla.org/mozilla-central/source/netwerk/protocol/http/src/nsHttpTransaction.cpp#368 mActivityDistributor->ObserveActivity( mChannel, NS_HTTP_ACTIVITY_TYPE_HTTP_TRANSACTION, NS_HTTP_ACTIVITY_SUBTYPE_REQUEST_BODY_SENT, LL_ZERO, LL_ZERO, EmptyCString()); Instead of the (fourth) LL_ZERO parameter there should be current time stamp (number of milliseconds since epoch). As soon as a patch is attached I can implement a test prototype in Firebug and give a feedback. I hope there won't be unexpected surprises :-) Thanks to Jan Bambas for the idea! Honza

A sample JS component that outputs the activity monitor data (my work with time is wrong, but it's enough to demonstrate). Needs to be manually copied to dist/bin/components.

Here you can see the event list and order that comes for each channel/transaction pair.

Thanks for the patch! I am currently testing it with Firebug. One question. What if more extensions want to use the component to track HTTP traffic? The component is currently used as a service: "@mozilla.org/netwerk/protocol/http/http-activity-distributor;1", which means there can be only one. Possible solution could be having the component implemented as a part of Firefox and registerregister listeners/observers into it (from extensions). What do you think?

When testing the activity-observer with Firebug, I have stumbled upon a problem where no window is associated with the request channel passed into the observeActivity method. The window is missing typically (but sometimes it works!) for: STATUS_RECEIVING_FROM (the last one) ACTIVITY_SUBTYPE_RESPONSE_COMPLETE ACTIVITY_SUBTYPE_TRANSACTION_CLOSE 1) Install the attached extension (enable dump) 2) Load http://stevesouders.com/cuzillion/?ex=10100&title=Inline+Scripts+Block 3) See the black system console - a log says if the window is missing. Note that the window should always be available for requests made by the page. Here is how I am trying to get the window: function getWindowForRequest(request) { var webProgress = getRequestWebProgress(request); if (webProgress) return webProgress.DOMWindow; return null; } function getRequestWebProgress(request) { try { if (request && request.notificationCallbacks) return request.notificationCallbacks.getInterface(Components.interfaces.nsIWebProgress); } catch (exc) {} try { if (request && request.loadGroup && request.loadGroup.groupObserver) return request.loadGroup.groupObserver.QueryInterface(Components.interfaces.nsIWebProgress); } catch (exc) {} return null; } Honza

Or just have a category of services and notify everything in the category. That's how other necko observers work, right?

(In reply to comment #15) > Or just have a category of services and notify everything in the category. > That's how other necko observers work, right? Yes, this is also a possibility (e.g. command line handler is using this way). Note that the other listeners like: nsIWebProgressListener, HTTP observer (nsIObserver for: http-on-modify-request, etc.) use appropriate methods like addProgressListener and addObserver. I think, both ways are acceptable. Honza

@Jan Bambas: do you have assume any progress on the problems I have described in Comment #14? - Having the window available in all events has quite a big priority since it blocks me from further testing. - The problem with multiple components isn't that important at this moment, but sure must be solved as well. Honza

I won't get to this at least for 3 or more weeks.

(In reply to comment #14) > The window is missing typically (but sometimes it works!) for: > STATUS_RECEIVING_FROM (the last one) > ACTIVITY_SUBTYPE_RESPONSE_COMPLETE > ACTIVITY_SUBTYPE_TRANSACTION_CLOSE This happens because nsHttpChannel::OnStopRequest() is sometimes called before your call to nsHttpChannel::GetNotificationCallbacks() and in this case mCallbacks is null. We probably need to pass the window as a parameter to the observer.

This is preliminary patch that implements nsIHttpActivityDistributor. It receives all http activity notifications and passes them to all registered observers on the main thread. It doesn't solve the problem with non-existent window described in comment #19. Compilation fails when I try to include nsIDOMWindow.h and nsIWebProgress.h in netwerk/protocol/http. Adding dom and uriloader to REQUIRES in Makefile.in doesn't help. I can pass notificationCallbacks and loadGroup as parameters to the observer instead of the window, but I don't like it. In fact I don't like passing nsIDOMWindow as a parameter either but I don't see any good solution. Any ideas?

(In reply to comment #21) > Created an attachment (id=383475) [details] > Test extension that uses activity distributor from patch #383474 Just an idea: if you don't want to call AddObserver and RemoveObserver methods on other then the main thread there is no need for a lock, you are passing reference to the observer list in the event that is being walked on the main thread only. Just add NS_ENSURE_VALIDCALL to all methods that move with the list of observers. This may have performance impact.

This patch looks great. Thanks for adding it! A couple comments: -there is a bug that can cause observers to get skipped in some cases. consider this case: 1. observer A registers 2. observer B registers 3. distributor begins to dispatch events 4. observer A receives an event 5. observer A unregisters in its event callback 6. observer B does not get notified see nsHttpActivityDistributor.cpp:68. when A unregisters, mObservers.Count() goes to 1. after the i++, we've reached the end of the array, and dispatch terminates, even though observer B was never notified. I think the easiest way to fix this is to copy the mObservers array and pass a copy into the nsHttpActivityEvent. This has the slightly strange behavior that a listener that gets removed after dispatch is initiated will still get called, but I think that's better than skipping a registered observer. Also, consider using nsIProxyObjectManager instead of nsIRunnable. Take a look at LeRoy's proposed impl, which uses nsIProxyObjectManager if I recall correctly: https://bugzilla.mozilla.org/show_bug.cgi?id=308371#c79 I am not a huge fan of nsIProxyObjectManager since it hides too much, but it sure is handy when proxying function calls across threads. Seems like it might be worthwhile to use it in this case.

One other thought - it seems wrong to pass an nsIDOMWindow from the network layer. Can we solve the missing window issue w/o having to pass an nsIDOMWindow explicitly?

(In reply to comment #22) > Just an idea: if you don't want to call AddObserver and RemoveObserver methods > on other then the main thread there is no need for a lock, you are passing > reference to the observer list in the event that is being walked on the main > thread only. The observer list is being copied in constructor of nsHttpActivityEvent and this can happen on multiple threads. So the lock is IMHO necessary.

(In reply to comment #23) > I think the easiest way to fix this is to copy the mObservers array and pass a > copy into the nsHttpActivityEvent. This has the slightly strange behavior that > a listener that gets removed after dispatch is initiated will still get called, > but I think that's better than skipping a registered observer. This is exactly how it works. I'm passing reference to mObservers just to avoid extra coping, but mObserver in nsHttpActivityEvent is a copy of mObserver in nsHttpActivityDistributor. > Also, consider using nsIProxyObjectManager instead of nsIRunnable. I didn't measure it but I think that my approach is more efficient than nsIProxyObjectManager even for one listener. And it is definitely faster for more listeners.

> I can pass > notificationCallbacks and loadGroup as parameters to the observer instead of > the window, but I don't like it. In fact I don't like passing nsIDOMWindow as a > parameter either but I don't see any good solution. Any ideas? I am also not fan of this. If there is no simple solution for the not-accessible parent window, let's skip the problem for now. I think I can come up with a workaround in Firebug. The basic idea for the workaround is to manage a map: request->window of all requests in progress. When ACTIVITY_SUBTYPE_REQUEST_HEADER is received the associated request is inserted into the map together with the window and removed when ACTIVITY_SUBTYPE_TRANSACTION_CLOSE happens. As soon as there is always ACTIVITY_SUBTYPE_TRANSACTION_CLOSE event for ACTIVITY_SUBTYPE_REQUEST_HEADER event, the map will be cleaned up as soon as all requests are finished. Anyway, I have tested the patch made by Michal, comment #20, and all works as expected. Thanks! Is it possible to do a review and commit? Honza (btw. I am on holiday next week)

Comment on attachment 383475 [details] Test extension that uses activity distributor from patch #383474 I am asking Christian to do the review. Please change to a different person if there is anybody more appropriate. Thanks!

Comment on attachment 383474 [details] [diff] [review] Activity distributor implementation Sorry it was wrong attachment, now it's correct.

Comment on attachment 383474 [details] [diff] [review] Activity distributor implementation just two very quick comments - will do a full review tomorrow or so - * This attribute is true when this interface is active and should - * observe http activities. When false, observeActivity() should not - * be called. - */ - readonly attribute boolean isActive; why this change? +++ b/netwerk/protocol/http/src/nsHttpTransaction.cpp mActivityDistributor = do_GetService(NS_HTTPACTIVITYDISTRIBUTOR_CONTRACTID, &rv); + if (NS_FAILED(rv)) return rv; I'd really be much happier if you dealt with this more gracefully. like the previous code did.

(In reply to comment #30) > - readonly attribute boolean isActive; > > why this change? The interface nsIHttpActivityObserver used to be implemented by some extension and it was unknown when it wanted to be notified. Now when some observer doesn't want to be notified it simply unregisters itself at nsHttpActivityDistributor. > > +++ b/netwerk/protocol/http/src/nsHttpTransaction.cpp > mActivityDistributor = > do_GetService(NS_HTTPACTIVITYDISTRIBUTOR_CONTRACTID, &rv); > + if (NS_FAILED(rv)) return rv; > > I'd really be much happier if you dealt with this more gracefully. like the > previous code did. nsHttpActivityDistributor is now a part of mozilla code and so do_GetService() shouldn't fail.

One thing I would like to also measure in Firebug is a request "blocking" time. I.e. the time spent waiting for a network connection to become available. Currently the first event sent by the activity-distributor is STATUS_RESOLVING (in the case DNS resolution is necessary) or STATUS_CONNECTING_TO. But what I need is an event e.g. STATUS_OPENING that says when the request has really begun (i.e. was inserted into the internal browser request queue). By using such an event I can measure time between: STATUS_OPENING -> (STATUS_RESOLVING || STATUS_CONNECTING_TO) which would represent the blocking time. I see two solutions: 1) The activity distributor sends additional event e.g. STATUS_OPENING when a request is inserted into the queue. 2) The existing HTTP-ON-MODIFY-REQUEST (which I believe is sent at the time when a request is inserted into the queue) is improved and passes also a time-stamp along. Since this event is handled using nsIObserver.observe method the third "data" parameter could be used (but it's string, which isn't ideal) I personally think that #1 is more cleaner. What do you think? Does this make sense? Honza

You can get the request start time from the http-on-modify-request callback.

Since that callback is always invoked on the UI thread you can just take a timestamp from within the callback. That's what I do in the page speed activity panel.

(In reply to comment #34) > Since that callback is always invoked on the UI thread you can just take a > timestamp from within the callback. That's what I do in the page speed activity > panel. I see, so this seems to be solved. Honza

Christian, could you please do the full review of the patch from Michal (attachment 383474 [details] [diff] [review])? This bug is critical for Firebug's Net panel. Honza

Just a friendly reminder that anybody wanted to do review for the attached patch is welcomed! Having this bug fixed would be huge help for Firebug's Net panel. Thanks! Honza

Perhaps biesi can propose an alternative reviewer, if he is too busy to get to it?

Comment on attachment 383474 [details] [diff] [review] Activity distributor implementation I would like to avoid any time regression as it would be tiny. 1. I don't like we have to call on every event of every http request function PR_Now even there are no observers registered 2. I don't like to enter the lock of the the observer even there are no observers registered 3. IsActive semantics is now implemented a different way; before this patch the activity observing was inactive for the whole transaction lifetime when an activity observer implementation indicated it is not active during initiation of the transaction - we never got any notification about that transaction even the observer has been activated yet during the transaction's lifetime, now observer may register and receive events from the middle. such events will be ignored anyway. 4. If you want to get this to 1.9.1 you MUST NOT modify any existing interfaces Thinks I would change: 1. Leave the isActive attribute that would indicate there are any observers registered; it probably may be left unimplemented by the final consumer implementation. Let's say it is a leftover for 1.9.1 branch; on the trunk (and 1.9.2) we may move that attribute to nsIActivityDistributor interface where it would belong better. 2. Leave the code in nsHttpTransaction as is now, just add the PR_Now() call (my patch). 3. Make all methods touching the mObservers array be accessible only on the main thread and hold just a reference to that array in the event. In event's Run method copy it to a local array before iteration to allow moving with the mObservers array in the callback. This way you can remove the lock. If you strongly expect that observers would register on a thread different from the main one (what IMHO doesn't make sense) then shout. Michal, sorry to put all of this here this way, I would rather discuss on IRC first, but you are at this time on the vacation.

Hm.. to have the isActive attribute again, we have to have the lock anyway.

I pushed the patch to the try server. There seems not to be any T regression at all.

Attribute isActive is back again and nsHttpTransaction behavior isn't changed (i.e. notify all or none events according to isActive state in Init() method. I didn't follow your suggestions in point 3 in comment #39 since we can't get rid of the lock anyway.

Thanks Michal! Honza

Honza Bambas, could you please take a look at the patch provided by Michal. Thanks! Honza

Comment on attachment 395815 [details] [diff] [review] patch v2 Boris, could you please make an API review here? Please recommend somebody else if you are overloaded by work. Thanks! Honza

Maybe biesi? Or ask in .platform whether some other sr is interested? I'm pretty overloaded right now, yes. Certainly won't be able to get to this this week.

Comment on attachment 395815 [details] [diff] [review] patch v2 sr=shaver on trivial API addition; seems like we could have both the distributor and the observer defined in the same IDL file, since then we would get a little closer to having as much useful text in the file as there is license noise. :-)

Great, thanks Mike for the review! Michal, can you please merge the nsIHttpActivityDistributor.idl into nsIHttpActivityObserver.idl and we are done! Honza

Comment on attachment 397156 [details] [diff] [review] patch v3 [Checkin: Comment 51] Moving review markers forward for the benefit of a future checkin-needed processor.

Regression: Ts increase 2.51% on Vista Firefox Previous results: 531.895 from build 20090901142804 of revision b1c03798d676 at 2009-09-01 14:28:00 on talos-rev2-vista13 run # 0 New results: 545.263 from build 20090901145035 of revision b84f3d059d5d at 2009-09-01 14:50:00 on talos-rev2-vista01 run # 0 Suspected checkin range: from revision b1c03798d676 to revision b84f3d059d5d :(

:( :( :( only on vista or are we seeing this on other platforms?

I haven't gotten a notice for other platforms, but you should check the graphs and see :( :( :( :( :( :( :(

Chris thinks this might have been a false positive.

Looking at the checkin date, I gather this is for 1.9.3?

The goal was actually 1.9.2, I hope still possible.

Comment on attachment 397156 [details] [diff] [review] patch v3 [Checkin: Comment 51] Then we should request approval to land it on 1.9.2

Although, why aren't there tests for this? I also thought the new super review policy says that you can't have the super reviewer also be your reviewer.

> Then we should request approval to land it on 1.9.2 The wanted1.9.2 flag is still set, what else we should do? > lthough, why aren't there tests for this? I also thought the new super review > policy says that you can't have the super reviewer also be your reviewer. The review has been done by Jan Bambas and sr by Mike Shaver.

(In reply to comment #60) > > Then we should request approval to land it on 1.9.2 > The wanted1.9.2 flag is still set, what else we should do? Ask for approval on the patch, which I did. > > lthough, why aren't there tests for this? I also thought the new super review > > policy says that you can't have the super reviewer also be your reviewer. > The review has been done by Jan Bambas and sr by Mike Shaver. The newest non-obsolete patch made it look like shaver did both. Nevermind!

(In reply to comment #61) > (In reply to comment #60) > > > Then we should request approval to land it on 1.9.2 > > The wanted1.9.2 flag is still set, what else we should do? > Ask for approval on the patch, which I did. Cool, thanks!

Whiteboard says [c-n: patch doesn't apply cleanly to m-1.9.2] but I can apply it cleanly to 1.9.2 trunk (id 7487692ed149). What's wrong?

Michal, any chance we can get it to 1.9.2 soon? Honza

It has been committed to 1.9.2 (see comment #64).

Ah, I see, great! Honza

These interfaces are now documented: https://developer.mozilla.org/en/nsIHttpActivityObserver https://developer.mozilla.org/en/nsIHttpActivityDistributor An example of it in use would be nice to have if anyone would like to put one together.

DejaClick has been using the http-activity-distributor interface on our backend for several years and is critical to our extension. We will be reviewing these changes to see what may need to be adjusted as a result. Unfortunately, as there were no updates or postings made to connect the earlier bugs related to nsIHttpActivityObserver, we were not able to get involved in the discussion sooner. I'll post some reference links on the other bugs. For posterity, please see the following related bugs: https://bugzilla.mozilla.org/show_bug.cgi?id=526207 https://bugzilla.mozilla.org/show_bug.cgi?id=308371 https://bugzilla.mozilla.org/show_bug.cgi?id=341702

clearing old flags.