InformAction Forums

Posted: **Thu May 19, 2011 12:35 pm**

When the page is reloaded by pressing F5 or the refresh button next to the location bar, two HTTP requests are issued for localhost. This happens regardless of the whitelist settings, the next configurations are confirmed to cause issues:
- Whitelist localhost
- Whitelist localhost:8000
- Allow JS globally

I first saw this behavior in the Developer console of Fx4, but have isolated the issue to refreshing. I've tried a clean FF profile with all extensions disabled too, resulting in:
- NoScript disabled: expected result: / , /favicon.ico , /favicon.ico [refresh] , /
- NoScript enabled: actual result: / , /favicon.ico , /favicon.ico [refresh] , /, /
After further investigation, the bug occurs only if ABE is enabled

Browser: Firefox 4.0.1 (from Ubuntu Natty repository)
NoScript: 2.1.0.3
Not affected: Firefox 3.6.17 (from firefox.com), running on Ubuntu Lucid

Test case:
First discovered while using the SimpleHTTPServer module from Python:

Code: Select all

$ python -m SimpleHTTPServer
Serving HTTP on 0.0.0.0 port 8000 ...
localhost - - [19/May/2011 14:31:55] "GET / HTTP/1.1" 200 -
localhost - - [19/May/2011 14:31:55] code 404, message File not found
localhost - - [19/May/2011 14:31:55] "GET /favicon.ico HTTP/1.1" 404 -
localhost - - [19/May/2011 14:31:56] code 404, message File not found
localhost - - [19/May/2011 14:31:56] "GET /favicon.ico HTTP/1.1" 404 -
localhost - - [19/May/2011 14:31:59] "GET / HTTP/1.1" 200 -
localhost - - [19/May/2011 14:31:59] "GET / HTTP/1.1" 200 -

The last two lines come from one refresh action.

Using netcat (the HTTP response should be in the file named "response"):

Code: Select all

$ while [ -e response ]; do sudo nc -l -p 80 < response ;done

Two identical HTTP requests are send to the server.

Posted: **Thu May 19, 2011 12:42 pm**

Can you reproduce on 2.1.0.5 as well?

Posted: **Thu May 19, 2011 4:52 pm**

Yes, 2.1.0.5 is still affected.

Posted: **Thu May 19, 2011 5:41 pm**

Investigating, thanks.

Posted: **Tue May 24, 2011 8:25 pm**

I'm also experiencing this problem and it's not limited to accessing localhost URLs.

Firefox 4.0.1
NoScript 2.1.0.2 (Allow JS globally, ABE enabled)

In the FF4 Web Console, I can see the duplicate requests:

Code: Select all

[15:48:16.626] GET http://hazelnut:8000/company_invoices/Invoice.action?invoice.id=1338&read=true [undefined 16ms]
[15:48:16.650] GET http://hazelnut:8000/company_invoices/Invoice.action?invoice.id=1338&read=true [HTTP/1.1 200 OK 1656ms]

FF reports an "undefined" status code for the first request. However, in my web server logs, both requests have a 200 status code.

Posted: **Tue May 24, 2011 8:31 pm**

Does it happen on a clean profile with just NoScript installed and the web console off?

Posted: **Tue May 24, 2011 8:51 pm**

Yes, with a clean profile, NoScript installed, and the web console off, I still have the problem. If I disable NoScript, the problem goes away.

Not sure if this helps but I haven't observed the problem when accessing https URLs.

Posted: **Tue May 24, 2011 8:58 pm**

Also, the problem seems to be limited to refreshes of GET requests. POSTs appear to be unaffected.

Posted: **Tue May 24, 2011 9:04 pm**

SLED wrote:Also, the problem seems to be limited to refreshes of GET requests. POSTs appear to be unaffected.

I noticed strange behavior with the console and refresh under certain conditions. I'm not sure if NoScript had something to do with it, but I got a blank page using `python -m SimpleHTTPServer` as web server:
1. Open console using Ctrl + Shift + K
2. Enable registration of sent/received request headers
3. Press F5 or the refresh button
4. The page stays blank

Posted: **Tue May 24, 2011 9:08 pm**

Lekensteyn wrote:
SLED wrote:Also, the problem seems to be limited to refreshes of GET requests. POSTs appear to be unaffected.
I noticed strange behavior with the console and refresh under certain conditions. I'm not sure if NoScript had something to do with it, but I got a blank page using `python -m SimpleHTTPServer` as web server:
1. Open console using Ctrl + Shift + K
2. Enable registration of sent/received request headers
3. Press F5 or the refresh button
4. The page stays blank

Edit: I mispoke. It happens on Windows and Linux but only when I select "Log Request and Response Bodies".

Posted: **Thu May 26, 2011 1:28 pm**

Sorry, I couldn't reproduce.
Firefox 4.0.1, clean profile with NoScript 2.1.0.5, python SimpleHTTPServer

Tested on both Windows XP 64 and Ubuntu 10.0.4.

Posted: **Thu May 26, 2011 4:06 pm**

Thanks for looking into this Giorgio. Just to confirm, you tested either with localhost or on the LAN? Also, you're testing with refresh requests (F5 or refresh button)? The problem doesn't happen consistently so it may take many attempts before it occurs.

I looked into the code a bit and I think I've tracked down where the duplicate request originates from. In ABE.checkRequest() a call is made to this.deferIfNeeded(req). My particular request passes over the first if statement in deferIfNeeded() which deals with DNS and then IOUtil.runWhenPending(req.channel, <callback function>) is called. In the passed callback function, a replacement request is made:

Code: Select all

req.replace(false, null, function(replacement) {      

  ABE.log(host + " not cached in DNS, deferring ABE checks after DNS resolution for request " + req.serial);

  DNS.resolve(host, 0, function(dnsRecord) {
    replacement.open();
  });

});

This results in a channel replacement:

Code: Select all

new ChannelReplacement(this.channel, null, false).replace(null, <callback function>);

At this point, a duplicate channel is created and the old channel is passed to IOUtil.runWhenPending with the following callback function:

Code: Select all

function() {

  if (oldChan.status) return; // channel's doom had been already defined

  let ccl = new CtxCapturingListener(oldChan,

    function() {

      try {

        callback(self._replaceNow(isRedir, this))

      } catch (e) {

        self.dispose();

      }

    });

  self.loadGroup = oldChan.loadGroup;

  oldChan.loadGroup = null; // prevents the wheel from stopping spinning

  // this calls asyncAbort, which calls onStartRequest on our listener
  oldChan.cancel(NS_BINDING_REDIRECTED); 

}

It checks if the channel already has a status code. If it doesn't, oldChan.cancel() is called which presumably kills the channel.

This killing of the original channel is exactly what I'm seeing. The first request dies with a broken pipe and the second request finishes. Here is the output when I use python's SimpleHTTPServer:

Code: Select all

localhost - - [26/May/2011 11:32:29] "GET / HTTP/1.1" 200 -
----------------------------------------
Exception happened during processing of request from ('127.0.0.1', 45734)
Traceback (most recent call last):
  File "/usr/local/products/python/2.5.2/lib/python2.5/SocketServer.py", line 222, in handle_request
    self.process_request(request, client_address)
  File "/usr/local/products/python/2.5.2/lib/python2.5/SocketServer.py", line 241, in process_request
    self.finish_request(request, client_address)
  File "/usr/local/products/python/2.5.2/lib/python2.5/SocketServer.py", line 254, in finish_request
    self.RequestHandlerClass(request, client_address, self)
  File "/usr/local/products/python/2.5.2/lib/python2.5/SocketServer.py", line 522, in __init__
    self.handle()
  File "/usr/local/products/python/2.5.2/lib/python2.5/BaseHTTPServer.py", line 316, in handle
    self.handle_one_request()
  File "/usr/local/products/python/2.5.2/lib/python2.5/BaseHTTPServer.py", line 310, in handle_one_request
    method()
  File "/.auto_direct/_usr_local/products/python/2.5.2/lib/python2.5/SimpleHTTPServer.py", line 44, in do_GET
    f = self.send_head()
  File "/.auto_direct/_usr_local/products/python/2.5.2/lib/python2.5/SimpleHTTPServer.py", line 81, in send_head
    return self.list_directory(path)
  File "/.auto_direct/_usr_local/products/python/2.5.2/lib/python2.5/SimpleHTTPServer.py", line 134, in list_directory
    self.send_response(200)
  File "/usr/local/products/python/2.5.2/lib/python2.5/BaseHTTPServer.py", line 370, in send_response
    self.send_header('Server', self.version_string())
  File "/usr/local/products/python/2.5.2/lib/python2.5/BaseHTTPServer.py", line 376, in send_header
    self.wfile.write("%s: %s\r\n" % (keyword, value))
  File "/usr/local/products/python/2.5.2/lib/python2.5/socket.py", line 262, in write
    self.flush()
  File "/usr/local/products/python/2.5.2/lib/python2.5/socket.py", line 249, in flush
    self._sock.sendall(buffer)
error: (32, 'Broken pipe')
----------------------------------------
localhost - - [26/May/2011 11:32:29] "GET / HTTP/1.1" 200 -

The first request appears to be killed by the client resulting in a broken pipe. The second one completes. This also results in the "undefined" status code that appears in FF's Web Console (see my first post).

Can you look into this a bit further? I'm not really sure why the channel replacement needs to occur. In ABE.deferIfNeeded(), is the fact that I'm working on the LAN the cause of bypassing the first if statement dealing with DNS?

Any help is appreciated.

Posted: **Thu May 26, 2011 4:32 pm**

SLED wrote:Thanks for looking into this Giorgio. Just to confirm, you tested either with localhost or on the LAN?

I tried with both.

SLED wrote: Also, you're testing with refresh requests (F5 or refresh button)? The problem doesn't happen consistently so it may take many attempts before it occurs.

I tried with F5, refresh button and shift + refresh button.
The rationale behind this happening on refresh is that refresh clears the DNS cache, therefore ABE checks are deferred to wait for DNS resolution.
This is consistent with what you're observing, but on replacement the original channel should actually be cancelled before hitting the net (and that's what I am observing).

Are you sure you don't have any HTTP-observing machiner (such as the LiveHTTPHeaders or the built-in Firefox 4 web console) active when you try?

Posted: **Thu May 26, 2011 6:29 pm**

Giorgio Maone wrote:on replacement the original channel should actually be cancelled before hitting the net (and that's what I am observing).

I'm not sure that this is the case. The request seems to hit the net even before the channel is cloned. To check, I modified ABE.deferIfNeeded() as follows:

Code: Select all

  deferIfNeeded: function(req) {
    ....
    ....
    ....

        if (req.channel.name.indexOf('localhost:8050') > -1) {
          var start = new Date().getTime();
          for (var i = 0; i < 1e7; i++) {
            if ((new Date().getTime() - start) > 5000){
              break;
            }
          }
        }

        req.replace(false, null, function(replacement) {      
          ABE.log(host + " not cached in DNS, deferring ABE checks after DNS resolution for request " + req.serial);
          DNS.resolve(host, 0, function(dnsRecord) {
            replacement.open();
          });
        });

    ....
    ....
    ....
  },

The modification affects the execution of the callback function passed to runWhenPending(). It makes the thread wait 5 seconds before the call to req.replace() can execute while allowing the original call to deferIfNeeded() to complete. When run with this modification, the webserver receives the initial request almost immediately. 5 seconds later, the second request comes in:

Code: Select all

localhost - - [26/May/2011 13:58:12] "GET / HTTP/1.1" 200 -
localhost - - [26/May/2011 13:58:17] "GET / HTTP/1.1" 200 -

So I don't think that FF is waiting on anything in NoScript before sending off the initial request. If I'm misunderstanding this, please let me know. You definitely know more about this than I do.

Are you sure you don't have any HTTP-observing machiner (such as the LiveHTTPHeaders or the built-in Firefox 4 web console) active when you try?

The web console is not open and I have all extensions except NoScript disabled. The Java and Flash plugins are installed. I assume no other http observers remain. Is there any way to check?

Thanks for your help.

Posted: **Thu May 26, 2011 10:47 pm**

OK, I managed to reproduce it.
It seems to happen when Firefox's own DNS cache is empty or invalid and a DNS request is sent out.

I should have fixed in latest development build (RC10), could you confirm?

InformAction Forums

Two HTTP requests are issued for localhost on refresh in FF4

Two HTTP requests are issued for localhost on refresh in FF4

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in

Re: Two HTTP requests are issued for localhost on refresh in