 	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"
 		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"
 				callback err, true, lockValue
 			else
 				metrics.inc "doc-blocking"
-				logger.log {doc_id}, "doc is locked"
+				logger.log {doc_id: doc_id, key: key}, "doc is locked"
 				callback err, false
 
 	getLock: (doc_id, callback = (error, lockValue) ->) ->

				if gotLock
					callback(null, lockValue)
				else
					setTimeout attempt, testInterval
					# back off when the lock is taken to avoid overloading
					testInterval = Math.min(testInterval * 2, LockManager.MAX_TEST_INTERVAL)

		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
				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"
				callback(err,result)
