Updating of a custom req.session property value does not seem to persist quick enough

Question

I have some Express middleware handling GET requests from my client side application to make subsequent requests to a separate API server that uses OAuth2 tokens, I am also using express-session for the storage of these tokens.

In my middleware that makes the outgoing request I have added handling to cope with occasions where an access token expires (API server sends back a 403) and makes a request to refresh the tokens, after which it will then issue the same original outgoing request to the API server, so the client is unaware of this all going on. The new tokens retrieved are then persisted back to the session store via express-session for use in subsequent requests. The tokens are also used for setting a Authorization bearer token header as you will see further below.

Here's the parts of my Express code that's involved:

routes.controller.js

//Currently handling GET API requests from client
module.exports.fetch = function(req, res) {
  var options = helpers.buildAPIRequestOptions(req);
  helpers.performOutgoingRequest(req, res, options);
};

helpers.js

module.exports.buildAPIRequestOptions = function(req, url) {
  var options = {};
  options.method = req.method;
  options.uri = 'http://someurl.com' + req.path;
  options.qs = req.query;
  options.headers = {
    'Authorization': 'Bearer ' + req.session.accessToken
  };
  return options;
};

module.exports.performOutgoingRequest = function(req, res, options) {
  request(options, function(err, response, body){
    if(response.statusCode === 401){
      console.log(chalk.red('\n--- 401 RESPONSE RECEIVED TRY REFRESHING TOKENS ---'));
      //Note the third param to call below is a callback and is invoked when calling next() in the refreshToken middleware
      authController.refreshToken(req, res, function(){
        console.log(chalk.green('\n--- RETRYING ORIGINAL REQUEST WITH UPDATED ACCESS TOKEN ---'));
        //Re-use original request options, but making sure we update the Authorization header beforehand
        options.headers.Authorization = 'Bearer ' + req.session.accessToken;
        retryOutgoingRequest(res, options);
      });
    } else {
      res.status(response.statusCode).send(body);
    }
  }); 
};

function retryOutgoingRequest(res, options) {
  request(options, function(err, response, body){
    if(err) {
      console.log(err);
    }
    res.status(response.statusCode).send(body);
  });
};

auth.controller.js

module.exports.refreshToken = function(req, res, next) {
  var formData = {
      grant_type: 'refresh_token',
      refresh_token: req.session.refreshToken
    },
    headers = {
      'Authorization' : 'Basic ' + consts.CLIENT_KEY_SECRET_BASE64
    };
  request.post({url:consts.ACCESS_TOKEN_REQUEST_URL, form:formData, headers: headers, rejectUnauthorized: false}, function(err, response, body){
    var responseBody = JSON.parse(body);
    if (response.statusCode === 200) {
      req.session.accessToken = responseBody.access_token;
      req.session.refreshToken = responseBody.refresh_token;
      next();
    } else {
      console.log(chalk.yellow('A problem occurred refreshing tokens, sending 401 HTTP response back to client...'));
      res.status(401).send();
    }
  });
};

For the most part the above is working just fine

When a user first log's in, some additional user profile info is fetched from the API server before they are taken to the main page of the application.

Some of the pages in the application also fetch data on page load, and so are subject to the access token checks.

During normal usage, so when a user logs in, and starts clicking around the pages, I can see the tokens are getting swapped out and saved in the session store via express-session as and when they expire. The new access token is correctly being used for subsequent requests as per the middleware I have written.

I now have a scenario where my middleware does not work.

So say I'm on a page that loads data on page load, lets say its an orders page. If I wait until the configured token expiry time on the API server has passed and then refresh the browser, the client side app will first make a request for the user info, and on success will then request the orders data required for the page (using AngularJS promises)

In my Express app the user info request gets a 403 from API server and so the tokens get refreshed via my middleware above, and the req.session.accessToken gets updated which I can see through console logging in my server application. But the next fetch of data for the orders ends up using the previously set access token and this causes a further unauthorised error from the API server since a request is being made with an invalid token.

If I refresh the browser again, both the user info and orders are fetched using the correct updated token from the previous middleware flow.

So I'm unsure what's going on here, I'm wondering if it's a timing issue with the req.session object not being persisted back to the session store in time for the next request to pick up?

Anyone got any ideas what may be going on here?

Thanks

Update 1

As requested in the comments, here are the request and response headers for the two requests being made.

First Request (which uses updated token server side)

Request Headers

GET /api/userinfo HTTP/1.1
Host: localhost:5000
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.94 Safari/537.36
Referer: https://localhost:5000/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-GB,en-US;q=0.8,en;q=0.6
Cookie: interact.sid=s%3A0NDG_bn67NeGQAYl1wP1-TmM19ExavFm.Zjv65e9BtSyNBuo%2FDxZEk2Np0963frVur4zHyYw3y5I

Response Headers

HTTP/1.1 200 OK
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
Strict-Transport-Security: max-age=86400
X-Download-Options: noopen
X-XSS-Protection: 1; mode=block
Content-Type: text/html; charset=utf-8
Content-Length: 364
ETag: W/"16c-4AIbpZmTm3I+Yl+SbZdirw"
set-cookie: interact.sid=s%3A0NDG_bn67NeGQAYl1wP1-TmM19ExavFm.Zjv65e9BtSyNBuo%2FDxZEk2Np0963frVur4zHyYw3y5I; Path=/; Expires=Fri, 13 May 2016 11:54:56 GMT; HttpOnly; Secure
Date: Fri, 13 May 2016 11:24:56 GMT
Connection: keep-alive

Second Request (which uses old token server side)

Request Headers

GET /api/customers HTTP/1.1
Host: localhost:5000
Connection: keep-alive
Accept: application/json, text/plain, */*
User-Agent: Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/50.0.2661.94 Safari/537.36
Referer: https://localhost:5000/
Accept-Encoding: gzip, deflate, sdch
Accept-Language: en-GB,en-US;q=0.8,en;q=0.6
Cookie: interact.sid=s%3A0NDG_bn67NeGQAYl1wP1-TmM19ExavFm.Zjv65e9BtSyNBuo%2FDxZEk2Np0963frVur4zHyYw3y5I

Response Headers

HTTP/1.1 401 Unauthorized
X-Content-Type-Options: nosniff
X-Frame-Options: SAMEORIGIN
Strict-Transport-Security: max-age=86400
X-Download-Options: noopen
X-XSS-Protection: 1; mode=block
set-cookie: interact.sid=s%3A0NDG_bn67NeGQAYl1wP1-TmM19ExavFm.Zjv65e9BtSyNBuo%2FDxZEk2Np0963frVur4zHyYw3y5I; Path=/; Expires=Fri, 13 May 2016 11:54:56 GMT; HttpOnly; Secure
Date: Fri, 13 May 2016 11:24:56 GMT
Connection: keep-alive
Content-Length: 0

Update 2

I should also mention I am using connect-mongo for my session store, I have tried using the default memory store but the same behaviour exists.

Answer 1

it sounds like a race condition client side, if you are performing 2 requests (to check auth - and then get data) is the second (get data) nested into the first calls success? or are you calling both at the same time linearly?

my thought is:

client - sends user info request (sessionid 1) - server processing

client - gets order info request (sessionid 1) - server processing

server - responds user info - 403 - client updates session id

server - responds order info - 403

really what you want is:

client - sends user info request (session 1) - server processing

server - gets user info request (403) - client updates session id

client - gets order info request (session 2) - server processing

server - respondes order info - actual results