Add option to enable locking debug logging

Signed-off-by: Robin Appelman <robin@icewind.nl>

2 files changed, 58 insertions, 3 deletions

diff --git a/config/config.sample.php b/config/config.sample.php
index 3d1829e17e6..1c65b050b70 100644
--- a/config/config.sample.php
+++ b/config/config.sample.php
@@ -1448,6 +1448,16 @@ $CONFIG = array(
 'memcache.locking' => '\\OC\\Memcache\\Redis',
 
 /**
+ * Enable locking debug logging
+ *
+ * Note that this can lead to a very large volume of log items being written which can lead
+ * to performance degradation and large log files on busy instance.
+ *
+ * Thus enabling this in production for longer periods of time is not recommended
+ */
+'filelocking.debug' => false,
+
+/**
  * Disable the web based updater
  */
 'upgrade.disable-web' => false,
diff --git a/lib/private/Files/Storage/Common.php b/lib/private/Files/Storage/Common.php
index f3e3cb9e58c..f0d0faac2c0 100644
--- a/lib/private/Files/Storage/Common.php
+++ b/lib/private/Files/Storage/Common.php
@@ -53,6 +53,7 @@ use OCP\Files\InvalidPathException;
 use OCP\Files\ReservedWordException;
 use OCP\Files\Storage\ILockingStorage;
 use OCP\Lock\ILockingProvider;
+use OCP\Lock\LockedException;
 
 /**
  * Storage backend class for providing common filesystem operation methods
@@ -79,6 +80,9 @@ abstract class Common implements Storage, ILockingStorage {
 	protected $mountOptions = [];
 	protected $owner = null;
 
+	private $shouldLogLocks = null;
+	private $logger;
+
 	public function __construct($parameters) {
 	}
 
@@ -681,7 +685,18 @@ abstract class Common implements Storage, ILockingStorage {
 	 * @throws \OCP\Lock\LockedException
 	 */
 	public function acquireLock($path, $type, ILockingProvider $provider) {
-		$provider->acquireLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		$logger = $this->getLockLogger();
+		if ($logger) {
+			$typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive';
+			$logger->info('acquire ' . $typeString . ' lock on ' . $path, ['app' => 'locking']);
+		}
+		try {
+			$provider->acquireLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+		}
 	}
 
 	/**
@@ -690,7 +705,18 @@ abstract class Common implements Storage, ILockingStorage {
 	 * @param \OCP\Lock\ILockingProvider $provider
 	 */
 	public function releaseLock($path, $type, ILockingProvider $provider) {
-		$provider->releaseLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		$logger = $this->getLockLogger();
+		if ($logger) {
+			$typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive';
+			$logger->info('release ' . $typeString . ' lock on ' . $path, ['app' => 'locking']);
+		}
+		try {
+			$provider->releaseLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+		}
 	}
 
 	/**
@@ -699,7 +725,26 @@ abstract class Common implements Storage, ILockingStorage {
 	 * @param \OCP\Lock\ILockingProvider $provider
 	 */
 	public function changeLock($path, $type, ILockingProvider $provider) {
-		$provider->changeLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		$logger = $this->getLockLogger();
+		if ($logger) {
+			$typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive';
+			$logger->info('change lock on ' . $path . ' to ' . $typeString, ['app' => 'locking']);
+		}
+		try {
+			$provider->changeLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+		}
+	}
+
+	private function getLockLogger() {
+		if (is_null($this->shouldLogLocks)) {
+			$this->shouldLogLocks = \OC::$server->getConfig()->getSystemValue('filelocking.debug', false);
+			$this->logger = $this->shouldLogLocks ? \OC::$server->getLogger() : null;
+		}
+		return $this->logger;
 	}
 
 	/**