Random 500 - SequelizeDatabaseError: relation "XXX" does not exist

Hello,

We get random 500 errors (it appears and stays on for some times, from one refresh to multiple hours) due to Sequelize not finding an existing relation.

Expected behavior

Nothing happens, data loads correctly

Actual behavior

500 internal error

Failure Logs

[forest] 🌳🌳🌳  Unexpected error: relation "users" does not exist
SequelizeDatabaseError: relation "users" does not exist
    at Query.formatError (/home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:366:16)
    at /home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:72:18
    at bound (domain.js:427:14)
    at runBound (domain.js:440:12)
    at tryCatcher (/home/node/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/home/node/app/node_modules/bluebird/js/release/promise.js:512:31)
    at Promise._settlePromise (/home/node/app/node_modules/bluebird/js/release/promise.js:569:18)
    at Promise._settlePromise0 (/home/node/app/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/home/node/app/node_modules/bluebird/js/release/promise.js:690:18)
    at _drainQueueStep (/home/node/app/node_modules/bluebird/js/release/async.js:138:12)
    at _drainQueue (/home/node/app/node_modules/bluebird/js/release/async.js:131:9)
    at Async._drainQueues (/home/node/app/node_modules/bluebird/js/release/async.js:147:5)
    at Immediate.Async.drainQueues [as _onImmediate] (/home/node/app/node_modules/bluebird/js/release/async.js:17:14)
    at processImmediate (internal/timers.js:461:21)
    at process.topLevelDomainCallback (domain.js:138:15)
    at process.callbackTrampoline (internal/async_hooks.js:124:14)

Context

We recently upgraded from v4 to v5 and then v6 following the upgrade docs

Infos:

  • forest-express-sequelize Version: 6.6.3
  • Express Version: 4.17.1
  • Sequelize Version: 5.19.6
  • Database Dialect: Postgres
  • Database Version: 9.6
  • Project Name: Platform

Hi @cberez,

Thanks for reaching out!

Could you please share your model definitions that use users as a relation?

Thanks.

Hi @adriguy,

That would be 90% of our model, the thing is nothing changes between times where it works and times where it doesn’t and it happens on all forest tables / objects even on tables of objects not linked to users (although views not linked to users probably have associations to other objects that are linked to users)…

Here’s one of the model using users relation:

'use strict'

module.exports = (sequelize, DataTypes) => {
  let Order = sequelize.define('orders', {
    'state': {
      type: DataTypes.INTEGER,
      defaultValue: 1,
      allowNull: false
    },
    'subscription_id': {
      type: DataTypes.INTEGER,
      allowNull: false
    },
    // ... some other fields
  }, {
    tableName: 'orders',
    underscored: true,
    schema: 'invoice'
  })

  Order.associate = (models) => {
    Order.belongsTo(models.subscriptions, { foreignKey: 'subscription_id' })
    Order.belongsTo(models.users, {
      foreignKey: 'customer_id',
      targetKey: 'uuid',
      constraints: false,
      as: 'user'
    })
    // ... some other associations
  }

  return Order
}

Also I checked during the last failures and the table’s still there in DB

@cberez hum… :thinking: quite hard to tell what’s going on here with this information.

Could you please set NODE_ENV=development in your admin backend .env file?
And when the bug happens, could you give us the SQL request that causes this error?

Thanks!

@adriguy here’s the whole log with NODE_ENV=development set for two successive occurences:

OPTIONS /forest/users?fields%5Busers%5D=fullname%2Cemail%2Cgender%2Cbirthdate%2Cid&page%5Bnumber%5D=1&page%5Bsize%5D=50&searchExtended=0&sort=-createdAt&timezone=Europe%2FParis 204 0.229 ms - 0
Executing (default): SELECT "uuid", "id", "roles", "gender", "first_name", "last_name", "email", "email_verified_at", "password", "birthdate", "newsletters", "accepted_tos_at", "booking_steps", "created_at" AS "createdAt", "updated_at" AS "updatedAt" FROM "users" AS "users" ORDER BY "users"."created_at" DESC LIMIT 50 OFFSET 0; {
  plain: false,
  raw: false,
  logging: [Function: log],
  where: '',
  order: [ [ 'created_at', [Literal] ] ],
  offset: 0,
  limit: 50,
  hooks: true,
  rejectOnEmpty: false,
  originalAttributes: [
    'uuid',          'id',
    'roles',         'gender',
    'first_name',    'last_name',
    'email',         'email_verified_at',
    'password',      'birthdate',
    'newsletters',   'accepted_tos_at',
    'booking_steps', 'createdAt',
    'updatedAt'
  ],
  attributes: [
    'uuid',
    'id',
    'roles',
    'gender',
    'first_name',
    'last_name',
    'email',
    'email_verified_at',
    'password',
    'birthdate',
    'newsletters',
    'accepted_tos_at',
    'booking_steps',
    [ 'created_at', 'createdAt' ],
    [ 'updated_at', 'updatedAt' ]
  ],
  tableNames: [ 'users' ],
  type: 'SELECT',
  model: users
}
[forest] 🌳🌳🌳  Unexpected error: relation "users" does not exist
SequelizeDatabaseError: relation "users" does not exist
    at Query.formatError (/home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:366:16)
    at /home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:72:18
From previous event:
    at Query.run (/home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:64:23)
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:645:29
From previous event:
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:645:12
From previous event:
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:641:10
    at /home/node/app/node_modules/retry-as-promised/index.js:70:21
    at new Promise (<anonymous>)
    at retryAsPromised (/home/node/app/node_modules/retry-as-promised/index.js:60:10)
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:631:30
From previous event:
    at Sequelize.query (/home/node/app/node_modules/sequelize/lib/sequelize.js:580:23)
    at QueryInterface.select (/home/node/app/node_modules/sequelize/lib/query-interface.js:1121:27)
    at /home/node/app/node_modules/sequelize/lib/model.js:1756:34
    at bound (domain.js:427:14)
    at runBound (domain.js:440:12)
    at processImmediate (internal/timers.js:461:21)
    at process.topLevelDomainCallback (domain.js:138:15)
    at process.callbackTrampoline (internal/async_hooks.js:124:14)
From previous event:
    at Function.findAll (/home/node/app/node_modules/sequelize/lib/model.js:1754:8)
    at /home/node/app/node_modules/forest-express-sequelize/dist/services/resources-getter.js:167:20
OPTIONS /forest/users/count?fields%5Busers%5D=fullname%2Cemail%2Cgender%2Cbirthdate%2Cid&searchExtended=0&timezone=Europe%2FParis 204 0.278 ms - 0
Executing (default): SELECT count("users"."uuid") AS "count" FROM "users" AS "users"; {
  plain: true,
  raw: true,
  logging: [Function: log],
  where: '',
  hooks: true,
  dataType: INTEGER {
    options: {},
    _length: undefined,
    _zerofill: undefined,
    _decimals: undefined,
    _precision: undefined,
    _scale: undefined,
    _unsigned: undefined
  },
  includeIgnoreAttributes: false,
  limit: null,
  offset: null,
  order: null,
  attributes: [ [ [Fn], 'count' ] ],
  type: 'SELECT'
}
[forest] 🌳🌳🌳  Unexpected error: relation "users" does not exist
SequelizeDatabaseError: relation "users" does not exist
    at Query.formatError (/home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:366:16)
    at /home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:72:18
From previous event:
    at Query.run (/home/node/app/node_modules/sequelize/lib/dialects/postgres/query.js:64:23)
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:645:29
From previous event:
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:645:12
From previous event:
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:641:10
    at /home/node/app/node_modules/retry-as-promised/index.js:70:21
    at new Promise (<anonymous>)
    at retryAsPromised (/home/node/app/node_modules/retry-as-promised/index.js:60:10)
    at /home/node/app/node_modules/sequelize/lib/sequelize.js:631:30
From previous event:
    at Sequelize.query (/home/node/app/node_modules/sequelize/lib/sequelize.js:580:23)
    at QueryInterface.rawSelect (/home/node/app/node_modules/sequelize/lib/query-interface.js:1163:27)
    at Function.aggregate (/home/node/app/node_modules/sequelize/lib/model.js:1992:32)
    at /home/node/app/node_modules/sequelize/lib/model.js:2044:19
    at bound (domain.js:427:14)
    at runBound (domain.js:440:12)
    at processImmediate (internal/timers.js:461:21)
    at process.topLevelDomainCallback (domain.js:138:15)
    at process.callbackTrampoline (internal/async_hooks.js:124:14)
From previous event:
    at Function.count (/home/node/app/node_modules/sequelize/lib/model.js:2028:8)
    at /home/node/app/node_modules/forest-express-sequelize/dist/services/resources-getter.js:209:20

Hi @cberez,

Did you go further with this problem?
Does the SQL request from debug logs is running well if you try directly on the database?

Hi @Sliman_Medini

I didn’t specifically test this one but a select * from users limit 1; runs properly while we get the error in forest. Our users relation is in the public schema.

The problem is still happening randomly on our staging env. We’re deploying to preprod today and will check if it occurs too, if so no release to prod as it’s a huge issue for us. I’m also negotiating with the product team to lighten up a bit all the custom fields we have to see if it’s related to too many requests ran concurrently.

On the DB side, it’s running as a service on google cloud so no logs unfortunately… We suspected a DB call overload but then the message doesn’t make sense.

Regards,

Damn,

One maybe useless idea, but data are here when it works?
Don’t you have things like tests that will drop/recreate all the tables on the same database? Look weird I know.

I do not see other possible causes for now. I will ask my teammates.

Is this always on user, or the table is also random?

Thanks for the help @Sliman_Medini
It’s always on user table and we don’t touch the envs user tables in testing or other

We might have found a fix: the schema for this table (public) was defined by an env variable that was never set. We replaced it with a hardcoded "public" and now we don’t seem to have the error anymore…

I understand how sequelize might not set a schema by default but then I don’t know why it was working sometimes…

Ok,

Oh yes, perfect if it works for you, even if it stays weird.
Can you please point me to where did you hardcode “public”?

Many thanks

In the users schema definition:

module.exports = (sequelize, DataTypes) => {
  let User = sequelize.define('users', {
    // fields
  }, {
    tableName: 'users',
    underscored: true,
    schema: 'public', // <------------
  })
}