-
Type:
Bug
-
Resolution: Duplicate
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.6.2
-
Component/s: Lambda
-
Labels:
-
(copied to CRM)
-
Empty show more show less
So the issue I'm having is as follows, I run a service in Node.JS running on AWS Lambda. My service creates a single MogoClient and then shares that for all subsequent queries. I have no issues with this through the first 10-ish queries (my service does between 1-3 each time it's triggered), but consistently calls after those first 10 (especially if you wait a minute or two before making the next call) will hang for 10-12 seconds. I also tested this with maxTimeMS which didn't stop it and it still took 10s.
MongoDB Node 3.6.2
MongoDB Server (Atlas) 4.4.1
Client Debug Logs
| 1603478336164 | START RequestId: 8709fac2-ddfb-44c7-955f-440eedbafffa Version: $LATEST |
| 1603478336167 | 2020-10-23T18:38:56.167Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO [DEBUG-Cursor:8] 1603478336167 issue initial query [{"find":"production.jobs","limit":0,"skip":0,"query":{"tenantId":"5f272b805b3f43454209bb15"},"timeout":true,"maxTimeMS":2000,"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"noCursorTimeout":true}] with flags [undefined] { type: 'debug', message: 'issue initial query [{"find":"production.jobs","limit":0,"skip":0,"query":{"tenantId":"5f272b805b3f43454209bb15"},"timeout":true,"maxTimeMS":2000,"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"noCursorTimeout":true}] with flags [undefined]', className: 'Cursor', pid: 8, date: 1603478336167 } |
| 1603478336338 | 2020-10-23T18:38:56.336Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO [DEBUG-Cursor:8] 1603478336336 schedule getMore call for query [undefined] { type: 'debug', message: 'schedule getMore call for query [undefined]', className: 'Cursor', pid: 8, date: 1603478336336 } |
| 1603478336435 | 2020-10-23T18:38:56.435Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO real start |
| 1603478346193 | 2020-10-23T18:39:06.192Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO [DEBUG-Cursor:8] 1603478346192 issue initial query [{"find":"production.jobs","limit":-1,"skip":0,"query":{"_id":"5e4cdd12bdac87b6a917995b"},"projection":{"keywordBucket":1,"pearlData":1,"tenantId":1},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"fields":{"keywordBucket":1,"pearlData":1,"tenantId":1},"batchSize":1}] with flags [undefined] { type: 'debug', message: 'issue initial query [{"find":"production.jobs","limit":-1,"skip":0,"query":{"_id":"5e4cdd12bdac87b6a917995b"},"projection":{"keywordBucket":1,"pearlData":1,"tenantId":1},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"fields":{"keywordBucket":1,"pearlData":1,"tenantId":1},"batchSize":1}] with flags [undefined]', className: 'Cursor', pid: 8, date: 1603478346192 } |
| 1603478346195 | 2020-10-23T18:39:06.194Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO Moving into reccomendations |
| 1603478346196 | 2020-10-23T18:39:06.196Z 8709fac2-ddfb-44c7-955f-440eedbafffa INFO [DEBUG-Cursor:8] 1603478346196 issue initial query [{"find":"production.seekers","limit":0,"skip":0,"query":{"pearlJobs.stagedFor":{"$in":[{"jobId":"5e4cdd12bdac87b6a917995b","selection":0},{"jobId":"5e4cdd12bdac87b6a917995b","selection":1},{"jobId":"5e4cdd12bdac87b6a917995b","selection":2}]},"tenantId":"5f272b805b3f43454209bb15"},"timeout":true,"maxTimeMS":2000,"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"noCursorTimeout":true,"maxAwaitTimeMS":2000}] with flags [undefined] { type: 'debug', message: 'issue initial query [{"find":"production.seekers","limit":0,"skip":0,"query":{"pearlJobs.stagedFor":{"$in":[{"jobId":"5e4cdd12bdac87b6a917995b","selection":0},{"jobId":"5e4cdd12bdac87b6a917995b","selection":1},{"jobId":"5e4cdd12bdac87b6a917995b","selection":2}]},"tenantId":"5f272b805b3f43454209bb15"},"timeout":true,"maxTimeMS":2000,"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"},"noCursorTimeout":true,"maxAwaitTimeMS":2000}] with flags [undefined]', className: 'Cursor', pid: 8, date: 1603478346196 } |
** Lines Ommited For Brevity ** |
| 1603478347302 | END RequestId: 8709fac2-ddfb-44c7-955f-440eedbafffa |
| 1603478347302 | REPORT RequestId: 8709fac2-ddfb-44c7-955f-440eedbafffa Duration: 11135.35 ms Billed Duration: 11200 ms Memory Size: 1024 MB Max Memory Used: 422 MB |
Server Debug Logs
{"t":{"$date":"2020-10-23T18:38:56.169+00:00"},"s":"I", "c":"-", "id":20883, "ctx":"conn59772","msg":"Interrupted operation as its client disconnected","attr":{"opId":11603396}} {"t":{"$date":"2020-10-23T18:38:56.169+00:00"},"s":"I", "c":"NETWORK", "id":22989, "ctx":"conn59772","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"18.144.14.179:43904","connectionId":59772}} {"t":{"$date":"2020-10-23T18:38:56.169+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59772","msg":"Connection ended","attr":{"remote":"18.144.14.179:43904","connectionId":59772,"connectionCount":53}} {"t":{"$date":"2020-10-23T18:38:56.180+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59773","msg":"Connection ended","attr":{"remote":"18.144.14.179:43906","connectionId":59773,"connectionCount":52}} {"t":{"$date":"2020-10-23T18:38:56.214+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"18.144.14.179:43932","connectionId":59824,"connectionCount":53}} {"t":{"$date":"2020-10-23T18:38:56.237+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59824","msg":"client metadata","attr":{"remote":"18.144.14.179:43932","client":"conn59824","doc":{"driver":{"name":"nodejs","version":"3.6.2"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"4.14.193-110.317.amzn2.x86_64"},"platform":"'Node.js v12.18.4, LE (unified)"}}} {"t":{"$date":"2020-10-23T18:38:56.237+00:00"},"s":"I", "c":"ACCESS", "id":20249, "ctx":"conn59824","msg":"Authentication failed","attr":{"mechanism":"SCRAM-SHA-256","principalName":"textingservice","authenticationDatabase":"admin","client":"18.144.14.179:43932","result":"BadValue: SCRAM-SHA-256 authentication is disabled"}} {"t":{"$date":"2020-10-23T18:38:56.239+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn59824","msg":"Successful authentication","attr":{"mechanism":"SCRAM-SHA-1","principalName":"textingservice","authenticationDatabase":"admin","client":"18.144.14.179:43932"}} {"t":{"$date":"2020-10-23T18:38:56.240+00:00"},"s":"I", "c":"-", "id":20883, "ctx":"conn59774","msg":"Interrupted operation as its client disconnected","attr":{"opId":11603457}} {"t":{"$date":"2020-10-23T18:38:56.241+00:00"},"s":"I", "c":"NETWORK", "id":22989, "ctx":"conn59774","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"13.52.255.207:34994","connectionId":59774}} {"t":{"$date":"2020-10-23T18:38:56.241+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59774","msg":"Connection ended","attr":{"remote":"13.52.255.207:34994","connectionId":59774,"connectionCount":52}} {"t":{"$date":"2020-10-23T18:38:56.244+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59775","msg":"Connection ended","attr":{"remote":"13.52.255.207:34998","connectionId":59775,"connectionCount":51}} {"t":{"$date":"2020-10-23T18:38:56.245+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"13.52.255.207:35006","connectionId":59825,"connectionCount":52}} {"t":{"$date":"2020-10-23T18:38:56.247+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"13.52.255.207:35010","connectionId":59826,"connectionCount":53}} {"t":{"$date":"2020-10-23T18:38:56.261+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59825","msg":"client metadata","attr":{"remote":"13.52.255.207:35006","client":"conn59825","doc":{"driver":{"name":"nodejs","version":"3.6.2"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"4.14.193-110.317.amzn2.x86_64"},"platform":"'Node.js v12.18.4, LE (unified)"}}} {"t":{"$date":"2020-10-23T18:38:56.263+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59826","msg":"client metadata","attr":{"remote":"13.52.255.207:35010","client":"conn59826","doc":{"driver":{"name":"nodejs","version":"3.6.2"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"4.14.193-110.317.amzn2.x86_64"},"platform":"'Node.js v12.18.4, LE (unified)"}}} {"t":{"$date":"2020-10-23T18:38:56.264+00:00"},"s":"I", "c":"ACCESS", "id":20249, "ctx":"conn59826","msg":"Authentication failed","attr":{"mechanism":"SCRAM-SHA-256","principalName":"textingservice","authenticationDatabase":"admin","client":"13.52.255.207:35010","result":"BadValue: SCRAM-SHA-256 authentication is disabled"}} {"t":{"$date":"2020-10-23T18:38:56.267+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn59826","msg":"Successful authentication","attr":{"mechanism":"SCRAM-SHA-1","principalName":"textingservice","authenticationDatabase":"admin","client":"13.52.255.207:35010"}} {"t":{"$date":"2020-10-23T18:38:58.759+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"192.168.236.27:51882","connectionId":59827,"connectionCount":54}} {"t":{"$date":"2020-10-23T18:38:58.766+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59827","msg":"client metadata","attr":{"remote":"192.168.236.27:51882","client":"conn59827","doc":{"driver":{"name":"mongo-go-driver","version":"v1.3.4"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.14.7","application":{"name":"MongoDB Automation Agent v10.19.3.6600 (git: 94410a3cfa65ce88cdd7b3bf35f61ad010e17e9b)"}}}} {"t":{"$date":"2020-10-23T18:38:58.767+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"192.168.236.27:51884","connectionId":59828,"connectionCount":55}} {"t":{"$date":"2020-10-23T18:38:58.782+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59828","msg":"client metadata","attr":{"remote":"192.168.236.27:51884","client":"conn59828","doc":{"driver":{"name":"mongo-go-driver","version":"v1.3.4"},"os":{"type":"linux","architecture":"amd64"},"platform":"go1.14.7","application":{"name":"MongoDB Automation Agent v10.19.3.6600 (git: 94410a3cfa65ce88cdd7b3bf35f61ad010e17e9b)"}}}} {"t":{"$date":"2020-10-23T18:38:58.821+00:00"},"s":"I", "c":"ACCESS", "id":20250, "ctx":"conn59828","msg":"Successful authentication","attr":{"mechanism":"SCRAM-SHA-256","principalName":"__system","authenticationDatabase":"local","client":"192.168.236.27:51884"}} {"t":{"$date":"2020-10-23T18:38:58.823+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59828","msg":"Connection ended","attr":{"remote":"192.168.236.27:51884","connectionId":59828,"connectionCount":54}} {"t":{"$date":"2020-10-23T18:38:58.823+00:00"},"s":"I", "c":"NETWORK", "id":22944, "ctx":"conn59827","msg":"Connection ended","attr":{"remote":"192.168.236.27:51882","connectionId":59827,"connectionCount":53}} {"t":{"$date":"2020-10-23T18:39:06.180+00:00"},"s":"I", "c":"NETWORK", "id":22943, "ctx":"listener","msg":"Connection accepted","attr":{"remote":"18.144.14.179:43936","connectionId":59829,"connectionCount":54}} {"t":{"$date":"2020-10-23T18:39:06.190+00:00"},"s":"I", "c":"NETWORK", "id":51800, "ctx":"conn59829","msg":"client metadata","attr":{"remote":"18.144.14.179:43936","client":"conn59829","doc":{"driver":{"name":"nodejs","version":"3.6.2"},"os":{"type":"Linux","name":"linux","architecture":"x64","version":"4.14.193-110.317.amzn2.x86_64"},"platform":"'Node.js v12.18.4, LE (unified)"}}}
- duplicates
-
-
- Closed
-