1 files changed, 196 insertions, 139 deletions

diff --git a/lib/private/Log.php b/lib/private/Log.php
index 0415967f0f0..301a25d12c1 100644
--- a/lib/private/Log.php
+++ b/lib/private/Log.php
@@ -1,48 +1,28 @@
 <?php
 
 declare(strict_types=1);
-
 /**
- * @copyright Copyright (c) 2016, ownCloud, Inc.
- *
- * @author Arthur Schiwon <blizzz@arthur-schiwon.de>
- * @author Bart Visscher <bartv@thisnet.nl>
- * @author Bernhard Posselt <dev@bernhard-posselt.com>
- * @author Christoph Wurst <christoph@winzerhof-wurst.at>
- * @author Joas Schilling <coding@schilljs.com>
- * @author Julius Härtl <jus@bitgrid.net>
- * @author Morris Jobke <hey@morrisjobke.de>
- * @author Olivier Paroz <github@oparoz.com>
- * @author Robin Appelman <robin@icewind.nl>
- * @author Roeland Jago Douma <roeland@famdouma.nl>
- * @author Thomas Müller <thomas.mueller@tmit.eu>
- * @author Victor Dubiniuk <dubiniuk@owncloud.com>
- *
- * @license AGPL-3.0
- *
- * This code is free software: you can redistribute it and/or modify
- * it under the terms of the GNU Affero General Public License, version 3,
- * as published by the Free Software Foundation.
- *
- * This program is distributed in the hope that it will be useful,
- * but WITHOUT ANY WARRANTY; without even the implied warranty of
- * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
- * GNU Affero General Public License for more details.
- *
- * You should have received a copy of the GNU Affero General Public License, version 3,
- * along with this program. If not, see <http://www.gnu.org/licenses/>
- *
+ * SPDX-FileCopyrightText: 2016-2024 Nextcloud GmbH and Nextcloud contributors
+ * SPDX-FileCopyrightText: 2016 ownCloud, Inc.
+ * SPDX-License-Identifier: AGPL-3.0-only
  */
 namespace OC;
 
+use Exception;
 use Nextcloud\LogNormalizer\Normalizer;
-use OCP\Log\IDataLogger;
-use function array_merge;
+use OC\AppFramework\Bootstrap\Coordinator;
 use OC\Log\ExceptionSerializer;
+use OCP\EventDispatcher\IEventDispatcher;
 use OCP\ILogger;
+use OCP\IRequest;
+use OCP\IUserSession;
+use OCP\Log\BeforeMessageLoggedEvent;
+use OCP\Log\IDataLogger;
 use OCP\Log\IFileBased;
 use OCP\Log\IWriter;
 use OCP\Support\CrashReport\IRegistry;
+use Throwable;
+use function array_merge;
 use function strtr;
 
 /**
@@ -55,42 +35,20 @@ use function strtr;
  * MonoLog is an example implementing this interface.
  */
 class Log implements ILogger, IDataLogger {
+	private ?bool $logConditionSatisfied = null;
+	private ?IEventDispatcher $eventDispatcher = null;
+	private int $nestingLevel = 0;
+
+	public function __construct(
+		private IWriter $logger,
+		private SystemConfig $config,
+		private Normalizer $normalizer = new Normalizer(),
+		private ?IRegistry $crashReporters = null,
+	) {
+	}
 
-	/** @var IWriter */
-	private $logger;
-
-	/** @var SystemConfig */
-	private $config;
-
-	/** @var boolean|null cache the result of the log condition check for the request */
-	private $logConditionSatisfied = null;
-
-	/** @var Normalizer */
-	private $normalizer;
-
-	/** @var IRegistry */
-	private $crashReporters;
-
-	/**
-	 * @param IWriter $logger The logger that should be used
-	 * @param SystemConfig $config the system config object
-	 * @param Normalizer|null $normalizer
-	 * @param IRegistry|null $registry
-	 */
-	public function __construct(IWriter $logger, SystemConfig $config = null, $normalizer = null, IRegistry $registry = null) {
-		// FIXME: Add this for backwards compatibility, should be fixed at some point probably
-		if ($config === null) {
-			$config = \OC::$server->getSystemConfig();
-		}
-
-		$this->config = $config;
-		$this->logger = $logger;
-		if ($normalizer === null) {
-			$this->normalizer = new Normalizer();
-		} else {
-			$this->normalizer = $normalizer;
-		}
-		$this->crashReporters = $registry;
+	public function setEventDispatcher(IEventDispatcher $eventDispatcher): void {
+		$this->eventDispatcher = $eventDispatcher;
 	}
 
 	/**
@@ -98,9 +56,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function emergency(string $message, array $context = []) {
+	public function emergency(string $message, array $context = []): void {
 		$this->log(ILogger::FATAL, $message, $context);
 	}
 
@@ -112,9 +69,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function alert(string $message, array $context = []) {
+	public function alert(string $message, array $context = []): void {
 		$this->log(ILogger::ERROR, $message, $context);
 	}
 
@@ -125,9 +81,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function critical(string $message, array $context = []) {
+	public function critical(string $message, array $context = []): void {
 		$this->log(ILogger::ERROR, $message, $context);
 	}
 
@@ -137,9 +92,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function error(string $message, array $context = []) {
+	public function error(string $message, array $context = []): void {
 		$this->log(ILogger::ERROR, $message, $context);
 	}
 
@@ -151,9 +105,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function warning(string $message, array $context = []) {
+	public function warning(string $message, array $context = []): void {
 		$this->log(ILogger::WARN, $message, $context);
 	}
 
@@ -162,9 +115,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function notice(string $message, array $context = []) {
+	public function notice(string $message, array $context = []): void {
 		$this->log(ILogger::INFO, $message, $context);
 	}
 
@@ -175,9 +127,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function info(string $message, array $context = []) {
+	public function info(string $message, array $context = []): void {
 		$this->log(ILogger::INFO, $message, $context);
 	}
 
@@ -186,9 +137,8 @@ class Log implements ILogger, IDataLogger {
 	 *
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function debug(string $message, array $context = []) {
+	public function debug(string $message, array $context = []): void {
 		$this->log(ILogger::DEBUG, $message, $context);
 	}
 
@@ -199,19 +149,31 @@ class Log implements ILogger, IDataLogger {
 	 * @param int $level
 	 * @param string $message
 	 * @param array $context
-	 * @return void
 	 */
-	public function log(int $level, string $message, array $context = []) {
-		$minLevel = $this->getLogLevel($context);
+	public function log(int $level, string $message, array $context = []): void {
+		$minLevel = $this->getLogLevel($context, $message);
+		if ($level < $minLevel
+			&& (($this->crashReporters?->hasReporters() ?? false) === false)
+			&& (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) {
+			return; // no crash reporter, no listeners, we can stop for lower log level
+		}
 
 		array_walk($context, [$this->normalizer, 'format']);
 
 		$app = $context['app'] ?? 'no app in context';
-		$message = $this->interpolateMessage($context, $message);
+		$entry = $this->interpolateMessage($context, $message);
+
+		$this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $entry));
+
+		$hasBacktrace = isset($entry['exception']);
+		$logBacktrace = $this->config->getValue('log.backtrace', false);
+		if (!$hasBacktrace && $logBacktrace) {
+			$entry['backtrace'] = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS);
+		}
 
 		try {
 			if ($level >= $minLevel) {
-				$this->writeLog($app, $message, $level);
+				$this->writeLog($app, $entry, $level);
 
 				if ($this->crashReporters !== null) {
 					$messageContext = array_merge(
@@ -220,21 +182,40 @@ class Log implements ILogger, IDataLogger {
 							'level' => $level
 						]
 					);
-					$this->crashReporters->delegateMessage($message, $messageContext);
+					$this->crashReporters->delegateMessage($entry['message'], $messageContext);
 				}
 			} else {
-				if ($this->crashReporters !== null) {
-					$this->crashReporters->delegateBreadcrumb($message, 'log', $context);
-				}
+				$this->crashReporters?->delegateBreadcrumb($entry['message'], 'log', $context);
 			}
-		} catch (\Throwable $e) {
+		} catch (Throwable $e) {
 			// make sure we dont hard crash if logging fails
 		}
 	}
 
-	public function getLogLevel($context) {
+	public function getLogLevel(array $context, string $message): int {
+		if ($this->nestingLevel > 1) {
+			return ILogger::WARN;
+		}
+
+		$this->nestingLevel++;
+		/**
+		 * @psalm-var array{
+		 *   shared_secret?: string,
+		 *   users?: string[],
+		 *   apps?: string[],
+		 *   matches?: array<array-key, array{
+		 *     shared_secret?: string,
+		 *     users?: string[],
+		 *     apps?: string[],
+		 *     message?: string,
+		 *     loglevel: 0|1|2|3|4,
+		 *   }>
+		 * } $logCondition
+		 */
 		$logCondition = $this->config->getValue('log.condition', []);
 
+		$userId = false;
+
 		/**
 		 * check for a special log condition - this enables an increased log on
 		 * a per request/user base
@@ -243,32 +224,23 @@ class Log implements ILogger, IDataLogger {
 			// default to false to just process this once per request
 			$this->logConditionSatisfied = false;
 			if (!empty($logCondition)) {
-
 				// check for secret token in the request
-				if (isset($logCondition['shared_secret'])) {
-					$request = \OC::$server->getRequest();
-
-					if ($request->getMethod() === 'PUT' &&
-						strpos($request->getHeader('Content-Type'), 'application/x-www-form-urlencoded') === false &&
-						strpos($request->getHeader('Content-Type'), 'application/json') === false) {
-						$logSecretRequest = '';
-					} else {
-						$logSecretRequest = $request->getParam('log_secret', '');
-					}
-
-					// if token is found in the request change set the log condition to satisfied
-					if ($request && hash_equals($logCondition['shared_secret'], $logSecretRequest)) {
-						$this->logConditionSatisfied = true;
-					}
+				if (isset($logCondition['shared_secret']) && $this->checkLogSecret($logCondition['shared_secret'])) {
+					$this->logConditionSatisfied = true;
 				}
 
 				// check for user
 				if (isset($logCondition['users'])) {
-					$user = \OC::$server->getUserSession()->getUser();
+					$user = \OCP\Server::get(IUserSession::class)->getUser();
 
-					// if the user matches set the log condition to satisfied
-					if ($user !== null && in_array($user->getUID(), $logCondition['users'], true)) {
+					if ($user === null) {
+						// User is not known for this request yet
+						$this->logConditionSatisfied = null;
+					} elseif (in_array($user->getUID(), $logCondition['users'], true)) {
+						// if the user matches set the log condition to satisfied
 						$this->logConditionSatisfied = true;
+					} else {
+						$userId = $user->getUID();
 					}
 				}
 			}
@@ -276,52 +248,110 @@ class Log implements ILogger, IDataLogger {
 
 		// if log condition is satisfied change the required log level to DEBUG
 		if ($this->logConditionSatisfied) {
+			$this->nestingLevel--;
 			return ILogger::DEBUG;
 		}
 
-		if (isset($context['app'])) {
-			$app = $context['app'];
+		if ($userId === false && isset($logCondition['matches'])) {
+			$user = \OCP\Server::get(IUserSession::class)->getUser();
+			$userId = $user === null ? false : $user->getUID();
+		}
 
+		if (isset($context['app'])) {
 			/**
 			 * check log condition based on the context of each log message
 			 * once this is met -> change the required log level to debug
 			 */
-			if (!empty($logCondition)
-				&& isset($logCondition['apps'])
-				&& in_array($app, $logCondition['apps'], true)) {
+			if (in_array($context['app'], $logCondition['apps'] ?? [], true)) {
+				$this->nestingLevel--;
 				return ILogger::DEBUG;
 			}
 		}
 
-		return min($this->config->getValue('loglevel', ILogger::WARN), ILogger::FATAL);
+		if (!isset($logCondition['matches'])) {
+			$configLogLevel = $this->config->getValue('loglevel', ILogger::WARN);
+			if (is_numeric($configLogLevel)) {
+				$this->nestingLevel--;
+				return min((int)$configLogLevel, ILogger::FATAL);
+			}
+
+			// Invalid configuration, warn the user and fall back to default level of WARN
+			error_log('Nextcloud configuration: "loglevel" is not a valid integer');
+			$this->nestingLevel--;
+			return ILogger::WARN;
+		}
+
+		foreach ($logCondition['matches'] as $option) {
+			if (
+				(!isset($option['shared_secret']) || $this->checkLogSecret($option['shared_secret']))
+				&& (!isset($option['users']) || in_array($userId, $option['users'], true))
+				&& (!isset($option['apps']) || (isset($context['app']) && in_array($context['app'], $option['apps'], true)))
+				&& (!isset($option['message']) || str_contains($message, $option['message']))
+			) {
+				if (!isset($option['apps']) && !isset($option['loglevel']) && !isset($option['message'])) {
+					/* Only user and/or secret are listed as conditions, we can cache the result for the rest of the request */
+					$this->logConditionSatisfied = true;
+					$this->nestingLevel--;
+					return ILogger::DEBUG;
+				}
+				$this->nestingLevel--;
+				return $option['loglevel'] ?? ILogger::DEBUG;
+			}
+		}
+
+		$this->nestingLevel--;
+		return ILogger::WARN;
+	}
+
+	protected function checkLogSecret(string $conditionSecret): bool {
+		$request = \OCP\Server::get(IRequest::class);
+
+		if ($request->getMethod() === 'PUT'
+			&& !str_contains($request->getHeader('Content-Type'), 'application/x-www-form-urlencoded')
+			&& !str_contains($request->getHeader('Content-Type'), 'application/json')) {
+			return hash_equals($conditionSecret, '');
+		}
+
+		// if token is found in the request change set the log condition to satisfied
+		return hash_equals($conditionSecret, $request->getParam('log_secret', ''));
 	}
 
 	/**
 	 * Logs an exception very detailed
 	 *
-	 * @param \Exception|\Throwable $exception
+	 * @param Exception|Throwable $exception
 	 * @param array $context
 	 * @return void
 	 * @since 8.2.0
 	 */
-	public function logException(\Throwable $exception, array $context = []) {
+	public function logException(Throwable $exception, array $context = []): void {
 		$app = $context['app'] ?? 'no app in context';
 		$level = $context['level'] ?? ILogger::ERROR;
 
+		$minLevel = $this->getLogLevel($context, $context['message'] ?? $exception->getMessage());
+		if ($level < $minLevel
+			&& (($this->crashReporters?->hasReporters() ?? false) === false)
+			&& (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) {
+			return; // no crash reporter, no listeners, we can stop for lower log level
+		}
+
 		// if an error is raised before the autoloader is properly setup, we can't serialize exceptions
 		try {
-			$serializer = new ExceptionSerializer($this->config);
-		} catch (\Throwable $e) {
-			$this->error("Failed to load ExceptionSerializer serializer while trying to log " . $exception->getMessage());
+			$serializer = $this->getSerializer();
+		} catch (Throwable $e) {
+			$this->error('Failed to load ExceptionSerializer serializer while trying to log ' . $exception->getMessage());
 			return;
 		}
-		$data = $serializer->serializeException($exception);
-		$data['CustomMessage'] = $this->interpolateMessage($context, $context['message'] ?? '--');
-
-		$minLevel = $this->getLogLevel($context);
+		$data = $context;
+		unset($data['app']);
+		unset($data['level']);
+		$data = array_merge($serializer->serializeException($exception), $data);
+		$data = $this->interpolateMessage($data, isset($context['message']) && $context['message'] !== '' ? $context['message'] : ('Exception thrown: ' . get_class($exception)), 'CustomMessage');
 
 		array_walk($context, [$this->normalizer, 'format']);
 
+		$this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $data));
+
 		try {
 			if ($level >= $minLevel) {
 				if (!$this->logger instanceof IFileBased) {
@@ -334,7 +364,7 @@ class Log implements ILogger, IDataLogger {
 			if (!is_null($this->crashReporters)) {
 				$this->crashReporters->delegateReport($exception, $context);
 			}
-		} catch (\Throwable $e) {
+		} catch (Throwable $e) {
 			// make sure we dont hard crash if logging fails
 		}
 	}
@@ -343,7 +373,7 @@ class Log implements ILogger, IDataLogger {
 		$app = $context['app'] ?? 'no app in context';
 		$level = $context['level'] ?? ILogger::ERROR;
 
-		$minLevel = $this->getLogLevel($context);
+		$minLevel = $this->getLogLevel($context, $message);
 
 		array_walk($context, [$this->normalizer, 'format']);
 
@@ -357,8 +387,9 @@ class Log implements ILogger, IDataLogger {
 			}
 
 			$context['level'] = $level;
-		} catch (\Throwable $e) {
+		} catch (Throwable $e) {
 			// make sure we dont hard crash if logging fails
+			error_log('Error when trying to log exception: ' . $e->getMessage() . ' ' . $e->getTraceAsString());
 		}
 	}
 
@@ -367,7 +398,7 @@ class Log implements ILogger, IDataLogger {
 	 * @param string|array $entry
 	 * @param int $level
 	 */
-	protected function writeLog(string $app, $entry, int $level) {
+	protected function writeLog(string $app, $entry, int $level): void {
 		$this->logger->write($app, $entry, $level);
 	}
 
@@ -381,16 +412,42 @@ class Log implements ILogger, IDataLogger {
 	/**
 	 * Interpolate $message as defined in PSR-3
 	 *
-	 * @param array $context
-	 * @param string $message
-	 *
-	 * @return string
+	 * Returns an array containing the context without the interpolated
+	 * parameters placeholders and the message as the 'message' - or
+	 * user-defined - key.
 	 */
-	private function interpolateMessage(array $context, string $message): string {
+	private function interpolateMessage(array $context, string $message, string $messageKey = 'message'): array {
 		$replace = [];
+		$usedContextKeys = [];
 		foreach ($context as $key => $val) {
-			$replace['{' . $key . '}'] = $val;
+			$fullKey = '{' . $key . '}';
+			$replace[$fullKey] = $val;
+			if (str_contains($message, $fullKey)) {
+				$usedContextKeys[$key] = true;
+			}
+		}
+		return array_merge(array_diff_key($context, $usedContextKeys), [$messageKey => strtr($message, $replace)]);
+	}
+
+	/**
+	 * @throws Throwable
+	 */
+	protected function getSerializer(): ExceptionSerializer {
+		$serializer = new ExceptionSerializer($this->config);
+		try {
+			/** @var Coordinator $coordinator */
+			$coordinator = \OCP\Server::get(Coordinator::class);
+			foreach ($coordinator->getRegistrationContext()->getSensitiveMethods() as $registration) {
+				$serializer->enlistSensitiveMethods($registration->getName(), $registration->getValue());
+			}
+			// For not every app might be initialized at this time, we cannot assume that the return value
+			// of getSensitiveMethods() is complete. Running delegates in Coordinator::registerApps() is
+			// not possible due to dependencies on the one hand. On the other it would work only with
+			// adding public methods to the PsrLoggerAdapter and this class.
+			// Thus, serializer cannot be a property.
+		} catch (Throwable $t) {
+			// ignore app-defined sensitive methods in this case - they weren't loaded anyway
 		}
-		return strtr($message, $replace);
+		return $serializer;
 	}
 }