Search code examples
node.jsherokuheroku-postgres

Heroku dyno no longer starting after automated Postgres maintenance


This app has been running without issue for over a year through multiple updates to both the Node application as well as the Postgres database. Last night an automated Postgres maintenance was run by Heroku, but we never got the all-clear. This morning we discovered that every http request has been returning an error since the maintenance began.

Deploying the repository to trigger a rebuild works without any build issues. The build completes successfully. Afterwards the logs say:

2021-09-27T16:23:02.205937+00:00 heroku[web.1]: State changed from starting to stopping
2021-09-27T16:23:32.815614+00:00 heroku[web.1]: State changed from stopping to down
2021-09-27T16:23:33.403629+00:00 heroku[web.1]: State changed from provisioning to starting

Failed requests to the API show this message in the logs:

2021-09-27T16:23:18.547267+00:00 heroku[router]: at=error code=H10 desc="App crashed" method=GET path="/" host=*** request_id=*** fwd="" dyno= connect=0ms service=0ms status=503 bytes=561 protocol=http tls_version=tls1.3

While nothing has changed in the logic from when this was working properly, I did check everything related to error code H10 that I could find. This is using a standard express generator ./bin/www file which seems to properly account for everything needed there. Contents for that file are:

#!/usr/bin/env node

/**
 * Module dependencies.
 */

var app = require('../app');
var debug = require('debug')('***:server');
var http = require('http');

/**
 * Get port from environment and store in Express.
 */
var port = normalizePort(process.env.PORT || '3000');
app.set('port', port);

/**
 * Create HTTP server.
 */

var server = http.createServer(app);

/**
 * Listen on provided port, on all network interfaces.
 */

server.listen(port);
server.on('error', onError);
server.on('listening', onListening);

/**
 * Normalize a port into a number, string, or false.
 */

function normalizePort(val) {
  var port = parseInt(val, 10);

  if (isNaN(port)) {
    // named pipe
    return val;
  }

  if (port >= 0) {
    // port number
    return port;
  }

  return false;
}

/**
 * Event listener for HTTP server "error" event.
 */

function onError(error) {
  if (error.syscall !== 'listen') {
    throw error;
  }

  var bind = typeof port === 'string'
    ? 'Pipe ' + port
    : 'Port ' + port;

  // handle specific listen errors with friendly messages
  switch (error.code) {
    case 'EACCES':
      console.error(bind + ' requires elevated privileges');
      process.exit(1);
      break;
    case 'EADDRINUSE':
      console.error(bind + ' is already in use');
      process.exit(1);
      break;
    default:
      throw error;
  }
}

/**
 * Event listener for HTTP server "listening" event.
 */

function onListening() {
  var addr = server.address();
  var bind = typeof addr === 'string'
    ? 'pipe ' + addr
    : 'port ' + addr.port;
  debug('Listening on ' + bind);
}

What could be causing this to start happening after a DB maintenance window? What steps can I take to try to get more useful information to troubleshoot?


Solution

  • I eventually received a response from Heroku support telling me to run heroku ps:stop web.1 -a *** because stop causes the dyno to be replaced on a new host. I had restarted the app many times throughout the day, but that apparently doesn't trigger the reprovisioning.