github/overleaf
1
0
Fork 0
mirror of https://github.com/overleaf/overleaf.git synced 2024-11-21 20:47:08 -05:00
Code Issues Projects Releases Packages Wiki Activity

replace verbose logging by slow query log

Browse source
This commit is contained in:
Brian Gough 2017-05-18 15:04:12 +01:00
parent 95596061d4
commit a550078071
1 changed files with 12 additions and 5 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

17
services/document-updater/app/coffee/LockManager.coffee
View file

@ -7,6 +7,8 @@ logger = require "logger-sharelatex"
os = require "os"
crypto = require "crypto"
Profiler = require "./Profiler"
HOST = os.hostname()
PID = process.pid
RND = crypto.randomBytes(4).toString('hex')
@ -30,33 +32,36 @@ module.exports = LockManager =
tryLock : (doc_id, callback = (err, isFree)->)->
lockValue = LockManager.randomLock()
key = keys.blockingKey(doc_id:doc_id)
logger.log {doc_id: doc_id, key: key}, "tryLock"
profile = new Profiler("tryLock", {doc_id, key, lockValue})
rclient.set key, lockValue, "EX", @LOCK_TTL, "NX", (err, gotLock)->
return callback(err) if err?
if gotLock == "OK"
metrics.inc "doc-not-blocking"
logger.log {doc_id: doc_id, key: key, lockValue: lockValue}, "got lock"
profile.log("got lock").end()
callback err, true, lockValue
else
metrics.inc "doc-blocking"
logger.log {doc_id: doc_id, key: key}, "doc is locked"
profile.log("doc is locked").end()
callback err, false
getLock: (doc_id, callback = (error, lockValue) ->) ->
startTime = Date.now()
testInterval = LockManager.LOCK_TEST_INTERVAL
profile = new Profiler("getLock", {doc_id})
do attempt = () ->
if Date.now() - startTime > LockManager.MAX_LOCK_WAIT_TIME
e = new Error("Timeout")
e.doc_id = doc_id
profile.log("timeout").end()
return callback(e)
LockManager.tryLock doc_id, (error, gotLock, lockValue) ->
return callback(error) if error?
profile.log("tryLock")
if gotLock
profile.end()
callback(null, lockValue)
else
logger.log {doc_id: doc_id, delay: testInterval}, "will retry lock"
setTimeout attempt, testInterval
# back off when the lock is taken to avoid overloading
testInterval = Math.min(testInterval * 2, LockManager.MAX_TEST_INTERVAL)
@ -75,12 +80,14 @@ module.exports = LockManager =
releaseLock: (doc_id, lockValue, callback)->
key = keys.blockingKey(doc_id:doc_id)
profile = new Profiler("releaseLock", {doc_id, key, lockValue})
rclient.eval LockManager.unlockScript, 1, key, lockValue, (err, result) ->
if err?
return callback(err)
else if result? and result isnt 1 # successful unlock should release exactly one key
profile.log("unlockScript:expired-lock").end()
logger.error {doc_id:doc_id, key:key, lockValue:lockValue, redis_err:err, redis_result:result}, "unlocking error"
return callback(new Error("tried to release timed out lock"))
else
logger.log {doc_id:doc_id, key:key, lockValue:lockValue}, "released lock"
profile.log("unlockScript:ok").end()
callback(err,result)