2016-05-05 81 views
0

我已经为我正在开发的多人游戏编写了后端节点服务器,并且大部分时间每个请求都需要大约20-100ms才能解决。然而,有时候(也许50个请求中有1个)我会做同样的请求,需要2000 + ms来解决。查询时间猫鼬偶尔需要3-4秒

服务器完全写在node.js中,托管在heroku上。我正在使用猫鼬来调用数据库。

以下是日志的屏幕截图,在顶部可以看到查询的功能。请求以19:03:03.68发送,响应以19:03:03.73发送出去,将所有数据结束保存在19:03:03.74。 Heroku将请求记录为58ms,这是期望的结果。

下面是问题发生的时间。您可以看到来自两个独立客户端的多个请求(每个客户端每秒发送约1个请求,这是正确的)。然而,请求建立起来并且在大约2000-5000ms之后,它们都会一个接一个地快速解决。我试着缩小了这个问题,但没有多少运气,但我相信这与我查询数据库时相关,因为您可以看到多个请求进入,但直到2300ms之后,数据库的第一个查询才真正解决。据我所知,这些请求与在20-100毫秒内解析并完全随机发生的请求相同。

Console Log

实际的代码类似于此服务器上(简化了这一问题的缘故):

console.log (“request received”); 
    Game.findOne({‘id’: gameID}, function(err, theGame){ 
     console.log("First Query"); 

我还开了蒙戈外壳数据库来寻找查询服用过多的时间量(> 2000毫秒),此代码:

db.system.profile.find({millis: {$gt : 2000} }).sort({ ts: 1}); 

下面是稍微修改的结果,其中应包括相关的一切:

{ "op" : "update", "ns" : "theDb.players", "query" : 
    { "_id" : ObjectId("572b8eb242d70903005df0df") 
    }, "updateobj" : 
    { "$set" : 
    { "lastSeen" : ISODate("2016-05-05T18:19:30.761Z"), "timeElapsed" : 16 
    } 
}, "nscanned" : 1, "nscannedObjects" : 1, "nMatched" : 1, "nModified" : 1, "fastmod" : true, "keyUpdates" : 0, "writeConflicts" : 0, "numYield" : 0, "locks" : 
{ "Global" : 
    { "acquireCount": 
    { "r" : NumberLong(2), "w" : NumberLong(2) } 
    }, "MMAPV1Journal" : 
    { "acquireCount" : 
    { "w" : NumberLong(2) }, "acquireWaitCount" : 
    { "w" : NumberLong(1) }, "timeAcquiringMicros" : 
    { "w" : NumberLong(7294179) } 
    }, "Database" : 
    { "acquireCount" : 
    { "w" : NumberLong(2) } 
    }, "Collection" : 
    { "acquireCount" : 
    { "W" : NumberLong(1) } 
    }, "oplog" : 
    { "acquireCount" : 
    { "w" : NumberLong(1) } 
    } 
}, "milli" : 2298, "execStats" : {}, "ts" : ISODate("2016-05-05T18:19:33.060Z") 

第二个结果:

{ "op" : "update", "ns" : "theDb.connections", "query" : 
    { "_id" : ObjectId("572b8eaf42d70903005df0dd") 
    }, "updateobj" : 
    { "$set" : 
    { "internalCounter" : 3, "lastCount" : 3, "lastSeen" : ISODate("2016-05-05T18:19:30.761Z"), "playerID" : 128863276517, "sinceLast" : 0 
    } 
    }, "nscanned" : 1, "nscannedObjects" : 1, "nMatched" : 1, "nModified" : 1, "keyUpdates" : 0, "writeConflicts" : 0, "numYield" : 0, "locks" : 
    { "Global" : 
    { "acquireCount" : 
     { "r" : NumberLong(2), "w" : NumberLong(2) 
     } 
    }, "MMAPV1Journal" : 
    { "acquireCount" : 
    { "w" : NumberLong(2) }, "acquireWaitCount" : 
     { "w" : NumberLong(1) }, "timeAcquiringMicros" : 
     { "w" :NumberLong(7294149) } 
    }, "Database" : 
    { "acquireCount" : 
     { "w" : NumberLong(2) } 
    }, "Collection" : 
    { "acquireCount" : 
     { "W" : NumberLong(1) } 
    }, "oplog" : 
    { "acquireCount" : 
     { "w" : NumberLong(1) } 
    } 
    }, "millis" : 2299, "execStats" : {},"ts" : ISODate("2016-05-05T18:19:33.061Z") 

我真的需要确保的延迟提出任何要求不超过500毫秒,否则在游戏本身很伤脑筋。对于可能造成这种情况的原因以及如何弄清楚,我真的很茫然。

我假设问题的原因是timeAcquiringMicros太长了。我不确定是什么造成这种情况。

*请注意,客户端正在请求数据只有标准的http请求,我目前没有使用任何套接字。

回答

2

好吧,我终于解决了这个问题。问题实际上并没有与我所做的任何事情联系在一起。我正在使用mlab提供的有关heroku的沙箱计划,我的应用程序正在与其他人一起使用沙盒计划竞争处理时间。他们的查询减慢了数据库的响应时间,导致了这些峰值。

解决方案:我不得不升级到他们的共享集群计划。由于升级我没有任何查询时间不规范。