Add logging total lock time

It is useful to know the total time that a lock was acquired for.

lib/master_lock.rb

@@ -2,6 +2,7 @@
 
 require 'logger'
 require 'socket'
+require 'json'
 
 # MasterLock is a system for interprocess locking. Resources can be locked by a
 # string identifier such that only one thread may have the lock at a time. Lock
@@ -56,6 +57,8 @@ class << self
     # @raise [LockNotAcquiredError] if the lock cannot be acquired before the
     #   timeout
     def synchronize(key, options = {})
+      start_time = Time.now
+
       check_configured
       raise NotStartedError unless @registry
 
@@ -88,10 +91,16 @@ def synchronize(key, options = {})
         yield
       ensure
         @registry.unregister(registration)
+
+        info = {
+          key: key,
+          lock_time: (Time.now - start_time).to_f
+        }
+
         if lock.release
-          logger.debug("Released lock #{key}")
+          logger.debug(info.merge(message: "Released lock.").to_json)
         else
-          logger.warn("Failed to release lock #{key}")
+          logger.warn(info.merge(message: "Failed to release lock.").to_json)
         end
       end
     end