Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-67217

High query response on primary (3-4 sec range) in mongo 4.2.20 version

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • None
    • Affects Version/s: 4.2.20
    • Environment:
    • ALL
    • Hide

      observed high query response after 6 hours of rebooting of one DB VM.

      Show
      observed high query response after 6 hours of rebooting of one DB VM.

      Scenario - We run tests with same load on 2 mongo versions(4.0.27,4.2.20).
      We found high query response on primary(in range of 3-4 seconds) for 4.2.20 version while found no issue with 4.0.27.

      High query response issue start timing: 2022-06-10 20:03 UTC

      Few high query response messages from primary:

      2022-06-10T20:03:52.016+0000 I  WRITE    [conn425] update drasessions_1.drasessions command: { q: { _id:

      { sessionid: "ClpGx0:172.16.241.111:5021:1654866656:0002395073" }

      , ts: { $lte: 1654891428485 }, srk: "serverb1.relay" }, u: { _id:

      { sessionid: "ClpGx0:172.16.241.111:5021:1654866656:0002395073" }

      , ts: 1654891428485, srk: "serverb1.relay", originHost: "site-b-client-calipers21-gx.pcef.gx1", originRealm: "client-consumer.calipers.pcef.gx", destHost: "site-b-server-calipers81-gx.pcef.b-gx-b1.2", destRealm: "server-consumer.calipers.pcef.gx", apn: "ims.com", imsi: "320000000295072", ipv6: "3101:0000:0004:809f", msisdn: "420000000295072", nextEvalTime: new Date(1654981428485), staleSessionExpiryCount: 3, staleBindingRefreshTime: new Date(1656619428486), sessionid: "ClpGx0:172.16.241.111:5021:1654866656:0002395073", systemId: "vpas-system-2", uuid: "vpas-system-21357665800" }, multi: false, upsert: true } planSummary: IXSCAN { _id: 1 } keysExamined:0 docsExamined:0 nMatched:0 nModified:0 upsert:1 keysInserted:2 numYields:0 queryHash:1380E850 planCacheKey:9313C0BA locks:{ ParallelBatchWriterMode: { acquireCount:

      { r: 1 }

      }, ReplicationStateTransition: { acquireCount:

      { w: 1 }

      }, Global: { acquireCount:

      { w: 1 }

      }, Database: { acquireCount:

      { w: 1 }

      }, Collection: { acquireCount:

      { w: 1 }

      }, Mutex: { acquireCount:

      { r: 2 }

      } } flowControl:{ acquireCount: 1 } storage:{} 3530ms
      2022-06-10T20:03:52.016+0000 I  COMMAND  [conn52] command ipv6bindings_1.ipv6bindings command: find { find: "ipv6bindings", filter:

      { _id: "3101:0000:0009:11c1" }

      , limit: 1, singleBatch: true, $db: "ipv6bindings_1", $clusterTime: { clusterTime: Timestamp(1654891428, 246), signature:

      { hash: BinData(0, 1AE068B7041E0DF364A48B3B76192706D425B50D), keyId: 7072624733400858628 }

      }, lsid: { id: UUID("55caafc8-fbb1-4ede-a1d8-dd788fadb341") }, $readPreference: { mode: "nearest" } } planSummary: IDHACK keysExamined:1 docsExamined:1 cursorExhausted:1 numYields:1 nreturned:1 reslen:520 locks:{ ReplicationStateTransition: { acquireCount:

      { w: 2 }

      }, Global: { acquireCount:

      { r: 2 }

      }, Database: { acquireCount:

      { r: 2 }

      }, Collection: { acquireCount:

      { r: 2 }

      }, Mutex: { acquireCount:

      { r: 1 }

      } } storage:{} protocol:op_msg 3441ms

      Attached files: 
      1) rs.status.txt: contains ** replica set status(attached with the ticket)
      2) mongo-diag-log.tar.gz(need to upload): kindly provide support portal link to upload (contains mongod.logs and diagnostic.data for all data members) file structure is given below:
      root@xyz:~$ sudo tar -tf mongo-diag-log.tar.gz
      mongo-27029_PRIMARY_2a.tar.gz
      mongo-27029-SECONDARY_2b.tar.gz
      mongo-27029-SECONDARY_8a.tar.gz
      mongo-27029-SECONDARY_8b.tar.gz
      root@xyz:~$ tar -tf mongo-27029_PRIMARY_2a.tar.gz
      mongo-27029_PRIMARY.log
      diagnostic.data/
      diagnostic.data/metrics.interim
      diagnostic.data/metrics.2022-06-10T14-51-15Z-00000
      diagnostic.data/metrics.2022-06-10T22-51-19Z-00000
      root@xyz~$ sudo tar -tf mongo-27029-SECONDARY_2b.tar.gz
      mongo-27029-SECONDARY_2b.log
      diagnostic.data/
      diagnostic.data/metrics.2022-06-10T21-26-19Z-00000
      diagnostic.data/metrics.interim
      diagnostic.data/metrics.2022-06-10T04-56-24Z-00000
      diagnostic.data/metrics.2022-06-11T05-01-19Z-00000
      diagnostic.data/metrics.2022-06-10T13-51-31Z-00000
      root@xyz:~$ sudo tar -tf mongo-27029-SECONDARY_8a.tar.gz
      mongo-27029-SECONDARY_8a.log
      diagnostic.data/
      diagnostic.data/metrics.2022-06-09T18-40-08Z-00000
      diagnostic.data/metrics.2022-06-10T03-25-08Z-00000
      diagnostic.data/metrics.interim
      diagnostic.data/metrics.2022-06-09T01-21-07Z-00000
      diagnostic.data/metrics.2022-06-10T13-01-28Z-00000
      diagnostic.data/metrics.2022-06-10T22-36-19Z-00000
      diagnostic.data/metrics.2022-06-09T10-00-08Z-00000
      root@xyz:~$ sudo tar -tf mongo-27029-SECONDARY_8b.tar.gz
      mongo-27029-SECONDARY_8b.log
      diagnostic.data/
      diagnostic.data/metrics.2022-06-10T20-21-19Z-00000
      diagnostic.data/metrics.2022-06-10T10-56-28Z-00000
      diagnostic.data/metrics.2022-06-11T06-06-19Z-00000
      diagnostic.data/metrics.interim
      diagnostic.data/metrics.2022-06-10T01-50-08Z-00000
      diagnostic.data/metrics.2022-06-09T06-09-14Z-00000
      diagnostic.data/metrics.2022-06-09T15-55-08Z-00000

        1. image-2022-06-27-02-18-16-686.png
          image-2022-06-27-02-18-16-686.png
          65 kB
        2. image-2022-06-27-02-23-01-877.png
          image-2022-06-27-02-23-01-877.png
          55 kB
        3. image-2022-06-27-02-25-35-724.png
          image-2022-06-27-02-25-35-724.png
          52 kB
        4. image-2022-06-27-02-26-11-985.png
          image-2022-06-27-02-26-11-985.png
          69 kB
        5. image-2022-06-27-02-34-24-202.png
          image-2022-06-27-02-34-24-202.png
          100 kB
        6. image-2022-06-27-02-34-36-415.png
          image-2022-06-27-02-34-36-415.png
          97 kB
        7. image-2022-06-27-02-50-27-830.png
          image-2022-06-27-02-50-27-830.png
          99 kB
        8. image-2022-06-30-06-21-23-457.png
          image-2022-06-30-06-21-23-457.png
          27 kB
        9. image-2022-06-30-06-26-01-013.png
          image-2022-06-30-06-26-01-013.png
          69 kB
        10. image-2022-06-30-06-28-57-244.png
          image-2022-06-30-06-28-57-244.png
          31 kB
        11. image-2022-07-08-09-23-16-585.png
          image-2022-07-08-09-23-16-585.png
          184 kB
        12. image-2022-07-08-09-33-45-541.png
          image-2022-07-08-09-33-45-541.png
          55 kB
        13. image-2022-07-08-09-43-02-073.png
          image-2022-07-08-09-43-02-073.png
          13 kB
        14. image-2022-07-08-10-24-12-094.png
          image-2022-07-08-10-24-12-094.png
          85 kB
        15. image-2022-07-08-10-24-15-944.png
          image-2022-07-08-10-24-15-944.png
          85 kB
        16. image-2022-09-01-15-09-05-589.png
          image-2022-09-01-15-09-05-589.png
          54 kB
        17. image-2022-09-01-15-09-39-664.png
          image-2022-09-01-15-09-39-664.png
          71 kB
        18. image-2022-09-01-15-15-42-817.png
          image-2022-09-01-15-15-42-817.png
          85 kB
        19. rs.status.txt
          11 kB
        20. screenshot-1.png
          screenshot-1.png
          22 kB

            Assignee:
            chris.kelly@mongodb.com Chris Kelly
            Reporter:
            kg3634@gmail.com KAPIL GUPTA
            Votes:
            9 Vote for this issue
            Watchers:
            7 Start watching this issue

              Created:
              Updated:
              Resolved: