My perilous undefined cookie in Heroku

Lately I've been working on a client-side encrypted password manager, built with React and Express, which you can play around with here.

The other day I came to the point where I felt it was time to deploy to Heroku. As usual, things were working fine in my local environment but everything crashed and burned once trying to run the app in prod. Debug time!!

What exactly was the problem? The app would build and start fine; however, whenever I would attempt to navigate to the app it would immediately crash - serving the standard 500 application error Heroku page. I immediately checked the app's logs and saw an error I hadn't previously seen:

/app/node_modules/express-session/session/session.js:59
  this.cookie.maxAge = this.cookie.originalMaxAge;

TypeError: Cannot read property 'originalMaxAge' of undefined
    at Session.resetMaxAge (/app/node_modules/express-session/session/ session.js:59:36)
    at Session.touch (/app/node_modules/express-session/session/ session.js:48:15)
    at ServerResponse.end (/app/node_modules/express-session/index.js:326:21)
    at Array.write (/app/node_modules/finalhandler/index.js:297:9)
    at listener (/app/node_modules/on-finished/index.js:169:15)
    at onFinish (/app/node_modules/on-finished/index.js:100:5)
    at callback (/app/node_modules/ee-first/index.js:55:10)
    at IncomingMessage.onevent (/app/node_modules/ee-first/index.js:93:5)
    at IncomingMessage.emit (events.js:203:15)
    at endReadableNT (_stream_readable.js:1145:12)
    at process._tickCallback (internal/process/next_tick.js:63:19)
npm ERR! code ELIFECYCLE
npm ERR! errno 1

this.cookie is undefined! How? What? When? WHY?

When I see a cookie error in this context, my mind goes directly to the common CORS, secure, and proxy trust pitfalls that are easy to fall into / not get quite right when working with session handling in Express. Thus I checked all such related code, changed it around, flipped booleans off and on, etc. But no dice...

Next I began to research the error to see if anyone else had ran into the same problem. I found some similar results but nothing quite the same. Further, most of the answers suggested playing around with CORS and the likes - a road I had already gone down quite exhaustively. In one post, a person stated that they had accidentally set the maxAge property of their cookie to a value that more or less expired immediately. I double-checked the value I had set in my server's config.js file:

export const {
  PORT = 4000,
  PROTO = 'http',
  HOST = 'localhost',
  DB_NAME = 'keySafeDB',
  DB_URI = 'mongodb://localhost:27017/keySafeDB',
  SESS_NAME = 'sessionId',
  SESS_SECRET = 'test-secret',
  SESS_LIFETIME = 1000 * 60 * 60
} = process.env;

Looked fine! But I was also setting SESS_LIFETIME as a config variable in Heroku's settings. So I checked there as well:

SESS_LIFETIME = 1000 * 60 * 60 * 24

That also looked fine! So what could it possibly be?? I decided to turn on express-session debugging to see if it would provide me with any useful info. Starting the app this time with DEBUG=express-session, the app also printed out this little gem:

express-session no SID sent, generating session

Okay, so not a whole lot of info there, but maybe I should dig into the source of express-session and see where that line is being printed out from, what the state of the app should be around that time, and how exactly the error itself ties into this context. Looking at express-session/index.js, I found the string here:

    // generate a session if the browser doesn't send a sessionID
    if (!req.sessionID) {
      debug('no SID sent, generating session');
      generate();
      next();
      return;
    }

Unfortunately, looking into the generate function didn't lead me to any new revelations. Since I was in the source already, I decided to also check out the origin of the error itself, in express-session/session/session.js but this also didn't open my eyes to anything groundbreaking.

So, I was at a lost. Since I had exhausted pretty much every possible point of error I could think of, I decided it was an appropriate time to ask around for help. I posted my plea in some Discord communities but unfortunately, since the error was seemingly so obscure, nobody had any real insight to offer.

So I decided I'd take my issue directly to the source itself and open a Github issue. I opened up the new issue form but stopped before writing. Something in me told me I should play around a liiiiittle bit more before taking such a drastic measure. Something I could still do, I thought, would be to remove some of the cookie-related config variables I had set in Heroku's settings and just use the ones I had hardcoded in the config.js file. After all, the app worked fine when using it locally and the main values that changed between environments were the values of these variables.

I started by deleting the config variable SESS_LIFETIME. I then attempted to open the app and......

....

it worked!

But why??! Was that really it the whole time?? The only difference between the SESS_LIFETIME value in the Heroku settings and in the local config.js file was the additional multiplication of 24, to get the cookie to last a day: 1000 * 60 * 60 * 24. Had I forgotten how to multiply and was actually fudging this equation completely? I set the value in the config.js file also to 1000 * 60 * 60 * 24 and re-deployed. The app still worked!! What?!!

I then reset the config variable in Heroku and the app went back to crashing immediately. So in the end this little config variable was the culprit all along! Ouch! And double ouch considering it wasn't even really necessary.

I checked out the Heroku docs and didn't find anything about restrictions on what a config variable value can contain. I also set the value to a simple integer and this also caused the application to crash. You would think this would be documented somewhere. Or maybe it's just well-known that Heroku's config variables can only be strings? If anyone has some insight there it would be appreciated!

But the main point of this article is to simply warn anyone that may be seeing a similar error - check out your config variables first! It might save you a few days (ahem.. I totally mean hours..) of unproductive troubleshooting :)