Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-3077

Java driver upgrade causing slowness to some calls

    XMLWordPrintable

    Details

    • Type: Task
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Duplicate
    • Affects Version/s: 3.4.2
    • Fix Version/s: None
    • Labels:
      None

      Description

      We are in process of upgrading java driver from version 2.14 to 3.4.2. The MongoDB server ver is at 3.2.19 and the goal is to upgrade server version to 3.4 once driver has been successfully upgraded. We are experiencing slowness to some calls on the new driver interacting with server version 3.2. Although I won't be able to link the app code, here's some comparison details between old and new driver. These are all findAll() queries.

      2.14 Driver Query time
      Run 1 291ms
      Run 2 215ms
      Run 3 106ms
      Run 4 210ms
      Run 5 182ms
      Avg 277ms

       

      3.4.2 Driver Query time
      Run 1 599ms
      Run 2 398ms
      Run 3 218ms
      Run 4 396ms
      Run 5 294ms
      Avg 491ms

      We added more timing information around different calls and compared between the Old and new driver. Extracting some info here.

      Old Driver:

       2018-11-08 01:46:23,083 DEBUG START:1541663167 [util.BatchMessageIterator] [main] Message query is: { "_id" : { "$gt" : { "$oid" : "5be3e89c498e8dc38e92c2af"} , "$lte" : { "$oid" : "5be3e9ce498e8dc38e92c2b0"}}}
      2018-11-08 01:46:23,090 INFO  START:1541663167 [util.WallClockTimer] [main] Timing around first data.hasNext() call took 6 ms
      2018-11-08 01:46:23,091 INFO  START:1541663167 [util.WallClockTimer] [main] Timing around data.size() call took 1 ms
      2018-11-08 01:46:23,092 INFO  START:1541663167 [util.WallClockTimer] [main] Timing around data.next() call took 0 ms
      2018-11-08 01:46:23,290 INFO  START:1541663167 [util.WallClockTimer] [main] Timing around third data.hasNext() call took 0 ms

      New Driver:

       2018-11-08 00:12:55,195 DEBUG START:1541657547 [util.BatchMessageIterator] [main] Message query is: { "_id" : { "$gt" : { "$oid" : "5be3d24a593a9d2842725f20"} , "$lte" : { "$oid" : "5be3d3e6593a9d2842725f21"}}}
      2018-11-08 00:12:55,381 DEBUG START:1541657547 [event.ThreadLocalCommandListener] [main] Command [find] succeeded and took 185 ms
      2018-11-08 00:12:55,383 INFO  START:1541657547 [util.WallClockTimer] [main] Timing around first data.hasNext() call took 187 ms
      2018-11-08 00:12:55,482 DEBUG START:1541657547 [event.ThreadLocalCommandListener] [main] Command [count] succeeded and took 1 ms
      2018-11-08 00:12:55,483 INFO  START:1541657547 [util.WallClockTimer] [main] Timing around data.size() call took 99 ms

      Looking at that data, we noticed:
      1. For data.size() calls, old driver consistently takes ~1ms, and new driver takes from 8ms to 99ms
      2. For data.hasNext() calls, seems like the first instance of hasNext() call with old driver takes from 1ms to 6ms, and new driver is taking from 5ms to 389ms. But the other hasNext() calls seems fine?
      3. For data.next() calls, there's not much difference between old driver and new driver.

       

      Looking for insight if you're aware of any bug in the new driver version that could possibly cause this behavior? Any help would be great for us to proceed with upgrading our mongoDB server versions across the board.

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              Unassigned Unassigned
              Reporter:
              manan@indeed.com Manan Shah
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: