599725 - web console reports data which the server did not send (304 Not Modified)

Status: VERIFIED FIXED

(DevTools :: General, defect, P2)

Description

[Stefan]

User-Agent:       Mozilla/5.0 (X11; Linux x86_64; rv:2.0b7pre) Gecko/20100101 Firefox/4.0b7pre
Build Identifier: Mozilla/5.0 (X11; Linux x86_64; rv:2.0b7pre) Gecko/20100101 Firefox/4.0b7pre

In the 304 (Not Modified) case the web console reports "Response Headers" which the server did not sent in its response to the request.

Reproducible: Always

Steps to Reproduce:
1. load http://www.heise.de/imgs/02/5/7/4/6/7/9/7b8c4e77d197c9bf.jpeg
2. open web console
3. press reload
4. click at the entry in the log
Actual Results:  
web console reports "Response Headers":

Accept-Ranges:bytes
Content-Length:7608
Content-Type:image/jpeg
Date:Sun, 26 Sep 2010 13:23:06 GMT
Last-Modified:Sat, 25 Sep 2010 16:48:31 GMT
Server:Apache

Expected Results:  
Report only these headers which the server actually sent:

<HTTP/1.1 304 Not Modified>
<Date: Sun, 26 Sep 2010 13:23:06 GMT>
<Server: Apache>
<Connection: close>

Comment 1

[Rob Campbell [:rc] (:robcee)]

I'm getting a 404 response for that URL now.

In any case, you're seeing the original headers from the request stored along with the cached response body. We need to keep those headers around to know when to expire the cached item. You can also so those headers in about:cache.

not a bug.

Comment 2

[Rob Campbell [:rc] (:robcee)]

(In reply to comment #1)
> ... You can also so* those headers in about:cache.

*see

Comment 3

[Stefan]

Take this image which is still available:

http://www.heise.de/icons/ho/heise_online_logo.gif

My proxy reports that only these response headers are sent over the network:

<HTTP/1.1 304 Not Modified>
<Date: Mon, 08 Nov 2010 14:41:20 GMT>
<Server: Apache>
<Connection: close>

while the web console says (let me quote the window title: "Inspect Network Request"):

Accept-Ranges:bytes
Content-Length:3416
Content-Type:image/gif
Date:Mon, 08 Nov 2010 14:41:20 GMT
Last-Modified:Sat, 26 Dec 2009 14:00:00 GMT
Server:Apache

Since the program does not deliver what it says it's self-evidently a bug. It delivers in part cached information and sells them under the label "fresh from the network". 

Aside from that the bug renders the use of the web console useless when debugginng 304 related errors since one can't tell which information is from the actual server response.

Comment 4

[Kevin Dangoor]

I agree. At the very least, it should indicate that the response headers are from the cache, but it would be more useful to show the actual headers sent from the server.

Comment 5

[Kevin Dangoor]

mass change: filter on PRIORITYSETTING

Comment 6

[Mihai Sucan [:msucan]]

Problem investigated:

- Firebug 1.5.4 in Firefox 3.6 has the same bug.

- There are no obvious issues with the Web Console code. We get the headers from the nsIHttpChannel/nsIRequest. We don't pick and choose - it's all raw there. (or it is supposed to be).

- The Live HTTP Headers 0.16 extension in Firefox 3.6 shows the response headers correctly. Inspecting the source code shows no obvious technical differences. It takes the nsIHttpChannel and uses the available visitResponseHeaders() method, just like the Web Console does.

There's only one nice catch: we use the nsIHttpActivityDistributor, while the Live HTTP Headers extension uses the nsIObserver service, to listen for the http-on-examine-response topic. It gets the subject (the nsIHttpChannel) which gives access to the headers, and so on.

We set an nsIStreamListener (our ResponseListener object) on the nsIHttpChannel (QI to nsITraceableChannel). We check for available response headers in OnDataAvailable() and OnStopRequest().

At the moment, I have a hacked, "debug quality" (ugly code), HUDService which uses the nsIObserver, and it works - it is able to read the real response headers. However, it does not yet tie into the network panel code, because the activity distributor only signals that the request starts *after* the nsIObserver sends notification for http-on-examine-response. (no httpActivity object in openRequests). I believe I can work around this issue, nonetheless.

Do you guys have better ideas than adding yet another observer? I'll prepare a patch that's actually usable, and we can further the discussion then.

(It seems to me like this would be a "Gecko bug", because it never says we get different headers when we use the nsIHttpActivityDistributor.)

Comment 7

[Mihai Sucan [:msucan]]

Attachment: proposed patch

Proposed patch. This adds a new observer for http-on-examine-response. This observer stores the HTTP response headers, that can be used by the other network panel code.

Directly storing the headers in openRequests (in httpActivity objects stored there), did not work, because for some reason http-on-examine-response is "almost" simultaneously ran while the other HTTP activity observer runs. Both cannot see changes made to the object from the other observer. I was forced to use a separate object where I can store the response headers, and I was also forced to read them at the end of the request (onStopRequest), otherwise it would have been "too early" (the response headers object would not visible earlier).

The fix is not too ugly, but it's somehow unfortunate we have to use an additional observer.

The mochitest case does pretty much the same as the STR of this bug. It opens a page, which has 200 OK, then reload to get 304 Not Modified (with different headers). I was glad to see that such important network code changes did not break old tests.

Looking forward to your feedback. Thanks!

Comment 8

[Rob Campbell [:rc] (:robcee)]

Comment on attachment 493504 [details] [diff] [review]
proposed patch

+    // This is used to find the correct HTTP response headers.
+    this.httpResponseExaminer = {
+      observe: function (aSubject, aTopic)

You don't need to create a separate observe function within the httpResponseExaminer object. Just make httpResponseExaminer the function and pass it to your addObserver call.

Not super keen on the additional observer, but this looks like it would do the job.

I'm wondering if it's possible to poll the cache in our onClick handler for http response objects and get the real header when we open the network inspector instead?

Comment 9

[Mihai Sucan [:msucan]]

(In reply to comment #8)
> Comment on attachment 493504 [details] [diff] [review]
> proposed patch
> 
> +    // This is used to find the correct HTTP response headers.
> +    this.httpResponseExaminer = {
> +      observe: function (aSubject, aTopic)
> 
> You don't need to create a separate observe function within the
> httpResponseExaminer object. Just make httpResponseExaminer the function and
> pass it to your addObserver call.

Ah, yeah. I'll update the patch.

> I'm wondering if it's possible to poll the cache in our onClick handler for
> http response objects and get the real header when we open the network
> inspector instead?

Thought of that as well. If we try to call visitResponseHeaders() too early or too late we get an exception (NOT AVAILABLE). We can only do it in onDataAvailable and onStopRequest. In both places we get cached headers, no the real ones.

I only know of http-on-examine-response, from the Live HTTP Headers extension, and this, based on testing, really gives us the real HTTP headers. If we want a different solution, I think we need to ping someone from the platform. Please CC someone accordingly.

Thanks!

Comment 10

[Mihai Sucan [:msucan]]

Attachment: patch update 2

Updated the patch as requested. Thanks for looking into it, Robert!

Comment 11

[Rob Campbell [:rc] (:robcee)]

(In reply to comment #9)
> (In reply to comment #8)
> > Comment on attachment 493504 [details] [diff] [review] [details]
> > I'm wondering if it's possible to poll the cache in our onClick handler for
> > http response objects and get the real header when we open the network
> > inspector instead?
> 
> Thought of that as well. If we try to call visitResponseHeaders() too early or
> too late we get an exception (NOT AVAILABLE). We can only do it in
> onDataAvailable and onStopRequest. In both places we get cached headers, no the
> real ones.

Was hoping that would work, but it was a long shot. f+!

Comment 12

[Mihai Sucan [:msucan]]

Comment on attachment 494402 [details] [diff] [review]
patch update 2

Thanks for the feedback+! Asking for review.

Comment 13

[Mihai Sucan [:msucan]]

For reference: I reported bug 615936 about the nsIHttpActivityObserver not giving us the uncached HTTP response headers, as we were expecting.

Comment 14

[Patrick Walton (:pcwalton)]

Doesn't apply; could you update when you get a chance? Sorry I didn't get to this sooner.

Comment 15

[Mihai Sucan [:msucan]]

Attachment: patch update 3

Patch rebased.

Comment 16

[Patrick Walton (:pcwalton)]

This is the fix for bug 606055, which is a nasty hard blocker.

Comment 17

[Patrick Walton (:pcwalton)]

Changing the whiteboard to hard blocker. We really need a review on this.

Comment 18

[Justin Dolske [:Dolske]]

Comment on attachment 502028 [details] [diff] [review]
patch update 3

Looks fine, but I'm mostly leaning on pwalton's review to have caught any nitpicky things.

Comment 19

[David Dahl :ddahl]

http://hg.mozilla.org/mozilla-central/rev/635f0075c184

Comment 20

[Geo Mealer [:geo] -- This account is inactive after 2015-07-07]

Verified fixed on Mozilla/5.0 (Windows NT 6.1; WOW64; rv:2.0b10) Gecko/20100101 Firefox/4.0b10 ID:20110121161358