Details
-
Bug
-
Resolution: Duplicate
-
Major - P3
-
None
-
3.0.3
-
None
-
ALL
Description
There is a very strange issue when new Mongodb 3.0.3 instance running ,
queries works well in most time , but suddenly it will cost more than 10 seconds.
Here is the output from the db log, first the short one and then the long one:
2015-05-18T15:24:42.879+0800 I COMMAND [conn22550] command Radius.$cmd command: findAndModify { findandmodify: "RadiusAccount", query: { acctsessionid: "90-3C-92-C2-EA-38-9659892E" }, sort: { _id: -1 }, update: { $set: { acctsessionid: "90-3C-92-C2-EA-38-9659892E", username: "18918978008", nasipaddress: "183.192.114.254", nasportid: "0000000125", nasporttype: 19, nasport: 1, sessiontime: 2700, inputoctets: "5456078", outputoctets: "694505", ipaddress: "100.65.154.152", calledstationid: "00-19-70-FE-14-5B:i-Shanghai", callingstationid: "90:3C:92:C2:EA:38", userlocation: "mobile&0206050021000460", operator: 2, userlevel: "1", nasipv6address: "::", framedinterfaceid: "9d27:dc24:ee63:9de5", loginipv6host: "2409:88a4:8000:16:9d27:dc24:ee63:9de5", acctipv6inputoctets: "6004364279808", acctipv6outputoctets: "19546396164096", nasidentifier: "0206050021000460", lut: new Date(1431933882876) } }, new: true, upsert: true } update: { $set: { acctsessionid: "90-3C-92-C2-EA-38-9659892E", username: "18918978008", nasipaddress: "183.192.114.254", nasportid: "0000000125", nasporttype: 19, nasport: 1, sessiontime: 2700, inputoctets: "5456078", outputoctets: "694505", ipaddress: "100.65.154.152", calledstationid: "00-19-70-FE-14-5B:i-Shanghai", callingstationid: "90:3C:92:C2:EA:38", userlocation: "mobile&0206050021000460", operator: 2, userlevel: "1", nasipv6address: "::", framedinterfaceid: "9d27:dc24:ee63:9de5", loginipv6host: "2409:88a4:8000:16:9d27:dc24:ee63:9de5", acctipv6inputoctets: "6004364279808", acctipv6outputoctets: "19546396164096", nasidentifier: "0206050021000460", lut: new Date(1431933882876) } } nscanned:1 nscannedObjects:1 nMatched:1 nModified:1 keyUpdates:0 writeConflicts:0 numYields:0 reslen:865 locks:{ Global: { acquireCount: { w: 2 } }, Database: { acquireCount: { w: 2 } }, Collection: { acquireCount: { w: 1 } }, oplog: { acquireCount: { w: 1 } } } 1ms
|
2015-05-17T00:12:46.422+0800 I COMMAND [conn12974] command Radius.$cmd command: findAndModify { findandmodify: "RadiusAccount", query: { acctsessionid: "090de21e9375571fece70d267c3e79a705e60cca2b751a64" }, sort: { _id: -1 }, update: { $set: { acctsessionid: "090de21e9375571fece70d267c3e79a705e60cca2b751a64", username: "18817339667", nasipaddress: "222.66.249.120", nasportid: "CPD11225", nasporttype: 19, nasport: 1, stoptime: new Date(1431792754077), sessiontime: 114, inputoctets: "57753", outputoctets: "320987", terminatecause: "Admin-Reset", stopdelay: 0, ipaddress: "101.92.170.191", calledstationid: "ishanghai", callingstationid: "D0:DF:9A:46:F2:78", userlocation: "telecom&CPD11225", operator: 1, userlevel: "1", servicetype: "Framed-User", nasidentifier: "2bb2f23ce9c21f721e9087ee9899ff76", lut: new Date(1431792754078) } }, new: true, upsert: true } keyUpdates:0 writeConflicts:0 numYields:35862 reslen:707 locks:{ Global: { acquireCount: { w: 35864 } }, Database: { acquireCount: { w: 35864 } }, Collection: { acquireCount: { w: 35863 } }, oplog: { acquireCount: { w: 1 } } } 12341ms
|
Actully , both the same query , it cost only 1ms when I run them manually.
Here is my config file :
processManagement :
|
fork : true
|
pidFilePath : /home/Radius/Rad.pid
|
systemLog:
|
destination : file
|
path : /home/Radius/Log/Rad_Log
|
logAppend : true
|
|
storage:
|
dbPath : /home/Radius/Data_WiredTiger
|
engine : wiredTiger
|
wiredTiger :
|
engineConfig :
|
cacheSizeGB : 20
|
directoryPerDB : true
|
|
net:
|
port : 40001
|
maxIncomingConnections : 2000
|
|
security:
|
authorization : enabled
|
keyFile : /home/Radius/Keys/RadKey
|
|
replication:
|
replSetName : rad
|
|
auditLog:
|
destination : file
|
format : JSON
|
path : /home/Radius/Log/RadiusDBAduit.json
|
filter : '{ atype : {$nin : ["authenticate"]} }'
|
Please give some advise on tracing the issue .
Thanks .
Carl Dong
Attachments
Issue Links
- duplicates
-
SERVER-15225 CachedPlanStage should execute for trial period and re-plan if query performs poorly
-
- Closed
-
- is duplicated by
-
SERVER-18602 A query will take very long time in a sudden but it works well in most time.
-
- Closed
-
- related to
-
SERVER-17054 Index not being utilized, on occasion.
-
- Closed
-