308371 - Add additional instrumentation to Http protocol

Status: RESOLVED FIXED

(Core :: Networking: HTTP, defect, P2)

Description

[LeRoy Krueger]

Add some additional instrumentation to the Http protocol handler. The current
Http protocol handler provides some activity indications to observers, but is
somewhat limited. 

The activities are reported without timestamps. Most of the activities take
place on the socket thread. If timestamps are added when the activities are
observed on the user interface thread, significant delays may be introduced
between the activity and the timestamp, and the delays will vary depending on
the dispatching of the different threads. An additional problem for the observer
is that some activities which generate events do not make it to the observer.

There is also a problem with getting the actual Http Response Header from the
current interfaces. When the server sends a '304 Not Modified' header back to
the platform, the current Http interfaces report this as a '200 OK' header
because the content was available in the cache.

To improve the Http instrumentation available to an observer, this bug proposes
to add several new interfaces to the current Http support.

The idea is to have an observer register with nsIObserverService for a new http
instrumentation topic. If there are one or more observers for the topic,  the
new instrumentation activities with timestamps will be reported. If no observers
are registered, Http activities will continue as usual.

Comment 1

[Darin Fisher]

This sounds good to me.  I'd like to see more details about the actual APIs that
you are proposing.

Comment 2

[LeRoy Krueger]

Attachment: additions to current http files

instrumentation additions to the existing http protocol files

Comment 3

[Darin Fisher]

Comment on attachment 195932 [details] [diff] [review]
additions to current http files

Could you please attach copies of the nsIHttpProbe* interfaces?

Comment 4

[Mike Kaply [:mkaply]]

Attachment: New files added for probe code.

Comment 5

[LeRoy Krueger]

To use the new instrumentation register with nsIObserverService for topic
'http-probe-activity'. 

When your observer method is called. aSubject will be an nsIHttpProbeActivity
interface, topic will be 'http-probe-activity'. You may use the
nsIHttpProbeActivity interface to read these readonly attributes.

  activityID       // one of:
     * nsISocketTransport::STATUS_RESOLVING
     * nsISocketTransport::STATUS_CONNECTING_TO
     * nsISocketTransport::STATUS_CONNECTED_TO
     * nsISocketTransport::STATUS_SENDING_TO
     *      extraData will contain the count of bytes sent
     * nsISocketTransport::STATUS_WAITING_FOR
     * nsIHttpProbeActivity::ACTIVITY_REQUEST_HEADER
     *      extraString will contain the text of the header
     * nsIHttpProbeActivity::ACTIVITY_REQUEST_BODY_SENT
     * nsIHttpProbeActivity::ACTIVITY_RESPONSE_START
     * nsIHttpProbeActivity::ACTIVITY_RESPONSE_HEADER
     *      extraString will contain the text of the header
     * nsIHttpProbeActivity::ACTIVITY_RESPONSE_COMPLETE
     *      extraData will contain the count of bytes received
     * nsIHttpProbeActivity::ACTIVITY_TRANSACTION_CLOSE
  timestamp        // microseconds past the 1970 epoch of the activity
  extraData        // optional extra PRUint64
  extraString      // optional extra ACString
  httpChannel      // nsIHttpChannel that generated the activity
  correlationID    // ID of the channel, 1 through max PRUint32
  currentTimestamp // microseconds past the 1970 epoch when called

nsIHttpProbeListener is used internally for nsHttpTransaction to report activity
back to nsHttpChannel. Most activities within nsHttpTransaction take place on a
socket thread, so a proxy is used for the nsIHttpProbeListener interface on the
nsHttpChannel object.

Comment 6

[LeRoy Krueger]

The three new interfaces are in the second attachment that Mike Kaply just put
up for me.

Comment 7

[LeRoy Krueger]

I have a question for Darin, or another member of the Http team. When creating a
proxy for the nsIHttpProbeListener interface I am using the NS_UI_THREAD_EVENTQ,
because I want the ReportActivity method to operate on the same thread as
Javascript. Would it be better to use NS_CURRENT_EVENTQ for future compatability
if each Browser gets its own UI thread?

Comment 8

[Darin Fisher]

The nsHttpTransaction object has a mConsumerEventQ member that you should use.

Comment 9

[Christian :Biesinger (don't email me, ping me on IRC)]

+    static nsCOMPtr<nsIObserverService> sObserverService = 
+                            do_GetService("@mozilla.org/observer-service;1");

wow... does this work? I'm really not sure that this is a good idea. can it be
stored on the HTTPHandler?

+    PRUint32 correlationID = 0;
+    rv = GetCorrelationID(&correlationID);
+    NS_ENSURE_SUCCESS(rv, rv);
+    NS_ENSURE_TRUE(correlationID, NS_ERROR_FAILURE);

there shouldn't really be a need to check both. at most, an assertion for the
second case should be sufficient... the initialization of the variable is not
needed either

+    nsCOMPtr<nsIHttpProbeActivity> activity(do_QueryInterface(
+                                                new nsHttpProbeActivity(
...
+    NS_ENSURE_SUCCESS(rv, rv);
+    NS_ENSURE_TRUE(activity, NS_ERROR_OUT_OF_MEMORY);    

(trailing whitespace on the last line here)
There's no need to QI here... and it might be better to do the allocation on its
own line, so you don't need quite so much indentation.

And you also don't need both NS_ENSURE_* lines...
+    NS_ENSURE_ARG_POINTER(aCorrelationID);

there's really no need to nullcheck out parameters... at most I'd use
NS_PRECONDITION (various times in the two patches)

public/nsIHttpProbeListener.idl
+    void ReportActivity(in PRUint32 aActivityID,

use interCaps (i.e. reportActivity)

src/nsHttpProbe.cpp
+    NS_ENSURE_ARG_POINTER(aResult);
+    NS_ENSURE_ARG_POINTER(aListener);

I'd turn them into assertions...

+    // this will be a normal circumstance
+    // return NS_OK and *result set to nsnull
+    NS_ENSURE_SUCCESS(rv, NS_OK);
+    NS_ENSURE_TRUE(observers, NS_OK);

normal circumstances shouldn't use NS_ENSURE_*, because that shows a warning on
stderr. (I also don't think you need both lines, but maybe...)

Comment 10

[LeRoy Krueger]

(In reply to comment #9)
Christian, 

Thanks for taking the time to review this submission so quickly. I will reply to
each comment below.

> +    static nsCOMPtr<nsIObserverService> sObserverService = 
> +                            do_GetService("@mozilla.org/observer-service;1");
> 
> wow... does this work? I'm really not sure that this is a good idea. can it be
> stored on the HTTPHandler?
> 
Yes, this does work for my Windows build. I browsed around in the code base
looking for an example of a static class member but did not notice any. I wanted
to keep the number of modules touched by this change to a minimum, so I kept
away from nsHttpHandler. I saw lots of examples in the code where the
nsIObserverService is loaded into an auto nsCOMPtr and then used. This function
will be called a number of times for each nsHttpTransaction, so I wanted to only
init the nsCOMPtr once.

> +    PRUint32 correlationID = 0;
> +    rv = GetCorrelationID(&correlationID);
> +    NS_ENSURE_SUCCESS(rv, rv);
> +    NS_ENSURE_TRUE(correlationID, NS_ERROR_FAILURE);
> 
> there shouldn't really be a need to check both. at most, an assertion for the
> second case should be sufficient... the initialization of the variable is not
> needed either

Trying to be complete. So you suggest:

  PRUint32 correlationID;
  rv = GetCorrelationID(&correlationID);
  NS_ENSURE_TRUE(correlationID, NS_ERROR_FAILURE);

Looks like that will work with the current implementation of GetCorrelationID(),
but we need to assume something about GetCorrelationID()... that it will set
correlationID to zero if it fails... Is that a safe assumption to make?

> 
> +    nsCOMPtr<nsIHttpProbeActivity> activity(do_QueryInterface(
> +                                                new nsHttpProbeActivity(
> ...
> +    NS_ENSURE_SUCCESS(rv, rv);
> +    NS_ENSURE_TRUE(activity, NS_ERROR_OUT_OF_MEMORY);    
> 
> (trailing whitespace on the last line here)

Rats! Thanks, I forgot to strip trailing spaces, will correct.

> There's no need to QI here... and it might be better to do the allocation on its
> own line, so you don't need quite so much indentation.
> 

I will try dropping the QI... I remember having a compiler error in that area, I
will check again. I read in the nsCOMPtr guidelines that initialization is
preferred to assignment. Does indentation override that preference?

> And you also don't need both NS_ENSURE_* lines...

Yes, if the QI is dropped, the rv line goes away.

> +    NS_ENSURE_ARG_POINTER(aCorrelationID);
> 
> there's really no need to nullcheck out parameters... at most I'd use
> NS_PRECONDITION (various times in the two patches)
> 
I am not sure I agree... This interface can be called from anywhere, including
Javascript. I would hate to crash someone's browser because of a missing parm
check. That parm is a pointer after all. 

> public/nsIHttpProbeListener.idl
> +    void ReportActivity(in PRUint32 aActivityID,
> 
> use interCaps (i.e. reportActivity)
> 

Quite right, sorry about that.

> src/nsHttpProbe.cpp
> +    NS_ENSURE_ARG_POINTER(aResult);
> +    NS_ENSURE_ARG_POINTER(aListener);
> 
> I'd turn them into assertions...
>

Yes, I also now see an assignment before the check...  This function will not be
called from outside of the compiled code, so NS_PRECONDITION seems appropriate here.
 
> +    // this will be a normal circumstance
> +    // return NS_OK and *result set to nsnull
> +    NS_ENSURE_SUCCESS(rv, NS_OK);
> +    NS_ENSURE_TRUE(observers, NS_OK);
> 
> normal circumstances shouldn't use NS_ENSURE_*, because that shows a warning on
> stderr. (I also don't think you need both lines, but maybe...)
> 

Something is going badly if EnumerateObservers gives back something other than
NS_OK... it will always normally return an nsISimpleEmumeration. The enumeration
will be empty if no observer is registered. I am thinking about not using 
NS_ENSURE_TRUE(bHasMoreElements, NS_OK); now. I don't want a warning for a
normal condition.
> 
> 
> 

Comment 11

[LeRoy Krueger]

(In reply to comment #8)
> The nsHttpTransaction object has a mConsumerEventQ member that you should use.

Thanks Darin, I will adapt it to use mConsumerEventQ in the next one you see.

Comment 12

[Christian :Biesinger (don't email me, ping me on IRC)]

(In reply to comment #10)
> I saw lots of examples in the code where the
> nsIObserverService is loaded into an auto nsCOMPtr and then used. This function
> will be called a number of times for each nsHttpTransaction, so I wanted to only
> init the nsCOMPtr once.

Storing it in an nsCOMPtr is ok; but I am not sure that using a static comptr is
good.

> Trying to be complete. So you suggest:
> 
>   PRUint32 correlationID;
>   rv = GetCorrelationID(&correlationID);
>   NS_ENSURE_TRUE(correlationID, NS_ERROR_FAILURE);

Actually I meant:
   PRUint32 correlationID;
   rv = GetCorrelationID(&correlationID);
   NS_ENSURE_SUCCESS(rv, rv);
   NS_ASSERTION(correlationID, "GetCorrelationID returned a zero ID!");

> I will try dropping the QI... I remember having a compiler error in that area, I
> will check again. I read in the nsCOMPtr guidelines that initialization is
> preferred to assignment. Does indentation override that preference?

I meant something like:
  nsHttpProbeActivity* act = new nsHttpProbeActivity(...);
  nsCOMPtr<nsIHttpProbeActivity> activity(act);

Hm... actually if you just drop the do_QI then that's probably ok too.

> > +    NS_ENSURE_ARG_POINTER(aCorrelationID);
> I am not sure I agree... This interface can be called from anywhere, including
> Javascript. I would hate to crash someone's browser because of a missing parm
> check. That parm is a pointer after all. 

JS can't pass null to an out argument.

> I am thinking about not using 
> NS_ENSURE_TRUE(bHasMoreElements, NS_OK); now. I don't want a warning for a
> normal condition.

Yeah, you could just do
 if (!bHasMoreElements)
   return NS_OK;

Comment 13

[timeless]

do *not* use static comptrs <period>

Comment 14

[LeRoy Krueger]

(In reply to comment #12 and #13)

Thanks Christian... I agree with with all of the edits, and have made all but
the change from the static nsCOMPtrs. Those changes and using the queue Darin
suggested are working fine here. I will update the code when we resolve the
static nsCOMPtr issue. timeless is right, I should not use them.

I am open to suggestions about how to replace my two instances of:

    static nsCOMPtr<nsIObserverService> sObserverService(
                    do_GetService("@mozilla.org/observer-service;1"));


One instance is in a function called once for each nsHttpTransaction, this one
is called from nsHttpTransaction.

The other is called 5 to 10 times for each nsHttpTransaction but is part of
nsHttpChannel.

My credit union home page needs over 150 nsHttpTransactions to load. (Oh My!)
Normal pages run between 20 and 50 nsHttpTransactions per page.

I have a feeling that do_GetService has a fairly long code path. I would like to
avoid the call as many times as possible.

Comment 15

[LeRoy Krueger]

Attachment: Test Extension for nsIHttpProbeActivity

httpProbeObserver.xpi is a small extension that tests the nsIHttpProbeActivity
interface.

Build Firefox with the patches and new files for the additional
instrumentation.
Install the test extension.
Start Firefox, the Tools menu will now include a line "Test
nsIHttpProbeActivity" click to activate/deactivate the test extension.
While the Test extension is active, browse normally. 
A formatted representation of the nsIHttpProbeActivity objects will be sent to
the Javascript Console Messages tab.

Comment 16

[Christian :Biesinger (don't email me, ping me on IRC)]

I believe you have easy access to an nsHttpHandler, which is a singleton. can't
you store it there?

Comment 17

[LeRoy Krueger]

Yes Christian, I have been thinking along the same lines. Two new methods in
nsHttpHandler should do it. The first is a public clone of:

    void NotifyObservers(nsIHttpChannel *chan, const char *event);

This new public method would have this signature:

    void NotifyObservers(nsIHttpProbeActivity *aActivity, const char *aTopic);

This method would be called from nsHttpChannel::ReportActivity().

We have a choice for the second function, we can either make it specific to
httpProbe, or more general.

A general public method would have a signature something like this:

   nsresult HasTopicObserver(PRBool &aHasObserver, const char * aTopic);

A specific public method would have a signature something like this:

   nsresult NewHttpProbeListenerProxy(nsIHttpProbeListener **aResult,
                                      nsISupports *aListener,
                                      nsIEventQueue *aTargetQueue);

Right now, I am leaning toward the specific function, which moves
net_NewHttpProbeListenerProxy() to nsHttpHandler. I would like some opinions
from the community before I make a final decision though. 

Comment 18

[LeRoy Krueger]

I have been looking at net_TimestampMicroseconds() and have found several problems.

PR_IntervalNow() will wrap as often as every 72 minutes. The current code
doesn't handle a wrap.

PR_IntervalToMicroseconds() does not deal with overflow which may occur.

The code handles PRUint64 addition and subtraction directly instead of using the
LL_* macros. 

So the next version of net_TimestampMicroseconds() will address those problems.

Comment 19

[LeRoy Krueger]

Attachment: Test Extension for nsIHttpProbeActivity

revise function formatMicrosecondTimestampForConsole() to deal with non-english
locales

Comment 20

[Mike Kaply [:mkaply]]

Attachment: Update to the new files per reviewer comments

Comment 21

[Mike Kaply [:mkaply]]

Attachment: Update to core files diff per reviewers

Comment 22

[Mike Kaply [:mkaply]]

Attachment: Forgot diff for new files HttpProbeActivity

Comment 23

[LeRoy Krueger]

Another note for the updated files. nsHttpProbe.h and nsHttpProbe.cpp have been
replaced by nsHttpProbeActivity.h and nsHttpProbeActivity.cpp from now on. 

All of the old static members and global functions have been moved into
nsHttpHandler.h and nsHttpHandler.cpp.

I moved some of the instrumentation points around a little in nsHttpTransaction.

Comment 24

[Darin Fisher]

Why isn't net_TimestampMicroseconds implemented simply as a call to PR_Now? 
Does that somehow not provide sufficient precision?  Or, are you just worried
that someone might change their clock while this interface is being used?  Is
there some other reason that I'm missing?

Comment 25

[LeRoy Krueger]

(In reply to comment #24)
> Why isn't net_TimestampMicroseconds implemented simply as a call to PR_Now? 
> Does that somehow not provide sufficient precision?  Or, are you just worried
> that someone might change their clock while this interface is being used?  Is
> there some other reason that I'm missing?

PR_Now() does well on some platforms, but a 'better' timestamp may be had at
least on Windows by using PR_IntervalNow() with a base timestamp obtained from
PR_Now(). 

On Windows the minimum increment I have seen for PR_Now() is 250 microseconds.
The minimum increment I have seen using net_TimestampMicroseconds is 6
microseconds. The sockets interface moves along much faster than the 250
microsecond resolution, so why not go for the higher resolution timestamp?

Comment 26

[Darin Fisher]

> On Windows the minimum increment I have seen for PR_Now() is 250 microseconds.
> The minimum increment I have seen using net_TimestampMicroseconds is 6
> microseconds. The sockets interface moves along much faster than the 250
> microsecond resolution, so why not go for the higher resolution timestamp?

Wow.  That makes me think that we should be using a different Windows API to
implement PR_Now.

Comment 27

[Darin Fisher]

> Wow.  That makes me think that we should be using a different Windows API to
> implement PR_Now.

Or, maybe not.  I guess this is the whole point to PR_IntervalNow.  Oh well.

Comment 28

[LeRoy Krueger]

Attachment: Updates for the core files

I have been working in nsHttpHandler::GetTimstampMicroseconds(), I found that
on my Linux machine, PR_Now() had a smallest observed interval of 3
microseconds, but PR_IntervalTimer had an interval of 1000 microseconds. So
there is now a one time test to check if the interval timer has a finer
resolution than PR_Now(). When PR_Now() is finer, PR_Now() is used. PRLock has
also been added to the timestamp method, it can be called from both the UI
thread and socket thread(s) and they could interfere within the interval timer
calculations.

I fixed a compiler warning about initialization order in nsHttpChannel for my
new member. 

Went on trailing space patrol in the rest of the modules.

Comment 29

[Darin Fisher]

GenerateTimestampMicroseconds is getting pretty complex :-(

Here's my suggestion.  While it is nice to provide full-featured capabilities
like this in the core, the bare minimum is just the insertion of hooks into the
proper places.  I think the core changes could be reduced to nothing more than a
few callbacks that are not constrained to only executing on the main thread. 
Then, you could move all of the timestamp generation, proxy, and so on code out
into an extension.  I'm making this suggestion because the current patch is way
too involved to be considered for Firefox 1.5.  There's performance implications
to consider for 1.5 as well as other issues, which I won't have time to really
think about until after 1.5 ships anyways.

You could imagine having the HTTP handler enumerate a XPCOM category at startup,
creating instances of all of the components listed in the category, and then
notifying that list of objects of various events both on the main thread as well
as the socket thread.  I'd recommend inventing a minimal interface for
communication between the HTTP implementation and these observers.

I'm sorry to not have steered you in this direction earlier, but it has been
tough to find the time to give this problem the thought it deserves.  I hope
this helps.

Comment 30

[Wan-Teh Chang]

In order to prevent PRIntervalTime (a 32-bit unsigned integer)
from wrapping around too quickly, NSPR has a maximum precision
of 10 microseconds.  See
http://lxr.mozilla.org/nspr/source/nsprpub/pr/include/prinrval.h#63

The 1000 microsecond precision is the minimum precision required
by NSPR.  From what you reported, there is room to improve the
precision to 100 or 10 microseconds on Linux.

On Windows PR_Now is implemented with the Win32 GetSystemTimeAsFileTime
function.

 

Comment 31

[LeRoy Krueger]

(In reply to comment #29)
Thanks you taking the time to review this proposal. I appreciate that your time
is limited and you have many demands on it. 

> GenerateTimestampMicroseconds is getting pretty complex :-(

Yep, it does feel complex... but most of the work is done the first time
through. On platforms with an optimum PR_Now() we have a path like this.
  if (false)
  if (true)
    return PR_Now();
Maybe we should just use PR_Now(). and deal with the PR_Now() resolution issue 
at a future time.

> 
> Here's my suggestion.  While it is nice to provide full-featured capabilities
> like this in the core, the bare minimum is just the insertion of hooks into the
> proper places.  I think the core changes could be reduced to nothing more than a
> few callbacks that are not constrained to only executing on the main thread.

Hmmm, I don't think I have communicated well. There is no thread switch in
nsHttpTransaction... the calls to nsIHttpProbeListener all take place on the
socket thread. A call to get the timestamp is needed before the async method
call is queued for the main thread. That is why nsHttpTransaction needs a proxy
for the nsIHttpProbeListener interface of nsHttpChannel. That way,
nsHttpTransaction will not be slowed too much by calls to nsIHttpProbeListener.
Whenever the UI thread gets around to servicing the async method queue, the
actual nsIHttpProbeListener method will be called to notify any registered
observers. 

> Then, you could move all of the timestamp generation, proxy, and so on code out
> into an extension.

I don't understand how to put this stuff into a JavaScript extension without a
thread switch, which would be deadly for acuracy.

>  I'm making this suggestion because the current patch is way
> too involved to be considered for Firefox 1.5.  There's performance implications
> to consider for 1.5 as well as other issues, which I won't have time to really
> think about until after 1.5 ships anyways.
> 
I agree, the complexity will need to be reduced if there is to be any hope of
getting into 1.5. Maybe we should fall back to targeting Firefox 2.0. Firefox
1.5 would be nice, but a facility we all can agree on and feel confident about
is more important.

> You could imagine having the HTTP handler enumerate a XPCOM category at startup,
> creating instances of all of the components listed in the category, and then
> notifying that list of objects of various events both on the main thread as well
> as the socket thread.  I'd recommend inventing a minimal interface for
> communication between the HTTP implementation and these observers.

I not sure what you are trying to tell me here. Would that mean the any
extension would need to include compiled code? At a minimum, a timestamp would
need to be grabbed before a thread switch or any queueing. The other thing that
is important is to make certain each the activities can be associated with the
correct nsHttpChannel. 

Do you know of an example of an extension that works in the manner similar to
what you propose? My limited experience is of extensions as universal code, not
compiled, platform specific code.
> 
> I'm sorry to not have steered you in this direction earlier, but it has been
> tough to find the time to give this problem the thought it deserves.  I hope
> this helps.

No problem, I have been looking forward to your review, and I am happy that you
have shared your suggestions.

Comment 32

[LeRoy Krueger]

(In reply to comment #30)
> In order to prevent PRIntervalTime (a 32-bit unsigned integer)
> from wrapping around too quickly, NSPR has a maximum precision
> of 10 microseconds.  See
> http://lxr.mozilla.org/nspr/source/nsprpub/pr/include/prinrval.h#63
> 
> The 1000 microsecond precision is the minimum precision required
> by NSPR.  From what you reported, there is room to improve the
> precision to 100 or 10 microseconds on Linux.
> 
> On Windows PR_Now is implemented with the Win32 GetSystemTimeAsFileTime
> function.
> 
>  

Yes, Win32 GetSystemTimeAsFileTime() does not update at a very high frequency,
although the resolution of 100 nanoseconds is commendable. 

To get a higher resolution current time, you can use the performance counter.
via Win32 QueryPerformanceFrequency() and Win32 QueryPerformanceCounter(). But
like any interval counter there are wrap issues and coordination to the time of
day clock can take a bit of time. There are also some nasty problems associated
with processor sleep modes that may or may not continue those counters. 

So Win32 GetSystemTimeAsFileTime() is probably the right choice for NSPR. We can
always hope that Windows will do the updates more frequently as platform
performance improves with the future.

Comment 33

[Darin Fisher]

> Hmmm, I don't think I have communicated well. There is no thread switch in
> nsHttpTransaction... the calls to nsIHttpProbeListener all take place on the
> socket thread. A call to get the timestamp is needed before the async method
> call is queued for the main thread. That is why nsHttpTransaction needs a 
> proxy for the nsIHttpProbeListener interface of nsHttpChannel. That way,
> nsHttpTransaction will not be slowed too much by calls to 
> nsIHttpProbeListener.  Whenever the UI thread gets around to servicing the 
> async method queue, the actual nsIHttpProbeListener method will be called to 
> notify any registered observers. 

My proposal is basically to move nsIHttpProbeListener out into your extension. 
It would require C++ code, which I understand is an additional burden for any
extension author, but it allows us to greatly simplify the changes to the
Mozilla codebase, which opens up 1.5 as a potential target.

Comment 34

[Christian :Biesinger (don't email me, ping me on IRC)]

JS can run on background threads too....

Comment 35

[Darin Fisher]

(In reply to comment #34)
> JS can run on background threads too....

Provided you ensure that your JS context has a global scope that isn't a DOM
window or somehow references a DOM window ;-)  There's no good way to get a high
resolution interval counter via JS, right?

Comment 36

[LeRoy Krueger]

(In reply to comment #35)
> (In reply to comment #34)
> > JS can run on background threads too....
> 
> Provided you ensure that your JS context has a global scope that isn't a DOM
> window or somehow references a DOM window ;-)  There's no good way to get a high
> resolution interval counter via JS, right?

Yes that is pretty much what I have seen. The Date object has millisecond
resolution, and I have not found PR_Now() exposed anywhere. That was one of the
reasons for nsIHttpProbeInfo::currentTimestamp. That way JS could access a high
res clock.

I can envision how to implement nsIHttpProbeListener up in JavaScript, JS will
even handle the proxy issues for us, the listener need not be on the socket
thread as long as the timestamp is taken on the socket thread. 

I can think of a couple of issues that would need to be addressed right away.
The first one is a way to register/unregister the interface with nsHttpHandler.
Is there a way to get to the global instance of nsHttpHandler from JS? Are the
interfaces frozen? Would it be appropriate to extend an existing interface, or
create a new one? The patch right now only extends, it does not try to mess with
success. 

The second is that the nsIHttpChannel for the instrumented transaction would
need to be one of the parms passed to nsIHttpProbeListener::ReportActivity().
nsHttpTransaction does not now have a reference to its owning nsHttpChannel. I
can see getting into reference count trouble quickly and nsHttpChannel lifetime
issues caused by the extension. Or am I just imagining a problem with
nsHttpChannel lifetime?

What would go away? Certainly nsIHttpProbeListener in nsHttpChannel. Possibly
nsIHttpProbeInfo in nsHttpChannel. Certainly nsIHttpProbeActivity. Possibly
nsHttpHandler::GenerateTimestampMicroseconds() if the probe macro used PR_Now()
with the available platform resolution. We could also substitute a different
check for a registered nsIHttpProbeListener for
nsHttpHandler::NewHttpProbeListenerProxy().
nsHttpHandler::NotifyActivityObservers could go too.

That leaves at least one new function in nsHttpHandler for the probe macro to
conditionally call when there is a registered listener. A question I have here
is should we allow for multiple listeners, or should one be all we allow, like
much of the existing code. That was one of the appealing points about using
nsIObserverService for registration.

Is this going in the direction you were thinking about. I haven't stepped
outside of JS for the extension yet, but there may be nsHttpChannel lifetime
issues to solve, and the timestamp still needs to happen on the socket thread in
the core. 

Do you have any issues with my current probe points in nsHttpTransaction? I
would retain a simple test of a member variable in the probe macro to prevent
parm gathering when no one is listening.

Comment 37

[Christian :Biesinger (don't email me, ping me on IRC)]

(the nsHttpHandler is the protocol handler for "http"; see
nsIIOService::GetProtocolHandler)

Comment 38

[LeRoy Krueger]

How about this approach to simplification:

Drop nsIHttpProbeInfo
Drop nsIHttpProbeActivity
Drop the correlationID for nsHttpChannel
remove all changes in nsHttpChannel
Drop GenerateTimestampMicroseconds() and use PR_Now() :-(

continue to use nsIObserverService, but require observers to also implement
nsIHttpProbeListener. That way our notifier could be a clone of
nsObserverService::NotifyObservers() that called nsIHttpProbeListener instead of
nsIObserve.

nsHttpTransaction would need to supply the right nsIHttpChannel to the
notification function.

All additions could be limited to nsHttpHandler and nsHttpTransaction.

I don't see a way around using a asynchronous proxy between the producer and
consumer of the probe data. I don't want the socket activity to be slowed down
by a synchronous data consumer.

Does this design seem more like your vision, Darin? If so, the pieces are in
place to get started right away.

Comment 39

[Darin Fisher]

> Does this design seem more like your vision, Darin? If so, the pieces are in
> place to get started right away.

How about dividing the problem like this:

  (1) Support an observer interface that will be called on either the main
thread or socket thread.  No proxying done at this point.  No timestamp
generated at this point.  This is just a low-level hook.  Call this interface
when various events happen.

  (2) Develop an observer implementation that generates a timestamp and
dispatches the events to the main thread.  This guy would be responsible for
making the API easy to use from script.

Make #1 your priority.  Once we get that done and into the tree, then we go for
#2.  If we run out of time for #2, or if it is considered too large of a change
for 1.5, then you can always build #2 yourself and include it in your extension.

Let's start by enumerating all of the events you want to intercept, and then
let's design a simple interface (could be nsIHttp specific) that can be used to
convey those events.  We'll also need a way to give the listener context about
what request is being processed.  For example, the listener will need a way to
get a the nsIHttpChannel.  The nsHttpTransaction has a reference to the
nsIHttpChannel, so it could just pass that reference along.  We have to be
careful because nsIHttpChannel can only be used on the main thread, so it might
make sense to pass the "channel" as a nsISupports.  (The channel supports being
addref'd and released on a background thread.)

  interface nsIHttpActivityObserver : nsISupports {
    void observe(in nsISupports aContext,
                 in long aTopic,
                 in nsresult aStatus,
                 ... );
  };

Let aContext be a reference to the channel, and let aTopic be a numeric value
that indicates what kind of event this is.  I would define all of the topics on
this interface as const values.  For socket level events, I'd just have a
"socket event" topic, and then I'd use the aStatus parameter to pass the
specific nsISocketTransport status code.

The "..." in the parameter list above is for possible other parameters that may
need to be defined.

To register nsIHttpActivityObserver implementations, just use a XPCOM category.
 At startup, nsHttpHandler can enumerate this category, which will contain a
list of ContractIDs to instantiate.

If you need to associate an ID with a nsIHttpChannel, then remember that your
extension could always QI nsIHttpChannel to nsIPropertyBag, and from there it
could assign an ID to a channel.  In other words, I don't think we need to add
an explicit GetCorrelationID function on every channel.

Comment 40

[LeRoy Krueger]

(In reply to comment #39)

Thanks Darin, I think I now have a clear idea of what you are suggesting.

I worry about a few things with this approach. 

nsIHttpActivityObserver needs to be present when nsHttpHandler loads and needs
to stick around until the nsHttpHandler is destroyed. Or should nsHttpHandler
query for the interface more often.

The nsIHttpActivityObserver will not have access to a fine grain timestamp if it
is created in JavaScript.

The call out to nsIHttpActivityObserver would occur several times during each
httpTransaction. I worry that the timing of the transaction would be affected by
the measurement of it, and that the timing of the transaction would vary based
on the quality of the nsIHttpActivityObserver implementation.

I will need to investigate:

To register nsIHttpActivityObserver implementations, just use a XPCOM category.
 At startup, nsHttpHandler can enumerate this category, which will contain a
list of ContractIDs to instantiate.

I don't remember coming across something like that. 

Comment 41

[LeRoy Krueger]

Ok, I think I am getting there... If the IDL looks like this:

#include "nsISupports.idl"


/**
 * nsIHttpActivityObserver
 *
 * This interface provides a way for network activities to be reported
 * to registered observers. The interface is normally called through a
 * proxy because ReportActivity must execute on the UI thread and most
 * of the activities will take place on a socket thread
 */
[scriptable, uuid(0451A753-FEC6-4c33-8B93-DC3B87213EBA)]
interface nsIHttpActivityObserver : nsISupports
{
    /**
     * report activity at a particular time with optional extra data
     *
     * @parma aChannel
     *        nsIHttpChannel interface for the the channel that
     *        generated this activity
     * @param aActivityID
     *        The id of this activity, will be one of
     *        nsISocketTransport::STATUS_RESOLVING
     *        nsISocketTransport::STATUS_CONNECTING_TO
     *        nsISocketTransport::STATUS_CONNECTED_TO
     *        nsISocketTransport::STATUS_SENDING_TO
     *          extraData will contain the count of bytes sent
     *          there may be more than one of these
     *        nsISocketTransport::STATUS_WAITING_FOR
     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_HEADER
     *          extraString will contain the text of the header
     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_BODY_SENT
     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_START
     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_HEADER
     *          extraString will contain the text of the header
     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_COMPLETE
     *          extraData will contain the count of bytes received
     *        nsIHttpActivityObserver::ACTIVITY_TRANS_CLOSE
     * @param aExtraData
     *        Any extra numeric data optionally available with
     *        this activity
     * @param aExtraString
     *        Any extra string data optionally available with
     *        this activity
     */
    void reportActivity(in nsISupports  aChannel,
                        in PRUint32     aActivityID,
                        in PRUint64     aExtraData,
                        in ACString     aExtraString);

    const unsigned long ACTIVITY_REQUEST_HEADER         = 5001;
    const unsigned long ACTIVITY_REQUEST_BODY_SENT      = 5002;
    const unsigned long ACTIVITY_RESPONSE_START         = 5003;
    const unsigned long ACTIVITY_RESPONSE_HEADER        = 5004;
    const unsigned long ACTIVITY_RESPONSE_COMPLETE      = 5005;
    const unsigned long ACTIVITY_TRANSACTION_CLOSE      = 5006;
    
};

%{C++

#define NS_HTTP_PROBE_REPORT_ACTIVITY(activity,extraData) \
    if (mHttpAcivityObserver) \
        mHttpAcivityObserver->observe( \
            mChannel, \
            NS_STATIC_CAST(PRUint32, activity), \
            NS_STATIC_CAST(PRUint64, extraData), \
            NS_LITERAL_CSTRING(""));

#define NS_HTTP_PROBE_REPORT_ACTIVITY_STRING(activity,extraString) \
    mHttpAcivityObserver->observe( \
         mChannel, \
         NS_STATIC_CAST(PRUint32, activity), \
         NS_STATIC_CAST(PRUint64, 0), \
         extraString);

#define NS_HTTP_PROBE_ACTIVITY_TOPIC "http-probe-activity"

#define NS_HTTP_PROBE_ACTIVITY_REQUEST_HEADER    \
            nsIHttpActivityObserver::ACTIVITY_REQUEST_HEADER
#define NS_HTTP_PROBE_ACTIVITY_REQUEST_BODY_SENT \
            nsIHttpActivityObserver::ACTIVITY_REQUEST_BODY_SENT
#define NS_HTTP_PROBE_ACTIVITY_RESPONSE_START    \
            nsIHttpActivityObserver::ACTIVITY_RESPONSE_START
#define NS_HTTP_PROBE_ACTIVITY_RESPONSE_HEADER   \
            nsIHttpActivityObserver::ACTIVITY_RESPONSE_HEADER
#define NS_HTTP_PROBE_ACTIVITY_RESPONSE_COMPLETE \
            nsIHttpActivityObserver::ACTIVITY_RESPONSE_COMPLETE
#define NS_HTTP_PROBE_ACTIVITY_TRANSACTION_CLOSE \
            nsIHttpActivityObserver::ACTIVITY_TRANSACTION_CLOSE

%}

The macros would stay where they are in nsHttpTransaction. I would have one
additional function in nsHttpHandler:

nsresult
nsHttpHandler::QueryHttpActivityObserver(nsIHttpActivityObserver **aResult)

Would be called from nsHttpTransaction::Init to set mHttpActivityObserver in the
nsHttpTransaction. Would also need to do a QueryInterface on the eventSink parm
to nsHttpTransaction::Init() to get the nsISupports of the nsHttpChannel into a
nsCOMPtr for nsHttpTransaction.

That would be the extent of changes in the http protocol.

Darin, I sure appreciate your patience with me. I will begin on the Query
function as soon as I study up on XPCOM categories.

Comment 42

[Mike Kaply [:mkaply]]

Attachment: Complete diff including new files

Comment 43

[LeRoy Krueger]

(In reply to comment #42)
(In reply to comment #39)

Thanks Micheal,

The new attachment superceeds all prior attachments.

This attachment tries to isolate those changes described by Darin as priority
one in comment #39.

We have a single new interface for the core. nsIHttpActivityObserverService. I
used the service suffix because the access is via do_GetService if it is created
in nsHttpHandler::Init() by the call to NS_CreateServicesFromCategory().

I created multiple entry points in the new interface because the number of parms
vary depending upon the activity reported. I felt it might be more efficient
than using LL_ZERO or EmptyString().get() when the parms were not needed. Easy
to change back to a single function though.

The new interface also has readonly attribute active. That way if the interface
determines no extension is listening for http activity, the interface can report
active = PR_FALSE.

In nsHttpTransaction::Init() there is a test made for a valid interface. If the
interface is valid, then a test is made to see if the interface is active. If it
is active,  the observations are made, if it is not active, the interface is
reset to nsnull and no observations are made. This should result in minimal
performance impact to nsHttpTransaction when no one is interested in observing
activity.

Because the test is made in nsHttpTransaction::Init(), downstream observers can
come and go easily. Only when active returns true, will nsHttpTransport gather
parms for the activity observer.

The macros for the observations have been replaced in nsHttpTransaction with the
actual method calls. Makes it a bit easier to read.

Darin, is this more in line with your top priority? I would like to get this bit
right before moving on to priority 2.

Comment 44

[LeRoy Krueger]

Help!

I think I am stuck. When trying to implement a JavaScript component to field
calls from nsHttpTransport. Things go as expected until the web page does a
document.Write call. When that happens we get an error on the JavaScript console
like this: (I have gone a bit further than the posted patch.)

Error: [Exception... "'Permission denied to get property Object.observerActive'
when calling method: [nsIHttpActivityObserver::observerActive]"  nsresult:
"0x8057001e (NS_ERROR_XPC_JS_THREW_STRING)"  location: "JS frame ::
http://www.anandtech.com/ :: <TOP_LEVEL> :: line 102"  data: no]
Source File: http://www.anandtech.com/
Line: 102

At http://wiki.mozilla.org/Mozilla2:CAPSSecurity they explain that
document.Write performs with a web-script security context instead of system.

I tried to implement nsISecurityCheckedComponent in my JavaScript object but it
is never QIed.

Does anyone know a way around this problem? It shouldn't hurt if the activity
reporter is called with any security context.

Comment 45

[LeRoy Krueger]

(In reply to comment #44)

I resolved the problem. I tried to use \defaults\preferences\httpActivity.js
user_pref() to tell CAPS that nsIHttpActivityObserver had allAccess. That failed
silently. Now the JavaScript instance of the interface does this:

        var prefSvc = Components.classes["@mozilla.org/preferences;1"].
                        getService(nsIPrefService);
        if (prefSvc) {
            var prefs = prefSvc.getBranch("capability.policy");
            if (prefs) {
                try {
                   
prefs.setCharPref(".default.nsIHttpActivityObserver.observerActive.get",
"allAccess");
                   
prefs.setCharPref(".default.nsIHttpActivityObserver.observeActivity", "allAccess");
                } catch (e) {
                }
            }
        }

That works every time.

Comment 46

[Mike Kaply [:mkaply]]

Attachment: Ready for review

Comment 47

[LeRoy Krueger]

The Ready for review patch has a few revisions. I went back to a simpler
interface nsIHttpActivityObserver with a single call to report all activity and
an attribute to test for active observers. In nsHttpTransaction, LL_ZERO is
always used for the timestamp, LL_ZERO and EmptyCString() are used when the
ExtraData and ExtraString are not used. When building extensions, having a
single interface will be much more straightforward.

Comment 48

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver

This test extension test nsIHttpActivityObserver with JavaScript. 

nsHttpActivityObserver.js is a component that registers in the
http-startup-category. The component contains two objects, one is thread safe,
the other must run on the UI thread. The thread safe object is the one
registered.

When observerActivity() is called in the thread safe object, a timestamp is
added, and the UI thread object is called via proxy. 

When observerActivity() is called in the UI thread object,
nsIObserverService.enumerateObservers() is called for topic
'http-activity-observer'. The registered observers are called in one of two
ways.

If the registered observer implements nsIObserver, observe(aSubject, aTopic,
aExtra) is called. aSubject will be a nsISupports interface for the
nsIHttpChannel that generated the activity. aTopic will be
'http-activity-observer'. And aExtra will be a string in this form:

33 - nsIHttpActivityObserver::ACTIVITY_RESPONSE_HEADER
2005-10-04T13:50:37.109-4:00
HTTP/1.1 200 OK
Date: Tue, 04 Oct 2005 17:52:53 GMT
Server: Microsoft-IIS/5.0
X-Powered-By: ASP.NET
Cache-Control: private
Content-Length: 0
X-AspNet-Version: 1.1.4322

The first line will have a numeric correlationID and the activityID in text
form. The second line will be a timestamp in XML date format. Subsequent lines
will be either the extraData or extraString from
nsIHttpActivityObserver::observeActivity()

If the registered observer implements nsIHttpActivityObserver in addition to
nsIObserver, nsIHttpActivityObserver::observerActive will be tested, and if
true nsIHttpActivityObserver::observeActivity will be called instead of
nsIObserver:observe.

Any number of observers may register for topic 'http-activity-observer'. All
will be called on either nsIObserver or nsIHttpActivityObserver but not both.

To use this test extension. Install it by opening httpActivityObserver.xpi,
then reopen Firefox. 'Test nsIHttpActivityObserver' will appear on the 'Tools'
menu. Select 'Test nsIHttpActivityObserver' to write the observed http
activities to the JavaScript console.

Comment 49

[Mike Kaply [:mkaply]]

Attachment: LAtest patch

Comment 50

[LeRoy Krueger]

LAtest patch revisions, switched from using the CID to using the contract ID in
nsHttpTransaction. Removed CID from nsIHttpActivityObserver.h

Comment 51

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver with nsIMicroTimestamp

Test extension for LAtest patch. Adds nsIMicroTimestamp service, this binary
service is currently compiled for the WINNT_x86-msvc and Linux_x86-gcc3
platforms. The new service makes microsecond resolution timestamps available to
JavaScript programs on supported platforms.

This multipart .xpi installs three extensions:
    httpActivityObserverTest	 -- test interface
    httpActivityObserverService  -- nsIHttpActivityObserver distribution
    microTimestampService	 -- microsecond timestamp service

Comment 52

[Darin Fisher]

I'm sorry to say this, but I don't see myself having much time to review this
patch for FF 1.5.  We are already so late in the release cycle, that unless you
have advance approval from [e-mail] (and/or [e-mail]), I
think my time would be better spent on critical, stop-ship bugs.

Comment 53

[carglue a t ya hoo do tcom]

(In reply to comment #52)
> I'm sorry to say this, but I don't see myself having much time to review this
> patch for FF 1.5.

That's unfortunate, as this (substantial) effort was critical to a number of 
important pending projects that would have added significant overall value to 
FF for the 1.5 release.

Comment 54

[Darin Fisher]

David: Please talk to [e-mail] and [e-mail].  Ultimately,
they have to approve this; they are running this release.  The decision is not
up to me.

Comment 55

[LeRoy Krueger]

Here is a small risk analysis for the LAtest patch:

Risk 1: HTTP/HTTPS will stop working.

This patch does not modify the existing statements in any way, all of the
changes are additions. In the normal case, a call will be made to
do_GetService(NS_HTTPACTIVITYOBSERVER_CONTRACTID, &rv); in
nsHttpTransaction::Init(). On systems without an instance of
NS_HTTPACTIVITYOBSERVER_CONTRACTID, this call will fail, a test will be made for
success, if the
call fails, no further processing will take place.

Each of the six other additions to the code are within an if
(mHttpActivityObserver) statement that will be false in the normal case.

We have tested the LAtest patch on the WINNT_x86-msvc, Linux_x86-gcc3 and
Darwin_ppc-gcc3 platforms with no problems. 

Risk 2: HTTP/HTTPS will slow down.

In the normal case, a single call to
do_GetService(NS_HTTPACTIVITYOBSERVER_CONTRACTID, &rv); is made to for each
nsHttpTransaction. There are also six if (mHttpActivityObserver) tests made in
the operational parts of nsHttpTransaction. None of these additions should slow
down http activity perceptibly.

Risk 3: Problems with HTTP/HTTPS will develop when an extension implements
NS_HTTPACTIVITYOBSERVER_CONTRACTID

The user always has the option to uninstall the extension. 

Benefit 1: No sensed activities will be coalesced.

Benefit 2: An extension which implements NS_HTTPACTIVITYOBSERVER_CONTRACTID will
be called on the thread where the activity takes place, so no queuing needs to
take place before a timestamp can be applied to the activity. 

Benefit 3: The actual headers sent and received will be available to an
observer. Right now the actual response header is not available to an observer,
and getting the complete header requires the unsafe use of the
nsIHttpChannelInternal interface.

Comment 56

[Scott MacGregor]

Thanks a lot for this patch guys. It sounds really exciting and is something
we'd be interested in. 

Unfortunately, we are just days away from finishing up our critical stop ship
bugs for the 1.5 release and we just don't have time for new feature work
anymore. In the future, it's really useful to get these kinds of changes going
and checked in before our public betas  if you want it to make the release
train. This allows us to get testing and feedback from our testing community
before we release the final version of the product. You can track dates for our
product alphas and betas from the firefox roadmap page so you can plan feature
work around those dates in the future.

As cool as this stuff looks, our product isn't at a point in the software
release cycle where we can take this kind of change right now. Thanks for
understanding.

Comment 57

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver with nsIMicroTimestampService

Comment 58

[LeRoy Krueger]

Replaced the test extension for nsIHttpActivityObserver.

This extension includes the httpactivitydist extension which is a binary component that timestamps and distributes nsIHttpActiviyObserver::ObserveActivity method calls to registered observers on the UI thread.

The binary components are compiled for the WIN32-i686 Linux-i686 and OSX-ppc platforms.

A binary component was needed because the JavaScript distributor did not do well when the same interface was called from multiple threads.

Comment 59

[Darin Fisher]

My plan is to review this and get it in on the trunk ASAP.

Comment 60

[LeRoy Krueger]

Some questions for Darin,

The patch was prepared against the tree in October, some of the patch lines have moved, but the patch still works ok. Would you prefer to review a new patch taken against a more current trunk? I am confident your review will result in changes in any case.

Take a good look at the NS_HTTPACTIVITYOBSERVER_CONTRACTID please. I took a stab at a name, but you will probably have a better suggestion.

Please consider whether we should make the readonly attribute nsIHttpActivityObserver::observerActive [noscript] or not. I haven't come up with a good reason for JavaScript implementors to worry about this attribute that is needed in the binary distributor.

Please consider whether we should keep the inline style of the calls to nsIHttpActivityObserver::observeActivity() or create a new private method in nsHttpTransaction to do the actual call and optionally include logging for each call. 

Comment 61

[carglue a t ya hoo do tcom]

Referring back to Darin's comment #39 :

"Make #1 your priority.  Once we get that done and into the tree, then we go for #2.  If we run out of time for #2, or if it is considered too large of a change for 1.5, then you can always build #2 yourself and include it in your extension."

With the pressure of the FF 1.5 release over, wouldn't it be preferable to now consider also including the #2 portion of the functionality within Mozilla proper as originally envisioned, rather than requiring the use of a separate binary component .xpi install with its requisite 'select-your-platform' and maintenance-and-distribution issues that will haunt extension developers?

This is a really great new interface that opens up a whole new category of instrumentation options for extensions developers, and I'm really looking forward to seeing both parts included in an official FF release.

Comment 62

[Darin Fisher]

Comment on attachment 199840 [details] [diff] [review]
LAtest patch

>Index: public/nsIHttpActivityObserver.idl

>+/**
>+ * nsIHttpActivityObserver
>+ *
>+ * This interface provides a way for network activities to be reported
>+ * to registered observers. The interface is normally called through a
>+ * proxy because ReportActivity must execute on the UI thread and most
>+ * of the activities will take place on a socket thread
>+ */

This comment doesn't seem to be true.  The ReportActivity method is not
defined, and none of the methods on this interface are called via a proxy.
Nor, are the methods called on the UI thread.


>+[scriptable, uuid(412880C8-6C36-48d8-BF8F-84F91F892503)]
>+interface nsIHttpActivityObserver : nsISupports
>+{
>+    /**
>+     * observe activity from the http transport
>+     *
>+     * @parma aChannel

s/parma/param/


>+     *        nsISupports interface for the the channel that
>+     *        generated this activity

I think it would be better to pass the nsIHttpChannel.


>+     * @param aActivityID
>+     *        The id of this activity, will be one of
>+     *        nsISocketTransport::STATUS_RESOLVING
>+     *        nsISocketTransport::STATUS_CONNECTING_TO
>+     *        nsISocketTransport::STATUS_CONNECTED_TO
>+     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_HEADER
>+     *          extraString will contain the text of the header
>+     *        nsISocketTransport::STATUS_SENDING_TO
>+     *          extraData will contain the count of bytes sent
>+     *          there may be more than one of these
>+     *        nsISocketTransport::STATUS_WAITING_FOR
>+     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_BODY_SENT
>+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_START
>+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_HEADER
>+     *          extraString will contain the text of the header
>+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_COMPLETE
>+     *          extraData will contain the count of bytes received
>+     *        nsIHttpActivityObserver::ACTIVITY_TRANSACTION_CLOSE

I think it would be better to split this into two parameters:

1) aActivityType
2) aActivitySubtype

Then you could define an activity type of ACTIVITY_TRANSPORT_STATUS
that would pass the various nsISocketTransport-defined values via
the activity subtype param.  Something like that would be clearer to 
me.  I don't like munging socket transport status with the new
status codes defined here... especially since the set of socket 
transport status codes may grow over time, and it would be bad if
changes to the socket transport status codes conflicted with the
activity types defined on this interface.



>+     * @param aTimestamp
>+     *        microseconds past the epoch of Jan 1, 1970

This field seems to be unused.  I'm happy to keep it here since it
would be nice to generate timestamps in the future.  I'd almost
prefer if you passed a PRUint32 instead and populated it with the
value of PR_IntervalToMilliseconds(PR_IntervalNow()).  Then people
could compute deltas between activity events.  I know you were 
concerned about the reliability of the timer used by NSPR, but note
that the Window's implementation of PR_IntervalNow was recently
changed to use timeGetTime().  I think it should be reliable enough
for most consumers.  If you need more reliable timing in your 
extension, then I suggest that you just ignore the time value 
supplied by the HTTP implementation.


>+     * @param aExtraData
>+     *        Any extra numeric data optionally available with
>+     *        this activity
>+     * @param aExtraString
>+     *        Any extra string data optionally available with
>+     *        this activity

I'd prefer to have these parameters named "aExtraIntData" and
"aExtraStringData" since they are both forms of "data".


>+    /**
>+     * This attribute is true when this interface is active and should
>+     * observe http activities. When false, this interface should not 
>+     * be used.
>+     */
>+    readonly attribute boolean observerActive;

I think it would be better to call this "isActive".


>+    const unsigned long ACTIVITY_REQUEST_HEADER         = 0x5001;
>+    const unsigned long ACTIVITY_REQUEST_BODY_SENT      = 0x5002;
>+    const unsigned long ACTIVITY_RESPONSE_START         = 0x5003;
>+    const unsigned long ACTIVITY_RESPONSE_HEADER        = 0x5004;
>+    const unsigned long ACTIVITY_RESPONSE_COMPLETE      = 0x5005;
>+    const unsigned long ACTIVITY_TRANSACTION_CLOSE      = 0x5006;

Please document these constants here instead of in the comment block
above.  In the comment for observeActivity, just refer to the 
"ACTIVITY_ values defined below" or something like that.


>+%{C++
>+
>+#define NS_HTTPACTIVITYOBSERVER_TOPIC \
>+  "http-activity-observer"
>+
>+#define NS_HTTPACTIVITYOBSERVER_CONTRACTID \
>+  "@mozilla.org/netwerk/protocol/http/http-activity-observer;1"

I think it might be nice to use the new nsCategoryCache technique
of dispatching events to numerous instances instead of to a singleton
like this.  It is a new class designed to make this stuff easier.
Take a look at how it is used in nsIOService.cpp.  (You can punt on
doing this if you like.)



>Index: src/nsHttpTransaction.cpp

>+    mHttpActivityObserver = do_GetService(NS_HTTPACTIVITYOBSERVER_CONTRACTID, &rv);

s/mHttpActivityObserver/mActivityObserver/


I'm pretty much okay with the implementation.  Please note that I
don't promise to freeze this API.  It may change in the future, and
I hope that is okay with you.  Please let me know how important API
stability is for you.  Again, I'm really sorry for the delays in
reviewing this patch.

-Darin

Comment 63

[LeRoy Krueger]

Thanks Darin, 

I will get to work on your comments today. 

Comment 64

[LeRoy Krueger]

(In reply to comment #62)
Thanks again Darin, 

Here are my responses to your comments. I have a few questions so please fill me in where appropriate.

LeRoy

> (From update of attachment 199840 [details] [diff] [review] [edit])
> >Index: public/nsIHttpActivityObserver.idl
> 
> >+/**
> >+ * nsIHttpActivityObserver
> >+ *
> >+ * This interface provides a way for network activities to be reported
> >+ * to registered observers. The interface is normally called through a
> >+ * proxy because ReportActivity must execute on the UI thread and most
> >+ * of the activities will take place on a socket thread
> >+ */
> 
> This comment doesn't seem to be true.  The ReportActivity method is not
> defined, and none of the methods on this interface are called via a proxy.
> Nor, are the methods called on the UI thread.
> 
Yes, ReportActivity should be observeActivity.

This patch is based in large part on your comment #39 back in September of last year. What we have here is part 1 of a more complete solution.

There are really three pieces to this solution. An instrumentation piece that must be present in the HTTP protocol code base. A distribution piece that sits between the instrumentation and the consumers. And one or more consumers.

The instrumentation piece is the patch for this review. 

The distribution piece is planned as an extension right now, it handles the timestamping on the instrumentation thread then uses an asynchronous proxy for the user thread to notify all of the registered consumers of the activity. I could submit the distribution piece for inclusion in the base code, but it will need to have the alternate timestamp facilities as well. I think I would prefer to leave it as an extension until the Windows timestamps increment more often. The distribution piece is included in the Test extension from 2006-01-20 in binary form for Windows, Linux and OSX platforms.

The consumer pieces can be either binary or Javascript without restriction. Every consumer will see all the activities with the same timestamps. The consumers may perform extensive processing of the activities without slowing the http channel in any way. 

nsIHttpActivityObserver is designed so that it may be reused by the instrumentation, distribution and consumer pieces.

> 
> >+[scriptable, uuid(412880C8-6C36-48d8-BF8F-84F91F892503)]
> >+interface nsIHttpActivityObserver : nsISupports
> >+{
> >+    /**
> >+     * observe activity from the http transport
> >+     *
> >+     * @parma aChannel
> 
> s/parma/param/

done thanks!

> 
> 
> >+     *        nsISupports interface for the the channel that
> >+     *        generated this activity
> 
> I think it would be better to pass the nsIHttpChannel. 

It is the nsISupports for the nsIHttpChannel. Do you want the comment to change or should I change the param type from nsISupports to nsIHttpChannel? I found lots of precedent for passing nsISupports in cases like this, and the socket thread side of the distributor becomes a bit more efficient using nsISupports.

> 
> 
> >+     * @param aActivityID
> >+     *        The id of this activity, will be one of
> >+     *        nsISocketTransport::STATUS_RESOLVING
> >+     *        nsISocketTransport::STATUS_CONNECTING_TO
> >+     *        nsISocketTransport::STATUS_CONNECTED_TO
> >+     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_HEADER
> >+     *          extraString will contain the text of the header
> >+     *        nsISocketTransport::STATUS_SENDING_TO
> >+     *          extraData will contain the count of bytes sent
> >+     *          there may be more than one of these
> >+     *        nsISocketTransport::STATUS_WAITING_FOR
> >+     *        nsIHttpActivityObserver::ACTIVITY_REQUEST_BODY_SENT
> >+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_START
> >+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_HEADER
> >+     *          extraString will contain the text of the header
> >+     *        nsIHttpActivityObserver::ACTIVITY_RESPONSE_COMPLETE
> >+     *          extraData will contain the count of bytes received
> >+     *        nsIHttpActivityObserver::ACTIVITY_TRANSACTION_CLOSE
> 
> I think it would be better to split this into two parameters:
> 
> 1) aActivityType
> 2) aActivitySubtype
> 
> Then you could define an activity type of ACTIVITY_TRANSPORT_STATUS
> that would pass the various nsISocketTransport-defined values via
> the activity subtype param.  Something like that would be clearer to 
> me.  I don't like munging socket transport status with the new
> status codes defined here... especially since the set of socket 
> transport status codes may grow over time, and it would be bad if
> changes to the socket transport status codes conflicted with the
> activity types defined on this interface.
> 

Great idea, makes much more sense that way. 

> 
> 
> >+     * @param aTimestamp
> >+     *        microseconds past the epoch of Jan 1, 1970
> 
> This field seems to be unused.  I'm happy to keep it here since it
> would be nice to generate timestamps in the future.  I'd almost
> prefer if you passed a PRUint32 instead and populated it with the
> value of PR_IntervalToMilliseconds(PR_IntervalNow()).  Then people
> could compute deltas between activity events.  I know you were 
> concerned about the reliability of the timer used by NSPR, but note
> that the Window's implementation of PR_IntervalNow was recently
> changed to use timeGetTime().  I think it should be reliable enough
> for most consumers.  If you need more reliable timing in your 
> extension, then I suggest that you just ignore the time value 
> supplied by the HTTP implementation.
>

The timestamp is filled in by the distributor piece on the instrumentation thread. Any timestamp provided must be added on the instrumentation thread, any attempt to timestamp after a thread switch would be pretty inaccurate.

The timestamp service in the test extension does use PR_IntervalNow() to calculate a better timestamp on those platforms where the PR_IntervalNow() increments faster than PR_Now() but PR_IntervalNow() can roll as quickly as every 72 minutes, making it unsuitable for an activity timestamp.
 
> 
> >+     * @param aExtraData
> >+     *        Any extra numeric data optionally available with
> >+     *        this activity
> >+     * @param aExtraString
> >+     *        Any extra string data optionally available with
> >+     *        this activity
> 
> I'd prefer to have these parameters named "aExtraIntData" and
> "aExtraStringData" since they are both forms of "data".
> 

No problem, done

> 
> >+    /**
> >+     * This attribute is true when this interface is active and should
> >+     * observe http activities. When false, this interface should not 
> >+     * be used.
> >+     */
> >+    readonly attribute boolean observerActive;
> 
> I think it would be better to call this "isActive".
> 

No problem, done.

This method is there so that the distributor can tell the instrumentation that no one is listening. The instrumentation can then skip all calls to the distributor for that transaction. The concern is to keep the instrumentation from using any more resources than absolutely necessary on the socket threads. No one would like to slow things down on those threads.

> 
> >+    const unsigned long ACTIVITY_REQUEST_HEADER         = 0x5001;
> >+    const unsigned long ACTIVITY_REQUEST_BODY_SENT      = 0x5002;
> >+    const unsigned long ACTIVITY_RESPONSE_START         = 0x5003;
> >+    const unsigned long ACTIVITY_RESPONSE_HEADER        = 0x5004;
> >+    const unsigned long ACTIVITY_RESPONSE_COMPLETE      = 0x5005;
> >+    const unsigned long ACTIVITY_TRANSACTION_CLOSE      = 0x5006;
> 
> Please document these constants here instead of in the comment block
> above.  In the comment for observeActivity, just refer to the 
> "ACTIVITY_ values defined below" or something like that.
> 

Make sense, will be done with the aActivityType, aActivitySubtype changes

> 
> >+%{C++
> >+
> >+#define NS_HTTPACTIVITYOBSERVER_TOPIC \
> >+  "http-activity-observer"
> >+
> >+#define NS_HTTPACTIVITYOBSERVER_CONTRACTID \
> >+  "@mozilla.org/netwerk/protocol/http/http-activity-observer;1"
> 
> I think it might be nice to use the new nsCategoryCache technique
> of dispatching events to numerous instances instead of to a singleton
> like this.  It is a new class designed to make this stuff easier.
> Take a look at how it is used in nsIOService.cpp.  (You can punt on
> doing this if you like.)
> 

Nice technique, I had not noticed it before. I will keep it in mind, makes life simpler.

I don't think it would be right for this solution though. A single distributor is much preferred to many distributors. That way all of the timestamps for the same activity will match, and there will be less drag on the socket thread if only one distributor is acting on each activity.

> 
> 
> >Index: src/nsHttpTransaction.cpp
> 
> >+    mHttpActivityObserver = do_GetService(NS_HTTPACTIVITYOBSERVER_CONTRACTID, &rv);
> 
> s/mHttpActivityObserver/mActivityObserver/
> 

No problem

> 
> I'm pretty much okay with the implementation.  Please note that I
> don't promise to freeze this API.  It may change in the future, and
> I hope that is okay with you.  Please let me know how important API
> stability is for you.  Again, I'm really sorry for the delays in
> reviewing this patch.
> 

The interface does not need to be frozen... but it would be nice. For the present, David Wood and I will be doing the initial consumer pieces. What do you think David?

I knew you would have a number of ways to improve on my first effort, I am glad you were able to get to it. If we can answer the questions above, these changes should not take too long to implement in another patch and Test extension. 

> -Darin
> 

Comment 65

[carglue a t ya hoo do tcom]

(In reply to comment #64)
> The interface does not need to be frozen... but it would be nice. For the
> present, David Wood and I will be doing the initial consumer pieces. What do
> you think David?

This all looks great to me.  I think I'm already using quite a number of unfrozen interfaces at present anyway, so one more won't change too much.  As with the others, using unfrozens requires following each FF release carefully to ensure that any related changes are handled properly.

Comment 66

[Mike Kaply [:mkaply]]

Attachment: Patch addressing the comments

Comment 67

[LeRoy Krueger]

The latest review patch addresses Darins review comments and makes some other small improvements.

This patch has been tested on FF 1.5.0.1, FF 1.5.0.2, FF 1.5.0.3 with no problems.
I had a problem testing with Bon Echo alpha1 that I could not isolate, so I held off posting this patch. Bon Echo alpha2 testing presented no problems with this patch.

Comment 68

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver and nsIMicroTimestamp

This test extension includes the extension httpactivitydist. The extension includes executable binaries for Windows and Linux on x86 platforms. The binaries were created with the Firefox 1.5.0.3 source tree.

Source for httpactivitydist is included as well as JavaScript sample code for observing http activity.

The test extension installs an entry (Test nsIHttpActivityObserver) in the Tools menu. When Test nsIHttpActivityObserver is checked. Http activity observations in text form will be written to the JavaScript Console as you browse.

The extension has been tested with both Firefox 1.5.0.3 and Bon Echo alpha2 on Windows and Linux for x86 platforms. Binaries for other platforms may be created by compiling the httpactivitydist source code for that platform.

Comment 69

[Darin Fisher]

Comment on attachment 222388 [details] [diff] [review]
Patch addressing the comments

>Index: public/nsIHttpActivityObserver.idl
>+    /**
>+     * This attribute is true when this interface is active and should
>+     * observe http activities. When false, this interface should not 
>+     * be used. Assumed true for scripts.
>+     */
>+    [noscript] readonly attribute boolean isActive;

Why is this noscript?


>+
>+    const unsigned long ACTIVITY_TYPE_SOCKET_TRANSPORT     = 0x0001;
>+    const unsigned long ACTIVITY_TYPE_HTTP_TRANSACTION     = 0x0002;
>+    
>+    const unsigned long ACTIVITY_SUBTYPE_REQUEST_HEADER    = 0x5001;
>+    /*          
>+     *  aExtraStringData will contain the text of the header 
>+     */

This comment isn't very doxygen friendly.


r=darin

Comment 70

[LeRoy Krueger]

(In reply to comment #69)
> (From update of attachment 222388 [details] [diff] [review] [edit])
> >Index: public/nsIHttpActivityObserver.idl
> >+    /**
> >+     * This attribute is true when this interface is active and should
> >+     * observe http activities. When false, this interface should not 
> >+     * be used. Assumed true for scripts.
> >+     */
> >+    [noscript] readonly attribute boolean isActive;
> 
> Why is this noscript?
> 

Mostly for performance reasons. I am anticipating most if not all consumers of http activity observations to be JavaScript. In nsHttpTransaction::Init(), the initial setup of the http activity distributor, is a two step operation. The first step is do_GetService() for the distributor. The distributor extension will be installed in the system and do_GetService will succeed even when there are no consumers active. The next step is to query isActive() in the distributor. The distributor isActive() method is called once for every http transaction, so it should be as efficient as possible. I see two choices for the   isActive() method. 

One would involve iterating a list of all registered observers and calling isActive() in each observer until true is returned. If all observers returned false, the distributor would return false.

The way the distributor isActive() method is implemented is to get the count of registered observers, if the count is zero, false is returned, otherwise true is returned. Observers can easily control the flow of data by registering and unregistering themselves for observation.

Since the distributor will never call isActive() in the registered observers, there is no reason for them to implement the method. I found [noscript] to be cleaner than a comment that said 'Always return true, unless you are the distributor.'


> 
> >+
> >+    const unsigned long ACTIVITY_TYPE_SOCKET_TRANSPORT     = 0x0001;
> >+    const unsigned long ACTIVITY_TYPE_HTTP_TRANSACTION     = 0x0002;
> >+    
> >+    const unsigned long ACTIVITY_SUBTYPE_REQUEST_HEADER    = 0x5001;
> >+    /*          
> >+     *  aExtraStringData will contain the text of the header 
> >+     */
> 
> This comment isn't very doxygen friendly.
> 
> 
> r=darin
> 
Ok, sorry 'bout that. If I fix the comments will I need another review before a superreview?

Comment 71

[Darin Fisher]

I think those are implementation details.  If you are worried about the cost of calling isActive, then make your distributor smarter.  I don't think we should preclude the possibility of a script-based distributor.  Please remove the [noscript] restriction.

As for getting this checked-in, all that is required is that you post a revised patch for check-in.  I'll take it from there.  You don't need an additional SR, I can provide that.

Comment 72

[Mike Kaply [:mkaply]]

Attachment: Final patch

Comment 73

[LeRoy Krueger]

the Final patch has revised comments and [noscript] is removed from the isActive attribute.

I will post a new test extension and distributor on Monday. 

Comment 74

[Darin Fisher]

fixed-on-trunk

Comment 75

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver and httpactivitydist

This test extension with httpactivitydist has been tested on Linux and Windows for Firefox 1.5.0.3 and bon Echo alpha2 with no problems. Sample JavaScript is included for how to use nsIHttpActivityObserver. Source code has been included for the httpactivitydist extension. Binaries may be compiled for other platforms using the source.

When installed, this extension will add 'Test nsIHttpActivityObserver' to the 'Tools' menu. When checked, the test program will append text messages of http activities to the JavaScript Console. Open the JavaScript console to view the messages.

Comment 76

[Darin Fisher]

Comment on attachment 222669 [details] [diff] [review]
Final patch

a=darin for the 1.8 branch

Comment 77

[Darin Fisher]

I will land this shortly on the 1.8 branch.

Comment 78

[Darin Fisher]

fixed1.8.1

Comment 79

[LeRoy Krueger]

Attachment: Test extension for nsIHttpActivityObserver and httpactivitydist

The new attachment includes httpactivtydist.xpi whose binaries have changed.

The primary change is to the timestamp service on the Windows platform. The older version would see if the timestamp could be improved by using the interval timer. This proved to be more trouble than it was worth, so that logic was removed. PR_Now() is now used by default for timestamps on all platforms.

If the ibmts package, available from www.alphaworks.ibm.com is installed on a windows platform, it will be used to improve the resolution of timestamps. PR_Now() timestamps are updated about 64 times a second, ibmts will produce a true microsecond timestamp. The setup call needed for the ibmts package is not too obvious. It is best to unpack the package, open a command prompt, then switch to the unpack directory and enter this at the command prompt

"media\default\disk images\disk1\setup" ibmpdm

Remember to put in the quotes. This command will toggle ibmts support in and out. The ibmts package for Windows platforms is completely optional, but recommended. Single use licenses are currently available with no fee.

The binaries included in httpactivitydist.xpi are compiled with firefox-2.0-source.tar.bz2. Support for Windows, OS X Universal, Linux i686 and Linux x86_64 is provided by the included platform binaries.

If someone wishes to extend the binary support to other platforms, the source code for the binary is included in httpactivitydist.xpi

Please contact me at [e-mail] for instructions on creating platform specific binaries.

Comment 80

[carglue a t ya hoo do tcom]

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=488270
https://bugzilla.mozilla.org/show_bug.cgi?id=341702