TryGhost / Ghost

Independent technology for modern publishing, memberships, subscriptions and newsletters.
https://ghost.org
MIT License
46.82k stars 10.2k forks source link

Error:: Knex:warning - Pool2 - Error: ResourceRequest aborted: Knex: Timeout acquiring a connection. #7346

Closed luebken closed 7 years ago

luebken commented 8 years ago

Issue Summary

Ghost crashed. Seeing this error:

Sep  9 03:53:47 digitalocean journal: Knex:warning - Pool2 - Error: ResourceRequest aborted: Knex: Timeout acquiring a connection.
Sep  9 03:54:12 digitalocean journal: 
Sep  9 03:54:12 digitalocean journal: ERROR: Knex: Timeout acquiring a connection. The pool is probably full. Are you missing a .transacting(trx) call? 
Sep  9 03:54:12 digitalocean journal: Rendering Error Page 
Sep  9 03:54:13 digitalocean journal: Ghost caught a processing error in the middleware layer. 
Sep  9 03:54:13 digitalocean journal: Error: Knex: Timeout acquiring a connection. The pool is probably full. Are you missing a .transacting(trx) call?
Sep  9 03:54:13 digitalocean journal:    at /usr/src/ghost/node_modules/knex/lib/runner.js:191:30
Sep  9 03:54:13 digitalocean journal:    at tryCatcher (/usr/src/ghost/node_modules/bluebird/js/release/util.js:16:23)
Sep  9 03:54:13 digitalocean journal:    at /usr/src/ghost/node_modules/bluebird/js/release/catch_filter.js:17:41
Sep  9 03:54:13 digitalocean journal:    at tryCatcher (/usr/src/ghost/node_modules/bluebird/js/release/util.js:16:23)
Sep  9 03:54:13 digitalocean journal:    at Promise._settlePromiseFromHandler (/usr/src/ghost/node_modules/bluebird/js/release/promise.js:504:31)
Sep  9 03:54:13 digitalocean journal:    at Promise._settlePromise (/usr/src/ghost/node_modules/bluebird/js/release/promise.js:561:18)
Sep  9 03:54:13 digitalocean journal:    at Promise._settlePromise0 (/usr/src/ghost/node_modules/bluebird/js/release/promise.js:606:10)
Sep  9 03:54:13 digitalocean journal:    at Promise._settlePromises (/usr/src/ghost/node_modules/bluebird/js/release/promise.js:681:18)
Sep  9 03:54:13 digitalocean journal:    at Async._drainQueue (/usr/src/ghost/node_modules/bluebird/js/release/async.js:138:16)
Sep  9 03:54:13 digitalocean journal:    at Async._drainQueues (/usr/src/ghost/node_modules/bluebird/js/release/async.js:148:10)
Sep  9 03:54:13 digitalocean journal:    at Immediate.Async.drainQueues [as _onImmediate] (/usr/src/ghost/node_modules/bluebird/js/release/async.js:17:14)
Sep  9 03:54:13 digitalocean journal:    at processImmediate [as _immediateCallback] (timers.js:383:17) 

After a couple of these my machine died with an OOM.

Steps to Reproduce

I can't.

Technical details:

kirrg001 commented 8 years ago

Hey @luebken Sorry to hear you are having trouble. There is a similar issue, see https://github.com/TryGhost/Ghost/issues/7137. It would be great if you could tell us if you did the same. And if not, what exactly did you do?Thanks!

luebken commented 8 years ago

No. I didn't try to delete a user.

I'm seeing just GET requests against /, /rss, /content, /assets etc.

ErisDS commented 7 years ago

I believe this is an issue in knex/pool2, not with Ghost. I'm not sure what workarounds are available for sqlite3, but it should be possible to get Ghost working by using MySQL instead.

We will try out re-upgrading the holy-trinity of knex, bookshelf and lodash soon, so that we are on knex 0.12, which hopefully that will resolve the issue.

In the meantime, I'm going to close this issue here as the bug is not in Ghost itself, and the dependencies are deliberately pinned due to a memory leak.

discordianfish commented 7 years ago

Ran into the same issue but with psotgres.

@ErisDS Are you in general not tracking bugs in things you depend on? I'd argue it's a bug in Ghost to depend on a buggy module.

ErisDS commented 7 years ago

Yes, I watch and contribute to many, many of our dependencies therefore there is zero point duplicating the issues here in this repository as it just produces extra noise in my already challenged inbox.

pascalandy commented 7 years ago

Same issue running Mysql.

It happens when the blog didn't serve anything for about 20 min. I just need to refresh and the error disappear after few seconds.

ERROR: select count(distinct posts.id) as aggregate from `posts` where `posts`.`status` = 'published' and `posts`.`page` = false - read EHOSTUNREACH
 Rendering Error Page
 Ghost caught a processing error in the middleware layer.
 Error: read EHOSTUNREACH
    at exports._errnoException (util.js:907:11)
    at TCP.onread (net.js:558:26)
    --------------------
    at Protocol._enqueue (/usr/src/app/node_modules/mysql/lib/protocol/Protocol.js:110:48)
    at Connection.query (/usr/src/app/node_modules/mysql/lib/Connection.js:165:25)
    at /usr/src/app/node_modules/knex/lib/dialects/mysql/index.js:152:18
    at Promise._execute (/usr/src/app/node_modules/bluebird/js/release/debuggability.js:300:9)
    at Promise._resolveFromExecutor (/usr/src/app/node_modules/bluebird/js/release/promise.js:481:18)
    at new Promise (/usr/src/app/node_modules/bluebird/js/release/promise.js:77:14)
    at Client_MySQL._query (/usr/src/app/node_modules/knex/lib/dialects/mysql/index.js:146:12)
    at Client_MySQL.query (/usr/src/app/node_modules/knex/lib/client.js:189:17)
    at Runner.<anonymous> (/usr/src/app/node_modules/knex/lib/runner.js:138:36)
    at Runner.tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at Runner.query (/usr/src/app/node_modules/bluebird/js/release/method.js:15:34)
    at /usr/src/app/node_modules/knex/lib/runner.js:61:21
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at /usr/src/app/node_modules/bluebird/js/release/using.js:185:26
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/usr/src/app/node_modules/bluebird/js/release/promise.js:510:31)
    at Promise._settlePromise (/usr/src/app/node_modules/bluebird/js/release/promise.js:567:18)
    at Promise._settlePromise0 (/usr/src/app/node_modules/bluebird/js/release/promise.js:612:10)
    at Promise._settlePromises (/usr/src/app/node_modules/bluebird/js/release/promise.js:691:18)
    at Promise._fulfill (/usr/src/app/node_modules/bluebird/js/release/promise.js:636:18)
    at PromiseArray._resolve (/usr/src/app/node_modules/bluebird/js/release/promise_array.js:125:19)
    at PromiseArray._promiseFulfilled (/usr/src/app/node_modules/bluebird/js/release/promise_array.js:143:14)
    at Promise._settlePromise (/usr/src/app/node_modules/bluebird/js/release/promise.js:572:26)
kirrg001 commented 7 years ago

@pascalandy I don't think your report is related to this issue.

Are you using a MySQL poolcluster?EHOSTUNREACH says that the mysql server could not be found.

pascalandy commented 7 years ago

This is probably related with my Docker network. I'm running only one instance of MYSQL.

discordianfish commented 7 years ago

So.. was this fixed? I don't know, lacking a issue to track. Just brought down my site again.

kirrg001 commented 7 years ago

@discordianfish Sorry to hear that. Which version of Ghost are you using?

Changdao commented 7 years ago

SQLite Ghost 0.8.0

Knex: Timeout acquiring a connection. The pool is probably full. Are you missing a .transacting(trx) call? ...........

27.197.186.18 - - [05/Feb/2017:13:16:18 +0000] "GET /ghost/ HTTP/1.0" - - "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/52.0.2743.116 Safari/537.36"

ERROR: Error: Knex: Timeout acquiring a connection. The pool is probably full. Are you missing a .transacting(trx) call? Rendering Error Page Ghost caught a processing error in the middleware layer. Error: Error: Knex: Timeout acquiring a connection. The pool is probably full. Are you missing a .transacting(trx) call? at handleError (/home/wondear/aihang/news/core/server/middleware/redirect-to-setup.js:12:21) at tryCatcher (/home/wondear/aihang/news/node_modules/bluebird/js/release/util.js:16:23) at Promise._settlePromiseFromHandler (/home/wondear/aihang/news/node_modules/bluebird/js/release/promise.js:502:31) at Promise._settlePromise (/home/wondear/aihang/news/node_modules/bluebird/js/release/promise.js:559:18) at Promise._settlePromise0 (/home/wondear/aihang/news/node_modules/bluebird/js/release/promise.js:604:10) at Promise._settlePromises (/home/wondear/aihang/news/node_modules/bluebird/js/release/promise.js:679:18) at Async._drainQueue (/home/wondear/aihang/news/node_modules/bluebird/js/release/async.js:138:16) at Async._drainQueues (/home/wondear/aihang/news/node_modules/bluebird/js/release/async.js:148:10) at Immediate.Async.drainQueues [as _onImmediate] (/home/wondear/aihang/news/node_modules/bluebird/js/release/async.js:17:14) at processImmediate [as _immediateCallback] (timers.js:383:17)

kirrg001 commented 7 years ago

@Changdao Could you please share when this error occurred for your? Could you please update to the latest Ghost version and report back if you still experience this error?

Thanks 👋

discordianfish commented 7 years ago

I've upgraded to 0.11.4 and again my site went down because of this. Sure you don't want to reopen this issue?

kirrg001 commented 7 years ago

@discordianfish Hey again.

  1. Do you have any steps to reproduce this?
  2. Do you know which route is affected?
  3. Does it happen always or just once?
  4. Could you share which version of knex is installed on your server? (ls -la node_modules/knex/package.json)
discordianfish commented 7 years ago

@kirrg001: Dang, just realize this blog is still on 0.9.0.. So maybe it is fixed, sorry. Still here the details:

1) Not really, it just seems to happen after running for some time (~2-3 weeks) 2) All? At least / /rss and some articles. Don't seem to get it for static assets (as expected I guess) 3) Every few weeks 4) 0.10.0

Will upgrade and update if this happens again. Is there any way to monitor the knex pool in general so I know if connections are available?

schematical commented 7 years ago

I am on "version": "0.11.4", of Ghost and I am getting the error at the moment.

kirrg001 commented 7 years ago

@schematical Hey 👋

Could you please answer the questions from https://github.com/TryGhost/Ghost/issues/7346#issuecomment-281064437?

Thanks :)

Changdao commented 7 years ago

@kirrg001 Sorry for update late. It's resolved, but I lost the exact detail log. I remember that there are two tables about tag/token(?) in Ghost and SQLite, which will increase and have many records in, and specific request will trigger the action to delete it transactional, maybe the transaction is too large to complete, Ghost failed. The solution is to truncate those two tables manually.

discordianfish commented 7 years ago

This happened to me again... If you need more information, let me know but first reopen the bug. Not going to further discuss on the closed issue.

pascalandy commented 7 years ago

I run Ghost installations within Docker. My some reason connexion drops with the DB. I had to refresh the page 2-3 time before it went back to normal. I found that when I use the healthcheck (which ping the blog every 30 sec), connexion stays consistant.

I don't know if it's exactly related to this issue, but I feel Ghost drop the connexion after a while. cc @sebgie

discordianfish commented 7 years ago

For me it stays down completely because for whatever reason ghost doesn't exit and just stays around without responding. I also don't know why it uses this pooling at all by default.

kirrg001 commented 7 years ago

@discordianfish Sorry to hear you're still having trouble. Could you please re-answer the questions from https://github.com/TryGhost/Ghost/issues/7346#issuecomment-281064437?

discordianfish commented 7 years ago

Answers are the same. It's the same issue that @luebken opened. Probably? something causes the connection to pill up. Either way @ErisDS already hinted at a knex/pool2, without mentioning which issue.

Since this issue here is closed and there is no reference to what might and what might not be fixed, I wouldn't even know where to start.

kirrg001 commented 7 years ago

@discordianfish Did you update Ghost to the latest LTS version?If not, could you please do and report back if your problem still exists? Thanks!

discordianfish commented 7 years ago

It's running 0.11.4

ErisDS commented 7 years ago

Hey @discordianfish - at the time this issue was raised, knex was about to swap back from pool2 to generic-pool in knex@0.12. Therefore there was little point investigating an issue in pool2. I didn't link any specific issue as the upgrade was coming due to a general malaise with pool2 and there were many, many open issues.

The switch over to knex@0.12 and generic-pool for Ghost happened in this PR: https://github.com/TryGhost/Ghost/commit/0ea814ea81f43b64fb91afe95ce571defc5aae99, and was released in Ghost 0.11.1. Therefore if you have upgraded to 0.11.4 your install should no longer be using pool2 or getting pool2 errors.

I have also outlined why our postgres support has always been sub-optimal and will be dropped in Ghost 1.0.