Uploaded image for project: 'Node.js Driver'
  1. Node.js Driver
  2. NODE-2862

10-12th Query From A Single Client Instance Hangs for 10s

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Major - P3
    • Resolution: Duplicate
    • 3.6.2
    • None
    • Lambda

    Description

      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 

       

       

      Error formatting macro: code: java.lang.StackOverflowError

      {"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)"}}}

       

      Attachments

        Issue Links

          Activity

            People

              matt.broadstone@mongodb.com Matt Broadstone
              alex@trypearl.io Alexander Velikanov
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: