balderdashy / sails

Realtime MVC Framework for Node.js
https://sailsjs.com
MIT License
22.84k stars 1.95k forks source link

Connection error when using PostgreSQL transactions #4573

Open maximovicd opened 5 years ago

maximovicd commented 5 years ago

Sails version: 1.1.0 Node version: 8.10.0 NPM version: 4.6.1 DB adapter name: sails-postgresql DB adapter version: 1.0.1 Operating system: Windows 10


I am getting the following error when using the transactions given in an example:

"sendNativeQuery failed ("badConnection"). The provided connection is not valid or no longer active. Are you sure it was obtained by calling this driver's getConnection() method?"

I'm using the following code:

await sails.getDatastore()
  .transaction(async (db) => {
    const createdEntity = await Entity.create({ name: 'test' }).usingConnection(db);
    const foundEntity = await Entity.findOne({ id: createdEntity.id }).usingConnection(db);   
  })

The call to findOne fails with the above message. Is there a known issue with PostgreSQL transactions?

sailsbot commented 5 years ago

@maximovicd Thanks for posting, we'll take a look as soon as possible.


For help with questions about Sails, click here. If you’re interested in hiring @sailsbot and her minions in Austin, click here.

rachaelshaw commented 5 years ago

@maximovicd two things I noticed in that example: 1) Was there anything more to the error message? (Maybe above the error you posted)? If so, that would be helpful in diagnosing what's going on, e.g. if there are issues with your app's default datastore configuration. 2) In that example, createdEntity will be undefined unless you chain on .fetch() after the call to .create():

const createdEntity = await Entity.create({ name: 'test' }).fetch().usingConnection(db);

Hope this helps a bit! Please let us know if you are still having issues and have more of the error message to share

maximovicd commented 5 years ago

Hey Rachael,

Thanks for answering.

This is the full error object I get on error:

{ AdapterError: Unexpected error from database adapter: Internal error occurred while running select. (See .raw for more information.) at Object.findOne (.\api\services/MyService.js:21:39) at tryCatch (.\node_modules\regenerator-runtime\runtime.js:62:40) at Generator.invoke [as _invoke] (.\node_modules\regenerator-runtime\runtime.js:288:22) at Generator.prototype.(anonymous function) [as next] (.\node_modules\regenerator-runtime\runtime.js:114:21) at asyncGeneratorStep (.\api\services\MyService.js:23:103) at _next (.\api\services\MyService.js:25:194) at cause: { AdapterError: Unexpected error from database adapter: Internal error occurred while running select. (See .raw for more information.) at Object.findOne (.\api\services/MyService.js:21:39) at tryCatch (.\node_modules\regenerator-runtime\runtime.js:62:40) at Generator.invoke [as _invoke] (.\node_modules\regenerator-runtime\runtime.js:288:22) at Generator.prototype.(anonymous function) [as next] (.\node_modules\regenerator-runtime\runtime.js:114:21) at asyncGeneratorStep (.\api\services\MyService.js:23:103) at _next (.\api\services\MyService.js:25:194) at name: 'AdapterError', adapterMethodName: 'find', modelIdentity: 'mailinglist', raw: { Error: Internal error occurred while running select. (See .raw for more information.) at Object.find (.\node_modules\sails-postgresql\lib\adapter.js:183:15) at _getPopulatedRecords (.\node_modules\waterline\lib\waterline\utils\query\help-find.js:145:21) at helpFind (.\node_modules\waterline\lib\waterline\utils\query\help-find.js:582:6) at _afterPotentiallyRunningBeforeLC (.\node_modules\waterline\lib\waterline\methods\find-one.js:265:9) at _maybeRunBeforeLC (.\nodemodules\waterline\lib\waterline\methods\find-one.js:239:16) at Deferred..extend._WLModel [as _handleExec] (.\node_modules\waterline\lib\waterline\methods\find-one.js:241:9) at Deferred.exec (.\node_modules\parley\lib\private\Deferred.js:286:10) at Deferred.tryCatcher (.\node_modules\parley\node_modules\bluebird\js\release\util.js:11:23) at ret (eval at makeNodePromisifiedEval (.\node_modules\parley\node_modules\bluebird\js\release\promisify.js:184:12), :14:23) at Deferred.toPromise (.\node_modules\parley\lib\private\Deferred.js:572:19) at Deferred.then (.\node_modules\parley\lib\private\Deferred.js:431:22) name: 'Error', code: 'E_INTERNAL_ERROR', raw: [Object] } }, isOperational: true, adapterMethodName: 'find', modelIdentity: 'mailinglist', raw: { Error: Internal error occurred while running select. (See .raw for more information.) at Object.find (.\node_modules\sails-postgresql\lib\adapter.js:183:15) at _getPopulatedRecords (.\node_modules\waterline\lib\waterline\utils\query\help-find.js:145:21) at helpFind (.\node_modules\waterline\lib\waterline\utils\query\help-find.js:582:6) at _afterPotentiallyRunningBeforeLC (.\node_modules\waterline\lib\waterline\methods\find-one.js:265:9) at _maybeRunBeforeLC (.\nodemodules\waterline\lib\waterline\methods\find-one.js:239:16) at Deferred..extend._WLModel [as _handleExec] (.\node_modules\waterline\lib\waterline\methods\find-one.js:241:9) at Deferred.exec (.\node_modules\parley\lib\private\Deferred.js:286:10) at Deferred.tryCatcher (.\node_modules\parley\node_modules\bluebird\js\release\util.js:11:23) at ret (eval at makeNodePromisifiedEval (.\node_modules\parley\node_modules\bluebird\js\release\promisify.js:184:12), :14:23) at Deferred.toPromise (.\node_modules\parley\lib\private\Deferred.js:572:19) at Deferred.then (.\node_modules\parley\lib\private\Deferred.js:431:22) name: 'Error', code: 'E_INTERNAL_ERROR', raw: { Exception: sendNativeQuery failed ("badConnection"). The provided connection is not valid or no longer active. Are you sure it was obtained by calling this driver's getConnection() method? at Object.runQuery (.\node_modules\sails-postgresql\helpers\private\query\run-query.js:34:6) at spawnConnectionCb (.\node_modules\sails-postgresql\helpers\select.js:149:21) at Immediate.ensureAsync (.\node_modules\sails-postgresql\helpers\private\connection\spawn-or-lease-connection.js:18:7) at runCallback (timers.js:794:20) at tryOnImmediate (timers.js:752:5) at processImmediate [as _immediateCallback] (timers.js:729:5) name: 'Exception', code: 'badConnection', exit: 'badConnection' } } }

For 2, we have:

  fetchRecordsOnUpdate: true,
  fetchRecordsOnCreate: true,
  fetchRecordsOnCreateEach: true,

So this shouldn't be issue. I don't understand, you aren't able to reproduce this error? For me it happens with any two calls to model methods.

rachaelshaw commented 5 years ago

@maximovicd just to make sure: have you tried logging the value returned from that .create() call to make sure createdEntity looks as expected?

And to clarify: are you only seeing an error when you try to do more than one call to a model method? Or is it failing even with one?

maximovicd commented 5 years ago

We are migrating Sails from 0.12 to 1, it is working as expected with no transactions.

However, with one call it still fails with the same message. Looks like the connection is invalid from the beginning.

rachaelshaw commented 5 years ago

@maximovicd I tested this out with a fresh sails project (just modified the signup action to use your example and didn't have any issues with .transaction().

Would you mind cloning this repo, configuring it with your local database url here, then testing out the signup page and reporting back? (It also might be helpful to compare the version of sails-hook-orm in that example vs. your own project to see if they're different.)

maximovicd commented 5 years ago

Hm, this is interesting. I can't repeat the issue with your code. However, I just created empty sails project (so no views or other dependencies), and when hitting an endpoint I get the same error.

Do you know of any dependency to grunt, or views or any issue with blueprints.actions: true? I will take time to create an empty sails project again and put it on github for you to check out.

EDIT: here is the link to the minimal example I used to get this error.

maximovicd commented 5 years ago

Pff, I see your change, and it does solve the issue for this small scale example. Unfortunately, when I try to transfer the code to my codebase, I still get the same error.

This time, the error happens only on second call to an ORM method. (Remembering back to January, this was the issue we experienced in the first place)

mikermcneil commented 5 years ago

@maximovicd I think part of the issue might be the absence of parentheses (see the commit above)

Would you try adding parentheses to the during function? Also see rachael's follow-up

rachaelshaw commented 5 years ago

@maximovicd just tested that repo out locally and saw the exact same error you reported; however, I noticed the controller code had a missing await, so fixed it (PR here: https://github.com/maximovicd/sails-transactions-issue/pull/1) and tried running it again and it worked as expected. Looks like when the transaction's during function isn't asynchronous, you'll get that error instead of the usual warning.

Normally, when there's an await missing, you'll see a warning in the console after 15 seconds:

- - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
WARNING: A function that was initially called over 15 seconds
ago has still not actually been executed.  Any chance the
source code is missing an "await"?

 [?] For more help, visit https://sailsjs.com/support
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - -
maximovicd commented 5 years ago

Yeah, see my comment above.

Also I might not have understand what you mean by "dropping the parentheses". Do you mean the ones around db argument in transaction?

rachaelshaw commented 5 years ago

@maximovicd sorry, @mikermcneil typed the wrong thing, just fixed it for him. See his comment above

maximovicd commented 5 years ago

This is an issue when using babel transformations, I added sails-hook-babel with polyfill: true and the issue returned. Is there any chance of getting this to work with polyfill?

mikermcneil commented 5 years ago

@maximovicd I've never used that hook, but I don't think you'll need to use any sort of transpiler for your backend code anymore as of node ≥7.8. await, arrow functions, and all the good stuff are supported out of the box.

Regardless, I would like to make this work though (i.e. without parentheses). It's just a matter of updating those regexes from my commit above-- it just gets tricky because of all the ways you can define arguments in JavaScript now

maximovicd commented 5 years ago

Hm, I'm sure you guys put some thought into it already, but is there a way for transactions to work without having issues when transforming the code?

mikermcneil commented 5 years ago

Hm, I'm sure you guys put some thought into it already, but is there a way for transactions to work without having issues when transforming the code?

@maximovicd Hmmm, not sure what you mean... Are you suggesting Sails or Waterline make some kind of automatic assumptions about which queries might be appropriate for it to bundle within the same transaction/connection rather than pulling a fresh(ish) connection each time? (I say "freshish" because generally they're not actually new connections, they're from the connection pool.)

bigbn commented 5 years ago

@maximovicd I've never used that hook, but I don't think you'll need to use any sort of transpiler for your backend code anymore as of node ≥7.8. await, arrow functions, and all the good stuff are supported out of the box.

Regardless, I would like to make this work though (i.e. without parentheses). It's just a matter of updating those regexes from my commit above-- it just gets tricky because of all the ways you can define arguments in JavaScript now

Got this error using @babel/node for a flow types support. image

I think this you can repeat it just by trying to start app.js from babel-node instead node

image

Basic config:

babel.config.js:
module.exports = {
  presets: [ '@babel/preset-flow', '@babel/preset-env' ]
}
bigbn commented 5 years ago

What can be reason for a such behaviour, where to dig? I can't continue my project because of this issue, and everything else work as expected. Sails is still good even under babel. I need at least temporary solution, before this bug will fixed in mainstream.

whichking commented 5 years ago

Hey, @bigbn, can you provide a repo that reproduces the behavior/error you're getting?

bigbn commented 5 years ago

Hey, @bigbn, can you provide a repo that reproduces the behavior/error you're getting?

Hi, @madisonhicks we've already found way to resolve this. The reason is what seemsToExpectCallback variable waits for EXACT 2 arguments via this regexp parametersAsString.match(/\,\s*([^,\{\}\[\]\s]+)\s*$/). But our code had such stucture:

...  await this.datastore.transaction(async (connection) => ...

instead of this

...  await this.datastore.transaction(async (connection, commit) => ...

this is the reason why seemsToExpectCallback was false, and connection released before async function passed to transaction method realy completes. No matter is our function async or not. We got 2 native insert SQL queries, and second query fails everytime with such error, because connection was already released.

      var seemsToExpectCallback = (function(){
        var fnStr = options.during.toString().replace(STRIP_COMMENTS_RX, '');
        var parametersAsString = fnStr.slice(fnStr.indexOf('(')+1, fnStr.indexOf(')'));
        return !! parametersAsString.match(/\,\s*([^,\{\}\[\]\s]+)\s*$/);
      })();//†

This code smells because it tries to parse function body, but function body can be transpiled, or not include arguments at all e.g.:

..  await this.datastore.transaction(async (...args) => ..
..  await this.datastore.transaction(function () { [db] = arguments ..

and also this place is not realy good:

// Take care of unhandled promise rejections from `await` (if appropriate)
if (options.during.constructor.name === 'AsyncFunction') {

it can be GeneratorFunction in transpiled code

whichking commented 5 years ago

Hi, @bigbn—thanks for the information! You’re absolutely right, this isn’t ideal, but it was provided to allow for backwards compatibility. Glad to have your help exposing this behavior.