-
Type:
Task
-
Resolution: Duplicate
-
Priority:
Major - P3
-
None
-
Affects Version/s: 3.4.2
-
Component/s: Performance, Query Operations
-
None
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.