- Sponsor
-
Notifications
You must be signed in to change notification settings - Fork 1.2k
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
7.18.2: "Connection terminated unexpectedly" when using client.query with a pool when pool has been idle for 10 minutes (running in AWS Lambda) #2112
Comments
@jcollum this is also happening for us and a number of others (see this thread knex/knex#3636). We're seeing this in Node 10 / 12 in the Lambda environment. Only solution at the moment was to run a custom Node 8 runtime for our Lambda functions. |
@jamesdixon : Ah -- I was just about to point you to this thread! lol |
dealing with the same issue on production, @briandamaged @jamesdixon any solution? please help |
It looks like it's related to the lambda environment or something and not pg. According to this it's hitting both pg & mysql....which makes it somewhat unlikely to be caused by this library. I'm not sure there's much I can do w/o having steps to reproduce, unfortunately. Looking at @jcollum's example it looks like it's somehow related to the lambda going idle and killing the open connections to the db. Weirdly if you only run the lambda once every 10 minutes that should be well outside the idle timeout and the pool should have closed all it's connections. Anyways I can make lots of assumptions about what's happening but w/o steps to reproduce I'm not gonna be able to provide much concrete support. I'll follow along if more info comes up I'll look into it. Also: PRs are always welcome for issues like this if you figure out what it is! 😉 |
Thanks for the input, @brianc!
That was the original thought but later on in the thread you referenced, one of the Knex maintainers pointed out that the MySQL error was actually different and may not be related. The one thing we do know is that the issue isn't present in Node 8 but rears its ugly head in Node 10/12. Are you aware of any major changes in those versions related to this library that might be exacerbated in a Lambda environment? |
@jamesdixon : Howdy! Just to clarify: what I meant was that Knex did not appear to be directly related to the pg-specific control path. However, I suspect that the same lower-level issue is affecting both My guess is that either the server or the network is aggressively closing the connections. This is then causing the client-side libraries to "get confused" when they discover that the connection is already closed. (At least, that appears to be the case for |
Got it! Thanks for the clarification!
…On Tue, Feb 25, 2020 at 11:02 AM Brian Lauber ***@***.***> wrote:
@jamesdixon <https://github.com/jamesdixon> : Howdy! Just to clarify:
what I meant was that Knex did not appear to be directly related to the
pg-specific control path. However, I suspect that the same lower-level
issue is affecting both "pg" and "mysql".
My guess is that either the server or the network is aggressively closing
the connections. This is then causing the client-side libraries to "get
confused" when they discover that the connection is already closed. (At
least, that appears to be the case for "pg". The Client class checks the
this._ending flag to see whether or not it was expecting the connection
to be closed)
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#2112?email_source=notifications&email_token=AAA24IXYNC5ZRZGUCSJDUOTREVMJ5A5CNFSM4K2TYUC2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEM44G7I#issuecomment-590988157>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AAA24ITEVY7NCGYWPMDCCKDREVMJ5ANCNFSM4K2TYUCQ>
.
|
I fixed it by not using a pool:
Minor performance hit there. |
@jcollum : My guess is that the issue isn't actually "fixed", but rather "avoided". As in: whenever your code needs to perform a query, it is:
BTW: it looks like there is a connection leak in that snippet. It should probably do this:
This will ensure that the connection will be closed even if an error occurs. |
Yah opening a new client every time is something you can do, but the latency overhead of opening a client is aprox 20x the overhead of sending a query....so ideally you'd use a pool. You don't have to, particularly if your lambda is going cold then pooling really likely isn't buying you much. There might be a way to simulate this in test by creating a pool, reaching into the internals, and severing the streams manually behind the scenes. Anyone care to make a first pass crack at that in a gist or something? If it reproduces the issue I can spin it into a test, make it pass, and ship a fix! |
Well yes it's not a fix it's a workaround. Thanks for catching that potential leak. |
@brianc : Thinking about this a bit more... I suspect that both Instead, this function should probably delegate to a I'll check the |
@brianc : So, it looks like the node-postgres/packages/pg-pool/index.js Line 216 in 1c8b6b9
However, it looks like the node-postgres/packages/pg/lib/client.js Lines 252 to 279 in 1c8b6b9
So, if this analysis is correct, then it means there is a way for the Pool to contain |
@brianc : Here's a snippet that seems to confirm my suspicion:
Sample output:
|
that's perfect I'll get it looked at soon! |
FYI: It looks like you can trigger the issue one layer deeper as well. Ex:
|
I'm impressed with how quickly this is being looked at |
@jcollum agreed. Shout out to @briandamaged for digging into this. I'm so thankful for people smarter than I am 🤣 |
I've been trying to work on |
Thanks for being so on top of this.
…On Tue, Feb 25, 2020 at 8:33 PM Brian C ***@***.***> wrote:
I'm impressed with how quickly this is being looked at
I've been *trying* to work on pg at least 5 days a week this year. I'll
be looking at this first thing tomorrow morning. I'm not 100% sure that
making the pool evict closed clients will fix the actual specific issue in
lamdas but...it's good behavior to have either way.
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#2112?email_source=notifications&email_token=AAFMAAVJEGOUR5O3PGT3XZTREXWLJA5CNFSM4K2TYUC2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEM6YE3I#issuecomment-591233645>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AAFMAAQNUNKE5UJFFXNV7CDREXWLJANCNFSM4K2TYUCQ>
.
|
@brianc thanks for building such an important library. Your efforts are truly appreciated. Cheers! |
❤️ thanks. Looking forward to making lots of folks node apps faster
in the next few months when I do some work on perf!
…On Tue, Feb 25, 2020 at 10:37 PM James Dixon ***@***.***> wrote:
@brianc <https://github.com/brianc> thanks for building such an important
library. Your efforts are truly appreciated. Cheers!
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#2112?email_source=notifications&email_token=AAAMHIMS2WOYO4X37VPYTO3REXWXLA5CNFSM4K2TYUC2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOEM6YKYY#issuecomment-591234403>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AAAMHIOKFBCV2UFEUSWWVRLREXWXLANCNFSM4K2TYUCQ>
.
|
@brianc : Here's a variation on the earlier script that provides some more evidence around the issue:
There are 2 key things you can play around with here:
Even with a delay of 1 second, the problem seems to disappear. So, now I'm unsure if this script is accurately recreating the scenario described by this issue. |
Wrapping the pool clients would solve a lot of these problems. Right now pool clients are the raw client with additional functions to release the connection back to the pool. That means that code that directly manipulates the connection, ex: You also need to ensure to call async function doStuff(label) {
const client = await pool.connect();
try {
console.log(`${label}: START`)
const res = await client.query("select 1", null);
console.log(`${label}: SUCCEEDED`);
} catch(err) {
console.log(`${label}: ERROR -> ${err}`)
} finally {
client.release();
}
} Calling |
@sehrope : Right. The purpose of the code snippet was to recreate a scenario where the low-level socket was being closed/ended outside of the Pool's managed lifecycle. So, you're correct: normally, you would not want to do that. As for the
(Okay, fine. It's technically possible, but it forces the developer to create/check In either case: the snippet's error is actually triggered by the first call to The main concept is: it's possible for Clients that are already in the Pool to lose their Connections. It's the Pool's responsibility to double-check the validity of a Client before handing it off to a caller. Based upon the issue reported here, it looks like there might be a corner case where this is not occurring. (Or, alternatively: perhaps several people missed this detail about |
Yes it's a bit tricky and hopefully when the pool interface gets improved it'll be easier to use. That "pass an error to evict" logic for the pool has been for all the years I've used this driver. All my usage of the driver has a local wrapper that handles that logic so it's in one place in each app, but you're right that everybody kind of has to handle it themselves.
Yes that's the logic to which I'm referring. Though rather than checking if an error occurred the usual approach is to have different const pg = require('pg');
const pool = new Pool({ /* ... */ });
const withClient = async (task) => {
const client = await pool.connect();
try {
const result = await task(client);
// If we get here then the task was successful so assume the client is fine
client.release();
return result;
} catch (err) {
// If we get here then the task failed so assume the client is broken
client.release(err);
throw err;
}
}; That logic is a bit over zealous as it'll evict potentially salvageable client errors (ex: after a successful ROLLBACK we'd expect the client to be usable again) but it's a decent default. If you expect to have lots of constraint violations that could thrash your pool you can make it a bit more intelligent to deal with that situation or have a transaction wrapper handle that.
It's important to evict broken connections or your pool will never heal and you'll keep getting the same broken connections. Evicting them will force your pool to (eventually) create new working connections.
Yes we should fix that. The docs site (https://node-postgres.com/api/pool#releaseCallback) has the right usage but the README must be really out of date.
The end usage always needs to deal with broken connections as even if the pool tests the connection, it's a race condition between the pool testing the connection and the end usage actually doing some work with the connection:
That's possible. For something like Lambda that can freeze your app and effectively kill any open sockets in the background, I'd suggest not using a pool at all if it's an option. Or you can add your own wrapper that repeatedly tries to fetch and test the connection prior to giving it to the rest of your code. Also, setting the |
I believe this issue is also happening to me on GCP - google cloud functions - I think this is similar to AWS Lamba functions. Just wanted to comment to note that it was happening in other serverless/cloud environments incase others are running into this issue from a google cloud project. This snippet is what I will be trying, I missed this in the documentation but I have a feeling it will alleviate the problem.
|
Cross-posting from TypeORM: typeorm/typeorm#5112 (comment) Call this method from inside the event handler function.
Please mind removing type annotations for plain node usage. This is targeting a TypeORM setup, but the concept should be working for node-pg as well. If someone could port this, highly appreciated :-) We're flying with this since a while now, and it remediated the issue (tho, obviously, not fix it fully). The database connection is established outside the main handler function, allowing it to be re-used. Just this little snippet here checks if everything is still up and running. Might add a little TTL on that check, so it only fires every few minutes. |
please check: #2439 (comment) |
My issue was that the Aurora reader I was connecting to was rebooting from falling behind the writer too much. Figured I'd post in case someone else was running into this. |
@brianc thank you for all your hard work, this to me is another case of big tech offloading it's problems to the open source community. Running in to the same issue on EKS and seeing how many people are being affected makes me feel a little less crazy. Gonna make my first sponsorship today to help support you, if I can track down a worthwhile solution I'll open a PR. Arohanui |
For anyone else still struggling with this I think I may have found a resolution. It seems to be largely an infrastructure provider issue as others have mentioned, AWS has a common practice of setting a 350 second timeout on idle TCP connections, Azure and GCP have different timeouts but similar issues. From a cursory search ELB and NAT Gateway were the culprits for me. The keepAlive flag implemented in node-pg follows the right setup from what I can see but it could be that the OS level and node aren't playing nice as the default timer for linux seems to be 7200. I ended up resolving by setting up pgbouncer and adding a keepAlive timer of 300 to the config pgbouncer.ini
Thank you all for helping me through the day |
We added below config as well as the pool config but still get the same error: 'net.ipv4.tcp_keepalive_time 60
|
still a thing |
Any solutions? my RESTFUL API randomly disconnects because of this...otherwise ill just setup a cronjob to call the /health endpoint every minute or something. |
I think the typical setup for serverless API-s connecting to traditional RDBMS is a separate connection pool (eg. pgbouncer). |
I have had similar experiences with this on Google Cloud using cloud functions, posted previously in here. This is actually the same conclusion that my team has come to as well. The way Cloud Functions are handled, at least on first generation functions on GCP, is that a single request is handled by a single instance. There will never be the ability for a connection pool to exist in this situation regardless of the timeout - Its one of the shortcomings of the FaaS architecture. |
Hey thanks for the reply, im not on AWS/AWS Lambda. My restful API is based on Fastify, here's a link just incase: https://www.fastify.io/ also im using client, not pool. Edit: Will be doing this instead: https://github.com/fastify/fastify-postgres |
@balbatross Do you mind explaining in more detail how you set up pgbouncer, and why that fixed your problem? links to docs is fine. Googled but found nothing. Thanks! |
@mepc36 PGBouncer solves this by moving the pooling to PGbouncer instead of pg-node. It sits between the node application and the database and uses its own internal pooling to keep track of connections, which is transparent to your application. I don't think the configuration you quoted really has anything to do with why this solves the issue, PGbouncer is the solution to the problem. You would setup PGbouncer on a VM - compute engine on GCP - and your application would connect to that instead of postgres directly. p.s. Nice to see a fellow developer from Philadelphia 😀 |
Quick question to everyone who is still experiencing this. Do you use Aurora Serverless v1 by any chance? The reason I'm asking is because I think this happens when the cluster experiences a scaling event. It drops all connections. This doesn't happen on v2 by the way. |
I think I got to the bottom of this with at least one particular case. This is only applicable to Aurora Serverless v1, and maybe v2. I will test v2 later and report back. Here's what happens: A scaling event is triggered. After ~ 2m the scaling event is triggered (cluster status = -- 1: long string, looks like base64 encoded, but not
-- 2: The value of `SecondsBeforeTimeout` from `ScalingConfigurationInfo`
-- 3: Not sure what this is, seems to be always `2`
select * from aurora_serverless_prepare_seamless_scaling('long string', 60000, 2) This query is blocking until all user queries are finished running. As soon as the last query ends, it will drop all of the active connections within milliseconds. I have tested this by running
So what actually happens in the Lambda environment? It's a race condition!
I have corroborated this with a massive amount of Log Insight queries and a CloudWatch dashboard.
|
@moltar I was experiencing this issue over in Google cloud functions - the Google equivalent of AWS lambda. I presume GCP has some timeout in the same way AWS is dropping the connections. It turns out there is no way for GCP cloud functions to handle concurrent requests, so it doesn’t actually make sense to try to start a pool as the function only handles 1 query per invocation. Version 2 has changed that, and allows concurrent requests. In a function as a service environment, IMO, the best way to handle this would be an external pool service like pgbouncer. |
This fixes various issues with node-postgres, specifically that the connection pooling implementation does not work well: brianc/node-postgres#1611 brianc/node-postgres#2112
This fixes various issues with node-postgres, specifically that the connection pooling implementation does not work well: brianc/node-postgres#1611 brianc/node-postgres#2112 --------- Co-authored-by: Ivan Chub <[email protected]>
This fixes various issues with node-postgres, specifically that the connection pooling implementation does not work well: brianc/node-postgres#1611 brianc/node-postgres#2112 --------- Co-authored-by: Ivan Chub <[email protected]>
Hi, the issue with connection still seems to be appearing in the latest version: 8.11.3 I have encountered something very similar to what was described above and managed to create some simple code snippet with the problem. Maybe this will help with resolving the issue. I'm just using pg-pool to connect to local postgres and insert simple json object. Simple table to store the jsonb. create table test (
value jsonb
); JS inserting the objects: async function insertUsingPool() {
// following query works fine
await pgPool.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 1}]
).catch((e) => { console.error(e) });
// this fails with error: TypeError: Do not know how to serialize a BigInt
await pgPool.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 2n}]
).catch((e) => { console.error(e) });
// this fails with error: Error: Connection terminated unexpectedly
await pgPool.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 3}]
).catch((e) => { console.error(e) });
} async function insertUsingClientPool() {
const pgPoolClient = await pgPool.connect();
// following query works fine
await pgPoolClient.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 4}]
).catch((e) => { console.error(e) });
// this throws exception and hangs... TypeError: Do not know how to serialize a BigInt
await pgPoolClient.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 5n}]
).catch((e) => { console.error(e) });
// not even executed...
await pgPoolClient.query(
`INSERT INTO test (value) VALUES ($1)`,
[{'test' : 6}]
).catch((e) => { console.error(e) });
} After running the insertUsingClientPool function, I don't know, maybe I'm doing something stupid and not using the pg lib correctly, but maybe the JSON.stringify should be called before establishing the connection? |
Any updates? |
How can we do this buddy? |
Code is running in a lambda. When we run the function below it runs fine. But if we run it and then wait 10 minutes then run it again, we get an error every time. We are querying Aurora Postgres on AWS.
Code:
This is what I see in the cloudwatch logs:
I've tried a few variations on this but the constant is the 10 minutes and the use of the Pool. To me this code is almost identical to the code in https://node-postgres.com/features/pooling.
So far it looks like the problem has been solved by using a Client instead:
The text was updated successfully, but these errors were encountered: