From 8c1ed7507aae772fdc274e98bb2fa31d9d3f8f99 Mon Sep 17 00:00:00 2001 From: Robin Appelman Date: Mon, 13 Feb 2017 15:03:46 +0100 Subject: [PATCH 1/4] Add option to enable locking debug logging Signed-off-by: Robin Appelman --- config/config.sample.php | 10 ++++++ lib/private/Files/Storage/Common.php | 51 ++++++++++++++++++++++++++-- 2 files changed, 58 insertions(+), 3 deletions(-) diff --git a/config/config.sample.php b/config/config.sample.php index 3d1829e17e..1c65b050b7 100644 --- a/config/config.sample.php +++ b/config/config.sample.php @@ -1447,6 +1447,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 */ diff --git a/lib/private/Files/Storage/Common.php b/lib/private/Files/Storage/Common.php index f3e3cb9e58..f0d0faac2c 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; } /** From fa684c0ef074d3d76beb9b0e735c8c0103d2bdb0 Mon Sep 17 00:00:00 2001 From: Morris Jobke Date: Mon, 13 Feb 2017 15:32:57 -0600 Subject: [PATCH 2/4] Add comment about log.condition Signed-off-by: Morris Jobke --- config/config.sample.php | 1 + 1 file changed, 1 insertion(+) diff --git a/config/config.sample.php b/config/config.sample.php index 1c65b050b7..228233452e 100644 --- a/config/config.sample.php +++ b/config/config.sample.php @@ -1454,6 +1454,7 @@ $CONFIG = array( * to performance degradation and large log files on busy instance. * * Thus enabling this in production for longer periods of time is not recommended + * or should be used together with the ``log.condition`` setting. */ 'filelocking.debug' => false, From a422a59f991daab9f87c628ad678455909d38622 Mon Sep 17 00:00:00 2001 From: Lukas Reschke Date: Mon, 13 Feb 2017 22:49:44 +0100 Subject: [PATCH 3/4] Add storage to log item as well Signed-off-by: Lukas Reschke --- lib/private/Files/Storage/Common.php | 36 +++++++++++++++++++++++++--- 1 file changed, 33 insertions(+), 3 deletions(-) diff --git a/lib/private/Files/Storage/Common.php b/lib/private/Files/Storage/Common.php index f0d0faac2c..0a0604ddd9 100644 --- a/lib/private/Files/Storage/Common.php +++ b/lib/private/Files/Storage/Common.php @@ -688,7 +688,17 @@ abstract class Common implements Storage, ILockingStorage { $logger = $this->getLockLogger(); if ($logger) { $typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive'; - $logger->info('acquire ' . $typeString . ' lock on ' . $path, ['app' => 'locking']); + $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); @@ -708,7 +718,17 @@ abstract class Common implements Storage, ILockingStorage { $logger = $this->getLockLogger(); if ($logger) { $typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive'; - $logger->info('release ' . $typeString . ' lock on ' . $path, ['app' => 'locking']); + $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); @@ -728,7 +748,17 @@ abstract class Common implements Storage, ILockingStorage { $logger = $this->getLockLogger(); if ($logger) { $typeString = ($type === ILockingProvider::LOCK_SHARED) ? 'shared' : 'exclusive'; - $logger->info('change lock on ' . $path . ' to ' . $typeString, ['app' => 'locking']); + $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); From 7f73ee0764b0b00e7235a7f6b017cc071cdc0fe7 Mon Sep 17 00:00:00 2001 From: Morris Jobke Date: Mon, 13 Feb 2017 18:03:35 -0600 Subject: [PATCH 4/4] Add missing PHPDoc and properly throw exception Signed-off-by: Morris Jobke --- lib/private/Files/Storage/Common.php | 5 +++++ lib/private/Files/Storage/Storage.php | 1 + lib/public/Files/Storage.php | 1 + lib/public/Files/Storage/ILockingStorage.php | 1 + 4 files changed, 8 insertions(+) diff --git a/lib/private/Files/Storage/Common.php b/lib/private/Files/Storage/Common.php index 0a0604ddd9..6e5799be34 100644 --- a/lib/private/Files/Storage/Common.php +++ b/lib/private/Files/Storage/Common.php @@ -706,6 +706,7 @@ abstract class Common implements Storage, ILockingStorage { if ($logger) { $logger->logException($e); } + throw $e; } } @@ -713,6 +714,7 @@ abstract class Common implements Storage, ILockingStorage { * @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) { $logger = $this->getLockLogger(); @@ -736,6 +738,7 @@ abstract class Common implements Storage, ILockingStorage { if ($logger) { $logger->logException($e); } + throw $e; } } @@ -743,6 +746,7 @@ abstract class Common implements Storage, ILockingStorage { * @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) { $logger = $this->getLockLogger(); @@ -766,6 +770,7 @@ abstract class Common implements Storage, ILockingStorage { if ($logger) { $logger->logException($e); } + throw $e; } } diff --git a/lib/private/Files/Storage/Storage.php b/lib/private/Files/Storage/Storage.php index 49a714587a..281a828410 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 cf67879908..1532c84b62 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 635c607537..ac61e9a062 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);