Receiving 2 HTTP requests on the server when only 1 sent

Question

I am creating an app and using http://c9.io environment to develop it. It is a NodeJS app, which provides some REST endpoints for the client side application to query. Till now, everything was running fine, and today what I observe is that for 1 call sent by the browser to the REST API, 2 requests are being shown as received, and the request handler is being called 2 times. This has slowed the response time for one request.

In Chrome developer tools, it shows only one request sent, however, I am using app.use() to log incoming requests in Express and it prints the same 2 times for each request. Also, the handler is called twice.

This is happening intermittently, not every time. I am behind a corporate network. As I have sent a lot of requests in the day for testing, is there any chance that a monitoring program is sending the requests since it finds it suspicious? I have not edited the code that handles the requests.

Edit: Adding the code for handlers as suggested.

app.get('/suggestions/:keyword', function(r, s) {
    sug_db.retrieveSuggestions(r.params.keyword, function(data) {
        s.writeHead(200, {'content-type': 'text/html'});
        s.write(renderSugg({data: data}))
        s.end();
    });
});

app.get('/search/:query', function(r, s) {
    esc_db.search(r.params.query, function(data) {
        s.send(renderResults({query: r.params.query, results:data}));
    });
});

As you can see, they do nothing but get some data from a database and return the result as HTTP response. The templating engine I am using is Pug (formerly Jade)

https://developer.mozilla.org/en-US/docs/Web/HTTP/Access_control_CORS#Preflighted_requests — Dark Falcon, Sep 20 '16 at 12:24
It is not a CORS call. Also, if it was sent by the browser, it would show up in the Inspector right? — aditya_medhe, Sep 20 '16 at 12:26
@aditya_m Yes, CORS request would show up in inspector. Also, it would be an OPTION request which probably wouldn't be handled by the same handler. It's hard to say anything without seeing your handler code. — rsp, Sep 20 '16 at 12:33
Have added the code in the edit. But please note that I did not change this code before the problem started occuring — aditya_medhe, Sep 20 '16 at 12:42

score 1 · Answer 1 · answered Sep 20 '16 at 12:53

It doesn't look like that code that you included in the question can be guilty of running twice. But maybe some code in sug_db.retrieveSuggestions or esc_db.search does that.

What I would do is this:

Add some logging inside the code that you provided, both before calling the functions and inside the callback:

app.get('/suggestions/:keyword', function(r, s) {
    console.log('*** GET /suggestions/:keyword handler');
    sug_db.retrieveSuggestions(r.params.keyword, function(data) {
        console.log('GET /suggestions/:keyword callback');
        s.writeHead(200, {'content-type': 'text/html'});
        s.write(renderSugg({data: data}))
        s.end();
    });
});

app.get('/search/:query', function(r, s) {
    console.log('*** GET /search/:query handler');
    esc_db.search(r.params.query, function(data) {
        console.log('GET /search/:query callback');
        s.send(renderResults({query: r.params.query, results:data}));
    });
});

(or change console.log to whatever method of logging you use). I would see what is actually called twice - the handlers themselves, or the callbacks, or none. Next would be examination of the functions that are actually called by the handlers:

sug_db.retrieveSuggestions()
esc_db.search()
renderSugg()
renderResults()

It's important to see what is actually called twice and then examine why it can be happening. But it can happen if, for example, you do something like:

function badFunction(data, callback) {
  if (something) {
    callback('error');
  }
  callback('ok');
}

instead of:

function goodFunction(data, callback) {
  if (something) {
    callback('error');
  } else {
    callback('ok');
  }
}

I would expect that the functions that are called from the handlers could do something like that to call the callback twice - and maybe the condition or error that they checking didn't happen before but happens now, causing the change in behavior.

Yes, I added `console.log` to the request handlers themselves, and they are being called twice. But the point is that even `app.use()` middleware that I am using to log every request, is showing 2 requests. Since it is executing before all this code, the problem lies somewhere way too early before control reaches this code right? — aditya_medhe, Sep 20 '16 at 12:58
@aditya_m Right. It seems like that's something before this code is reached. Maybe indeed there are 2 network requests being sent. Or maybe your logging is being run twice. It's hard to say. There's nothing really that I can advice other than adding a lot of console.log lines to your code and to maybe use tcpdump or something to see if the requests are double on the network or only in your app. You could also write a simple mockup application that always returns some test data to both of those endpoints and see if it will be run twice as well. Very strange problem. — rsp, Sep 20 '16 at 14:19
the very nature of this problem and it's occurrence pattern (occurring at the end of the day, after many requests have been run successfully) points me towards some monitoring software that's checking the server by sending a duplicate request. (As I said, I'm behind a highly protected corporate network). Will get the IP address of the client and log it to see from which system the other request is coming from. That'll surely give a clue. Will update this thread if I find anything... — aditya_medhe, Sep 20 '16 at 14:27
I just reached home and tried again. Bang!! It works as usual, at a lightning speed. I think it's the corp network that's the culprit — aditya_medhe, Sep 20 '16 at 15:03

Receiving 2 HTTP requests on the server when only 1 sent

1 Answers1