-
Type:
Bug
-
Resolution: Incomplete
-
Priority:
Major - P3
-
None
-
Affects Version/s: None
-
Component/s: WiredTiger
-
None
-
Fully Compatible
-
ALL
-
None
-
3
-
None
-
None
-
None
-
None
-
None
-
None
-
None
I find, in the slow query logs, queries that make no sense. An excerpt is below:
2017-08-17T09:32:03.964+0200 I COMMAND [conn8550] query XX.statistic query: { date: new Date(1502917200000), monitor: [ "monitor|general" ] } planSummary: IXSCAN { monitor: 1, date: 1 } ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:1 reslen:155 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } 23606ms
2017-08-17T09:32:03.964+0200 I COMMAND [conn8519] query XX.trigger query: { token: "live/dynamic_subscription/live", status: true, retired: false, ref: 17 } planSummary: IXSCAN { token: 1 } ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:1 reslen:13278 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } 33632ms
2017-08-17T09:32:03.964+0200 I COMMAND [conn8493] query XX.trigger query: { token: "live/product_recommender/live", status: true, retired: false, ref: 20 } planSummary: IXSCAN { token: 1 } ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:1 reslen:22196 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } 29860ms
2017-08-17T09:32:03.970+0200 I COMMAND [conn8518] query XXX.statistic query: { date: new Date(1502917200000), monitor: [ "monitor|general" ] } planSummary: IXSCAN { monitor: 1, date: 1 } ntoskip:0 nscanned:1 nscannedObjects:1 keyUpdates:0 writeConflicts:0 numYields:2 nreturned:1 reslen:155 locks:{ Global: { acquireCount: { r: 6 } }, Database: { acquireCount: { r: 3 } }, Collection: { acquireCount: { r: 3 } } } 20648ms
20 seconds for a query that hits an index?
Sometimes I also get queries on an ID:
2017-08-17T10:00:19.909+0200 I COMMAND [conn10311] query XX.dlv_cs_similar query: { _id: ObjectId('59954d0fcaf95bd83e8b51f6') } planSummary: IDHACK ntoskip:0 nscanned:0 nscannedObjects:0 idhack:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:20 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } 4701ms
It occurs suddenly, every several minutes. It affects 20-30 queries, than nothing. It's like, from time to time, there is a global lock that occurs.
More details about my setup:
- System: Debian 9
- Mongo version: 3.0.15
- 2 SSD disks in raid0
- Mongo RAM usage: 13.4 GB / 128 G
- CPU @20%
Mongostat does not give anything suspicious:
12 3781 333 96 174 525|0 1.6 18.5 0 16.7G 15.5G 0|1 21|9 641k 12m 155 rplset04 PRI 09:54:14
12 4344 380 105 188 295|0 1.6 18.5 0 16.7G 15.5G 0|0 23|12 708k 11m 137 rplset04 PRI 09:54:15
10 3221 319 133 163 241|0 1.7 18.5 0 16.7G 15.5G 0|0 23|7 543k 14m 128 rplset04 PRI 09:54:16
18 2915 319 114 172 90|0 1.7 18.5 0 16.7G 15.5G 0|0 22|10 511k 17m 128 rplset04 PRI 09:54:17
One primary, one replica, one voter.
For multitenancy, I am using one DB per client (600 databases). They take 185 GB on the disk.
- is related to
-
-
- Closed
-