Merge pull request #3465 from nextcloud/storage-log-locks

Add option to enable locking debug logging

4 files changed, 86 insertions, 3 deletions

diff --git a/lib/private/Files/Storage/Common.php b/lib/private/Files/Storage/Common.php
index f3e3cb9e58c..6e5799be34c 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,25 +685,101 @@ 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(
+				sprintf(
+					'acquire %s lock on "%s" on storage "%s"',
+					$typeString,
+					$path,
+					$this->getId()
+				),
+				[
+					'app' => 'locking',
+				]
+			);
+		}
+		try {
+			$provider->acquireLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+			throw $e;
+		}
 	}
 
 	/**
 	 * @param string $path
 	 * @param int $type \OCP\Lock\ILockingProvider::LOCK_SHARED or \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE
 	 * @param \OCP\Lock\ILockingProvider $provider
+	 * @throws \OCP\Lock\LockedException
 	 */
 	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(
+				sprintf(
+					'release %s lock on "%s" on storage "%s"',
+					$typeString,
+					$path,
+					$this->getId()
+				),
+				[
+					'app' => 'locking',
+				]
+			);
+		}
+		try {
+			$provider->releaseLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+			throw $e;
+		}
 	}
 
 	/**
 	 * @param string $path
 	 * @param int $type \OCP\Lock\ILockingProvider::LOCK_SHARED or \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE
 	 * @param \OCP\Lock\ILockingProvider $provider
+	 * @throws \OCP\Lock\LockedException
 	 */
 	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(
+				sprintf(
+					'change lock on "%s" to %s on storage "%s"',
+					$path,
+					$typeString,
+					$this->getId()
+				),
+				[
+					'app' => 'locking',
+				]
+			);
+		}
+		try {
+			$provider->changeLock('files/' . md5($this->getId() . '::' . trim($path, '/')), $type);
+		} catch (LockedException $e) {
+			if ($logger) {
+				$logger->logException($e);
+			}
+			throw $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;
 	}
 
 	/**
diff --git a/lib/private/Files/Storage/Storage.php b/lib/private/Files/Storage/Storage.php
index 49a714587a7..281a8284107 100644
--- a/lib/private/Files/Storage/Storage.php
+++ b/lib/private/Files/Storage/Storage.php
@@ -107,6 +107,7 @@ interface Storage extends \OCP\Files\Storage {
 	 * @param string $path The path of the file to release the lock for
 	 * @param int $type \OCP\Lock\ILockingProvider::LOCK_SHARED or \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE
 	 * @param \OCP\Lock\ILockingProvider $provider
+	 * @throws \OCP\Lock\LockedException
 	 */
 	public function releaseLock($path, $type, ILockingProvider $provider);
 
diff --git a/lib/public/Files/Storage.php b/lib/public/Files/Storage.php
index cf67879908c..1532c84b621 100644
--- a/lib/public/Files/Storage.php
+++ b/lib/public/Files/Storage.php
@@ -425,6 +425,7 @@ interface Storage extends IStorage {
 	 * @param string $path The path of the file to acquire the lock for
 	 * @param int $type \OCP\Lock\ILockingProvider::LOCK_SHARED or \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE
 	 * @param \OCP\Lock\ILockingProvider $provider
+	 * @throws \OCP\Lock\LockedException
 	 * @since 8.1.0
 	 */
 	public function releaseLock($path, $type, ILockingProvider $provider);
diff --git a/lib/public/Files/Storage/ILockingStorage.php b/lib/public/Files/Storage/ILockingStorage.php
index 635c607537f..ac61e9a062e 100644
--- a/lib/public/Files/Storage/ILockingStorage.php
+++ b/lib/public/Files/Storage/ILockingStorage.php
@@ -46,6 +46,7 @@ interface ILockingStorage {
 	 * @param string $path The path of the file to acquire the lock for
 	 * @param int $type \OCP\Lock\ILockingProvider::LOCK_SHARED or \OCP\Lock\ILockingProvider::LOCK_EXCLUSIVE
 	 * @param \OCP\Lock\ILockingProvider $provider
+	 * @throws \OCP\Lock\LockedException
 	 * @since 9.0.0
 	 */
 	public function releaseLock($path, $type, ILockingProvider $provider);