@@ -35,419 +35,419 @@ |
||
| 35 | 35 | * MonoLog is an example implementing this interface. |
| 36 | 36 | */ |
| 37 | 37 | class Log implements ILogger, IDataLogger { |
| 38 | - private ?bool $logConditionSatisfied = null; |
|
| 39 | - private ?IEventDispatcher $eventDispatcher = null; |
|
| 40 | - private int $nestingLevel = 0; |
|
| 41 | - |
|
| 42 | - public function __construct( |
|
| 43 | - private IWriter $logger, |
|
| 44 | - private SystemConfig $config, |
|
| 45 | - private Normalizer $normalizer = new Normalizer(), |
|
| 46 | - private ?IRegistry $crashReporters = null, |
|
| 47 | - ) { |
|
| 48 | - } |
|
| 49 | - |
|
| 50 | - public function setEventDispatcher(IEventDispatcher $eventDispatcher): void { |
|
| 51 | - $this->eventDispatcher = $eventDispatcher; |
|
| 52 | - } |
|
| 53 | - |
|
| 54 | - /** |
|
| 55 | - * System is unusable. |
|
| 56 | - * |
|
| 57 | - * @param string $message |
|
| 58 | - * @param array $context |
|
| 59 | - */ |
|
| 60 | - public function emergency(string $message, array $context = []): void { |
|
| 61 | - $this->log(ILogger::FATAL, $message, $context); |
|
| 62 | - } |
|
| 63 | - |
|
| 64 | - /** |
|
| 65 | - * Action must be taken immediately. |
|
| 66 | - * |
|
| 67 | - * Example: Entire website down, database unavailable, etc. This should |
|
| 68 | - * trigger the SMS alerts and wake you up. |
|
| 69 | - * |
|
| 70 | - * @param string $message |
|
| 71 | - * @param array $context |
|
| 72 | - */ |
|
| 73 | - public function alert(string $message, array $context = []): void { |
|
| 74 | - $this->log(ILogger::ERROR, $message, $context); |
|
| 75 | - } |
|
| 76 | - |
|
| 77 | - /** |
|
| 78 | - * Critical conditions. |
|
| 79 | - * |
|
| 80 | - * Example: Application component unavailable, unexpected exception. |
|
| 81 | - * |
|
| 82 | - * @param string $message |
|
| 83 | - * @param array $context |
|
| 84 | - */ |
|
| 85 | - public function critical(string $message, array $context = []): void { |
|
| 86 | - $this->log(ILogger::ERROR, $message, $context); |
|
| 87 | - } |
|
| 88 | - |
|
| 89 | - /** |
|
| 90 | - * Runtime errors that do not require immediate action but should typically |
|
| 91 | - * be logged and monitored. |
|
| 92 | - * |
|
| 93 | - * @param string $message |
|
| 94 | - * @param array $context |
|
| 95 | - */ |
|
| 96 | - public function error(string $message, array $context = []): void { |
|
| 97 | - $this->log(ILogger::ERROR, $message, $context); |
|
| 98 | - } |
|
| 99 | - |
|
| 100 | - /** |
|
| 101 | - * Exceptional occurrences that are not errors. |
|
| 102 | - * |
|
| 103 | - * Example: Use of deprecated APIs, poor use of an API, undesirable things |
|
| 104 | - * that are not necessarily wrong. |
|
| 105 | - * |
|
| 106 | - * @param string $message |
|
| 107 | - * @param array $context |
|
| 108 | - */ |
|
| 109 | - public function warning(string $message, array $context = []): void { |
|
| 110 | - $this->log(ILogger::WARN, $message, $context); |
|
| 111 | - } |
|
| 112 | - |
|
| 113 | - /** |
|
| 114 | - * Normal but significant events. |
|
| 115 | - * |
|
| 116 | - * @param string $message |
|
| 117 | - * @param array $context |
|
| 118 | - */ |
|
| 119 | - public function notice(string $message, array $context = []): void { |
|
| 120 | - $this->log(ILogger::INFO, $message, $context); |
|
| 121 | - } |
|
| 122 | - |
|
| 123 | - /** |
|
| 124 | - * Interesting events. |
|
| 125 | - * |
|
| 126 | - * Example: User logs in, SQL logs. |
|
| 127 | - * |
|
| 128 | - * @param string $message |
|
| 129 | - * @param array $context |
|
| 130 | - */ |
|
| 131 | - public function info(string $message, array $context = []): void { |
|
| 132 | - $this->log(ILogger::INFO, $message, $context); |
|
| 133 | - } |
|
| 134 | - |
|
| 135 | - /** |
|
| 136 | - * Detailed debug information. |
|
| 137 | - * |
|
| 138 | - * @param string $message |
|
| 139 | - * @param array $context |
|
| 140 | - */ |
|
| 141 | - public function debug(string $message, array $context = []): void { |
|
| 142 | - $this->log(ILogger::DEBUG, $message, $context); |
|
| 143 | - } |
|
| 144 | - |
|
| 145 | - |
|
| 146 | - /** |
|
| 147 | - * Logs with an arbitrary level. |
|
| 148 | - * |
|
| 149 | - * @param int $level |
|
| 150 | - * @param string $message |
|
| 151 | - * @param array $context |
|
| 152 | - */ |
|
| 153 | - public function log(int $level, string $message, array $context = []): void { |
|
| 154 | - $minLevel = $this->getLogLevel($context, $message); |
|
| 155 | - if ($level < $minLevel |
|
| 156 | - && (($this->crashReporters?->hasReporters() ?? false) === false) |
|
| 157 | - && (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) { |
|
| 158 | - return; // no crash reporter, no listeners, we can stop for lower log level |
|
| 159 | - } |
|
| 160 | - |
|
| 161 | - $context = array_map($this->normalizer->format(...), $context); |
|
| 162 | - |
|
| 163 | - $app = $context['app'] ?? 'no app in context'; |
|
| 164 | - $entry = $this->interpolateMessage($context, $message); |
|
| 165 | - |
|
| 166 | - $this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $entry)); |
|
| 167 | - |
|
| 168 | - $hasBacktrace = isset($entry['exception']); |
|
| 169 | - $logBacktrace = $this->config->getValue('log.backtrace', false); |
|
| 170 | - if (!$hasBacktrace && $logBacktrace) { |
|
| 171 | - $entry['backtrace'] = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); |
|
| 172 | - } |
|
| 173 | - |
|
| 174 | - try { |
|
| 175 | - if ($level >= $minLevel) { |
|
| 176 | - $this->writeLog($app, $entry, $level); |
|
| 177 | - |
|
| 178 | - if ($this->crashReporters !== null) { |
|
| 179 | - $messageContext = array_merge( |
|
| 180 | - $context, |
|
| 181 | - [ |
|
| 182 | - 'level' => $level |
|
| 183 | - ] |
|
| 184 | - ); |
|
| 185 | - $this->crashReporters->delegateMessage($entry['message'], $messageContext); |
|
| 186 | - } |
|
| 187 | - } else { |
|
| 188 | - $this->crashReporters?->delegateBreadcrumb($entry['message'], 'log', $context); |
|
| 189 | - } |
|
| 190 | - } catch (Throwable $e) { |
|
| 191 | - // make sure we dont hard crash if logging fails |
|
| 192 | - } |
|
| 193 | - } |
|
| 194 | - |
|
| 195 | - public function getLogLevel(array $context, string $message): int { |
|
| 196 | - if ($this->nestingLevel > 1) { |
|
| 197 | - return ILogger::WARN; |
|
| 198 | - } |
|
| 199 | - |
|
| 200 | - $this->nestingLevel++; |
|
| 201 | - /** |
|
| 202 | - * @psalm-var array{ |
|
| 203 | - * shared_secret?: string, |
|
| 204 | - * users?: string[], |
|
| 205 | - * apps?: string[], |
|
| 206 | - * matches?: array<array-key, array{ |
|
| 207 | - * shared_secret?: string, |
|
| 208 | - * users?: string[], |
|
| 209 | - * apps?: string[], |
|
| 210 | - * message?: string, |
|
| 211 | - * loglevel: 0|1|2|3|4, |
|
| 212 | - * }> |
|
| 213 | - * } $logCondition |
|
| 214 | - */ |
|
| 215 | - $logCondition = $this->config->getValue('log.condition', []); |
|
| 216 | - |
|
| 217 | - $userId = false; |
|
| 218 | - |
|
| 219 | - /** |
|
| 220 | - * check for a special log condition - this enables an increased log on |
|
| 221 | - * a per request/user base |
|
| 222 | - */ |
|
| 223 | - if ($this->logConditionSatisfied === null) { |
|
| 224 | - // default to false to just process this once per request |
|
| 225 | - $this->logConditionSatisfied = false; |
|
| 226 | - if (!empty($logCondition)) { |
|
| 227 | - // check for secret token in the request |
|
| 228 | - if (isset($logCondition['shared_secret']) && $this->checkLogSecret($logCondition['shared_secret'])) { |
|
| 229 | - $this->logConditionSatisfied = true; |
|
| 230 | - } |
|
| 231 | - |
|
| 232 | - // check for user |
|
| 233 | - if (isset($logCondition['users'])) { |
|
| 234 | - $user = \OCP\Server::get(IUserSession::class)->getUser(); |
|
| 235 | - |
|
| 236 | - if ($user === null) { |
|
| 237 | - // User is not known for this request yet |
|
| 238 | - $this->logConditionSatisfied = null; |
|
| 239 | - } elseif (in_array($user->getUID(), $logCondition['users'], true)) { |
|
| 240 | - // if the user matches set the log condition to satisfied |
|
| 241 | - $this->logConditionSatisfied = true; |
|
| 242 | - } else { |
|
| 243 | - $userId = $user->getUID(); |
|
| 244 | - } |
|
| 245 | - } |
|
| 246 | - } |
|
| 247 | - } |
|
| 248 | - |
|
| 249 | - // if log condition is satisfied change the required log level to DEBUG |
|
| 250 | - if ($this->logConditionSatisfied) { |
|
| 251 | - $this->nestingLevel--; |
|
| 252 | - return ILogger::DEBUG; |
|
| 253 | - } |
|
| 254 | - |
|
| 255 | - if ($userId === false && isset($logCondition['matches'])) { |
|
| 256 | - $user = \OCP\Server::get(IUserSession::class)->getUser(); |
|
| 257 | - $userId = $user === null ? false : $user->getUID(); |
|
| 258 | - } |
|
| 259 | - |
|
| 260 | - if (isset($context['app'])) { |
|
| 261 | - /** |
|
| 262 | - * check log condition based on the context of each log message |
|
| 263 | - * once this is met -> change the required log level to debug |
|
| 264 | - */ |
|
| 265 | - if (in_array($context['app'], $logCondition['apps'] ?? [], true)) { |
|
| 266 | - $this->nestingLevel--; |
|
| 267 | - return ILogger::DEBUG; |
|
| 268 | - } |
|
| 269 | - } |
|
| 270 | - |
|
| 271 | - if (!isset($logCondition['matches'])) { |
|
| 272 | - $configLogLevel = $this->config->getValue('loglevel', ILogger::WARN); |
|
| 273 | - if (is_numeric($configLogLevel)) { |
|
| 274 | - $this->nestingLevel--; |
|
| 275 | - return min((int)$configLogLevel, ILogger::FATAL); |
|
| 276 | - } |
|
| 277 | - |
|
| 278 | - // Invalid configuration, warn the user and fall back to default level of WARN |
|
| 279 | - error_log('Nextcloud configuration: "loglevel" is not a valid integer'); |
|
| 280 | - $this->nestingLevel--; |
|
| 281 | - return ILogger::WARN; |
|
| 282 | - } |
|
| 283 | - |
|
| 284 | - foreach ($logCondition['matches'] as $option) { |
|
| 285 | - if ( |
|
| 286 | - (!isset($option['shared_secret']) || $this->checkLogSecret($option['shared_secret'])) |
|
| 287 | - && (!isset($option['users']) || in_array($userId, $option['users'], true)) |
|
| 288 | - && (!isset($option['apps']) || (isset($context['app']) && in_array($context['app'], $option['apps'], true))) |
|
| 289 | - && (!isset($option['message']) || str_contains($message, $option['message'])) |
|
| 290 | - ) { |
|
| 291 | - if (!isset($option['apps']) && !isset($option['loglevel']) && !isset($option['message'])) { |
|
| 292 | - /* Only user and/or secret are listed as conditions, we can cache the result for the rest of the request */ |
|
| 293 | - $this->logConditionSatisfied = true; |
|
| 294 | - $this->nestingLevel--; |
|
| 295 | - return ILogger::DEBUG; |
|
| 296 | - } |
|
| 297 | - $this->nestingLevel--; |
|
| 298 | - return $option['loglevel'] ?? ILogger::DEBUG; |
|
| 299 | - } |
|
| 300 | - } |
|
| 301 | - |
|
| 302 | - $this->nestingLevel--; |
|
| 303 | - return ILogger::WARN; |
|
| 304 | - } |
|
| 305 | - |
|
| 306 | - protected function checkLogSecret(string $conditionSecret): bool { |
|
| 307 | - $request = \OCP\Server::get(IRequest::class); |
|
| 308 | - |
|
| 309 | - if ($request->getMethod() === 'PUT' |
|
| 310 | - && !str_contains($request->getHeader('Content-Type'), 'application/x-www-form-urlencoded') |
|
| 311 | - && !str_contains($request->getHeader('Content-Type'), 'application/json')) { |
|
| 312 | - return hash_equals($conditionSecret, ''); |
|
| 313 | - } |
|
| 314 | - |
|
| 315 | - // if token is found in the request change set the log condition to satisfied |
|
| 316 | - return hash_equals($conditionSecret, $request->getParam('log_secret', '')); |
|
| 317 | - } |
|
| 318 | - |
|
| 319 | - /** |
|
| 320 | - * Logs an exception very detailed |
|
| 321 | - * |
|
| 322 | - * @param Exception|Throwable $exception |
|
| 323 | - * @param array $context |
|
| 324 | - * @return void |
|
| 325 | - * @since 8.2.0 |
|
| 326 | - */ |
|
| 327 | - public function logException(Throwable $exception, array $context = []): void { |
|
| 328 | - $app = $context['app'] ?? 'no app in context'; |
|
| 329 | - $level = $context['level'] ?? ILogger::ERROR; |
|
| 330 | - |
|
| 331 | - $minLevel = $this->getLogLevel($context, $context['message'] ?? $exception->getMessage()); |
|
| 332 | - if ($level < $minLevel |
|
| 333 | - && (($this->crashReporters?->hasReporters() ?? false) === false) |
|
| 334 | - && (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) { |
|
| 335 | - return; // no crash reporter, no listeners, we can stop for lower log level |
|
| 336 | - } |
|
| 337 | - |
|
| 338 | - // if an error is raised before the autoloader is properly setup, we can't serialize exceptions |
|
| 339 | - try { |
|
| 340 | - $serializer = $this->getSerializer(); |
|
| 341 | - } catch (Throwable $e) { |
|
| 342 | - $this->error('Failed to load ExceptionSerializer serializer while trying to log ' . $exception->getMessage()); |
|
| 343 | - return; |
|
| 344 | - } |
|
| 345 | - $data = $context; |
|
| 346 | - unset($data['app']); |
|
| 347 | - unset($data['level']); |
|
| 348 | - $data = array_merge($serializer->serializeException($exception), $data); |
|
| 349 | - $data = $this->interpolateMessage($data, isset($context['message']) && $context['message'] !== '' ? $context['message'] : ('Exception thrown: ' . get_class($exception)), 'CustomMessage'); |
|
| 350 | - |
|
| 351 | - array_walk($context, [$this->normalizer, 'format']); |
|
| 352 | - |
|
| 353 | - $this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $data)); |
|
| 354 | - |
|
| 355 | - try { |
|
| 356 | - if ($level >= $minLevel) { |
|
| 357 | - if (!$this->logger instanceof IFileBased) { |
|
| 358 | - $data = json_encode($data, JSON_PARTIAL_OUTPUT_ON_ERROR | JSON_UNESCAPED_SLASHES); |
|
| 359 | - } |
|
| 360 | - $this->writeLog($app, $data, $level); |
|
| 361 | - } |
|
| 362 | - |
|
| 363 | - $context['level'] = $level; |
|
| 364 | - if (!is_null($this->crashReporters)) { |
|
| 365 | - $this->crashReporters->delegateReport($exception, $context); |
|
| 366 | - } |
|
| 367 | - } catch (Throwable $e) { |
|
| 368 | - // make sure we dont hard crash if logging fails |
|
| 369 | - } |
|
| 370 | - } |
|
| 371 | - |
|
| 372 | - public function logData(string $message, array $data, array $context = []): void { |
|
| 373 | - $app = $context['app'] ?? 'no app in context'; |
|
| 374 | - $level = $context['level'] ?? ILogger::ERROR; |
|
| 375 | - |
|
| 376 | - $minLevel = $this->getLogLevel($context, $message); |
|
| 377 | - |
|
| 378 | - array_walk($context, [$this->normalizer, 'format']); |
|
| 379 | - |
|
| 380 | - try { |
|
| 381 | - if ($level >= $minLevel) { |
|
| 382 | - $data['message'] = $message; |
|
| 383 | - if (!$this->logger instanceof IFileBased) { |
|
| 384 | - $data = json_encode($data, JSON_PARTIAL_OUTPUT_ON_ERROR | JSON_UNESCAPED_SLASHES); |
|
| 385 | - } |
|
| 386 | - $this->writeLog($app, $data, $level); |
|
| 387 | - } |
|
| 388 | - |
|
| 389 | - $context['level'] = $level; |
|
| 390 | - } catch (Throwable $e) { |
|
| 391 | - // make sure we dont hard crash if logging fails |
|
| 392 | - error_log('Error when trying to log exception: ' . $e->getMessage() . ' ' . $e->getTraceAsString()); |
|
| 393 | - } |
|
| 394 | - } |
|
| 395 | - |
|
| 396 | - /** |
|
| 397 | - * @param string $app |
|
| 398 | - * @param string|array $entry |
|
| 399 | - * @param int $level |
|
| 400 | - */ |
|
| 401 | - protected function writeLog(string $app, $entry, int $level): void { |
|
| 402 | - $this->logger->write($app, $entry, $level); |
|
| 403 | - } |
|
| 404 | - |
|
| 405 | - public function getLogPath():string { |
|
| 406 | - if ($this->logger instanceof IFileBased) { |
|
| 407 | - return $this->logger->getLogFilePath(); |
|
| 408 | - } |
|
| 409 | - throw new \RuntimeException('Log implementation has no path'); |
|
| 410 | - } |
|
| 411 | - |
|
| 412 | - /** |
|
| 413 | - * Interpolate $message as defined in PSR-3 |
|
| 414 | - * |
|
| 415 | - * Returns an array containing the context without the interpolated |
|
| 416 | - * parameters placeholders and the message as the 'message' - or |
|
| 417 | - * user-defined - key. |
|
| 418 | - */ |
|
| 419 | - private function interpolateMessage(array $context, string $message, string $messageKey = 'message'): array { |
|
| 420 | - $replace = []; |
|
| 421 | - $usedContextKeys = []; |
|
| 422 | - foreach ($context as $key => $val) { |
|
| 423 | - $fullKey = '{' . $key . '}'; |
|
| 424 | - $replace[$fullKey] = $val; |
|
| 425 | - if (str_contains($message, $fullKey)) { |
|
| 426 | - $usedContextKeys[$key] = true; |
|
| 427 | - } |
|
| 428 | - } |
|
| 429 | - return array_merge(array_diff_key($context, $usedContextKeys), [$messageKey => strtr($message, $replace)]); |
|
| 430 | - } |
|
| 431 | - |
|
| 432 | - /** |
|
| 433 | - * @throws Throwable |
|
| 434 | - */ |
|
| 435 | - protected function getSerializer(): ExceptionSerializer { |
|
| 436 | - $serializer = new ExceptionSerializer($this->config); |
|
| 437 | - try { |
|
| 438 | - /** @var Coordinator $coordinator */ |
|
| 439 | - $coordinator = \OCP\Server::get(Coordinator::class); |
|
| 440 | - foreach ($coordinator->getRegistrationContext()->getSensitiveMethods() as $registration) { |
|
| 441 | - $serializer->enlistSensitiveMethods($registration->getName(), $registration->getValue()); |
|
| 442 | - } |
|
| 443 | - // For not every app might be initialized at this time, we cannot assume that the return value |
|
| 444 | - // of getSensitiveMethods() is complete. Running delegates in Coordinator::registerApps() is |
|
| 445 | - // not possible due to dependencies on the one hand. On the other it would work only with |
|
| 446 | - // adding public methods to the PsrLoggerAdapter and this class. |
|
| 447 | - // Thus, serializer cannot be a property. |
|
| 448 | - } catch (Throwable $t) { |
|
| 449 | - // ignore app-defined sensitive methods in this case - they weren't loaded anyway |
|
| 450 | - } |
|
| 451 | - return $serializer; |
|
| 452 | - } |
|
| 38 | + private ?bool $logConditionSatisfied = null; |
|
| 39 | + private ?IEventDispatcher $eventDispatcher = null; |
|
| 40 | + private int $nestingLevel = 0; |
|
| 41 | + |
|
| 42 | + public function __construct( |
|
| 43 | + private IWriter $logger, |
|
| 44 | + private SystemConfig $config, |
|
| 45 | + private Normalizer $normalizer = new Normalizer(), |
|
| 46 | + private ?IRegistry $crashReporters = null, |
|
| 47 | + ) { |
|
| 48 | + } |
|
| 49 | + |
|
| 50 | + public function setEventDispatcher(IEventDispatcher $eventDispatcher): void { |
|
| 51 | + $this->eventDispatcher = $eventDispatcher; |
|
| 52 | + } |
|
| 53 | + |
|
| 54 | + /** |
|
| 55 | + * System is unusable. |
|
| 56 | + * |
|
| 57 | + * @param string $message |
|
| 58 | + * @param array $context |
|
| 59 | + */ |
|
| 60 | + public function emergency(string $message, array $context = []): void { |
|
| 61 | + $this->log(ILogger::FATAL, $message, $context); |
|
| 62 | + } |
|
| 63 | + |
|
| 64 | + /** |
|
| 65 | + * Action must be taken immediately. |
|
| 66 | + * |
|
| 67 | + * Example: Entire website down, database unavailable, etc. This should |
|
| 68 | + * trigger the SMS alerts and wake you up. |
|
| 69 | + * |
|
| 70 | + * @param string $message |
|
| 71 | + * @param array $context |
|
| 72 | + */ |
|
| 73 | + public function alert(string $message, array $context = []): void { |
|
| 74 | + $this->log(ILogger::ERROR, $message, $context); |
|
| 75 | + } |
|
| 76 | + |
|
| 77 | + /** |
|
| 78 | + * Critical conditions. |
|
| 79 | + * |
|
| 80 | + * Example: Application component unavailable, unexpected exception. |
|
| 81 | + * |
|
| 82 | + * @param string $message |
|
| 83 | + * @param array $context |
|
| 84 | + */ |
|
| 85 | + public function critical(string $message, array $context = []): void { |
|
| 86 | + $this->log(ILogger::ERROR, $message, $context); |
|
| 87 | + } |
|
| 88 | + |
|
| 89 | + /** |
|
| 90 | + * Runtime errors that do not require immediate action but should typically |
|
| 91 | + * be logged and monitored. |
|
| 92 | + * |
|
| 93 | + * @param string $message |
|
| 94 | + * @param array $context |
|
| 95 | + */ |
|
| 96 | + public function error(string $message, array $context = []): void { |
|
| 97 | + $this->log(ILogger::ERROR, $message, $context); |
|
| 98 | + } |
|
| 99 | + |
|
| 100 | + /** |
|
| 101 | + * Exceptional occurrences that are not errors. |
|
| 102 | + * |
|
| 103 | + * Example: Use of deprecated APIs, poor use of an API, undesirable things |
|
| 104 | + * that are not necessarily wrong. |
|
| 105 | + * |
|
| 106 | + * @param string $message |
|
| 107 | + * @param array $context |
|
| 108 | + */ |
|
| 109 | + public function warning(string $message, array $context = []): void { |
|
| 110 | + $this->log(ILogger::WARN, $message, $context); |
|
| 111 | + } |
|
| 112 | + |
|
| 113 | + /** |
|
| 114 | + * Normal but significant events. |
|
| 115 | + * |
|
| 116 | + * @param string $message |
|
| 117 | + * @param array $context |
|
| 118 | + */ |
|
| 119 | + public function notice(string $message, array $context = []): void { |
|
| 120 | + $this->log(ILogger::INFO, $message, $context); |
|
| 121 | + } |
|
| 122 | + |
|
| 123 | + /** |
|
| 124 | + * Interesting events. |
|
| 125 | + * |
|
| 126 | + * Example: User logs in, SQL logs. |
|
| 127 | + * |
|
| 128 | + * @param string $message |
|
| 129 | + * @param array $context |
|
| 130 | + */ |
|
| 131 | + public function info(string $message, array $context = []): void { |
|
| 132 | + $this->log(ILogger::INFO, $message, $context); |
|
| 133 | + } |
|
| 134 | + |
|
| 135 | + /** |
|
| 136 | + * Detailed debug information. |
|
| 137 | + * |
|
| 138 | + * @param string $message |
|
| 139 | + * @param array $context |
|
| 140 | + */ |
|
| 141 | + public function debug(string $message, array $context = []): void { |
|
| 142 | + $this->log(ILogger::DEBUG, $message, $context); |
|
| 143 | + } |
|
| 144 | + |
|
| 145 | + |
|
| 146 | + /** |
|
| 147 | + * Logs with an arbitrary level. |
|
| 148 | + * |
|
| 149 | + * @param int $level |
|
| 150 | + * @param string $message |
|
| 151 | + * @param array $context |
|
| 152 | + */ |
|
| 153 | + public function log(int $level, string $message, array $context = []): void { |
|
| 154 | + $minLevel = $this->getLogLevel($context, $message); |
|
| 155 | + if ($level < $minLevel |
|
| 156 | + && (($this->crashReporters?->hasReporters() ?? false) === false) |
|
| 157 | + && (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) { |
|
| 158 | + return; // no crash reporter, no listeners, we can stop for lower log level |
|
| 159 | + } |
|
| 160 | + |
|
| 161 | + $context = array_map($this->normalizer->format(...), $context); |
|
| 162 | + |
|
| 163 | + $app = $context['app'] ?? 'no app in context'; |
|
| 164 | + $entry = $this->interpolateMessage($context, $message); |
|
| 165 | + |
|
| 166 | + $this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $entry)); |
|
| 167 | + |
|
| 168 | + $hasBacktrace = isset($entry['exception']); |
|
| 169 | + $logBacktrace = $this->config->getValue('log.backtrace', false); |
|
| 170 | + if (!$hasBacktrace && $logBacktrace) { |
|
| 171 | + $entry['backtrace'] = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); |
|
| 172 | + } |
|
| 173 | + |
|
| 174 | + try { |
|
| 175 | + if ($level >= $minLevel) { |
|
| 176 | + $this->writeLog($app, $entry, $level); |
|
| 177 | + |
|
| 178 | + if ($this->crashReporters !== null) { |
|
| 179 | + $messageContext = array_merge( |
|
| 180 | + $context, |
|
| 181 | + [ |
|
| 182 | + 'level' => $level |
|
| 183 | + ] |
|
| 184 | + ); |
|
| 185 | + $this->crashReporters->delegateMessage($entry['message'], $messageContext); |
|
| 186 | + } |
|
| 187 | + } else { |
|
| 188 | + $this->crashReporters?->delegateBreadcrumb($entry['message'], 'log', $context); |
|
| 189 | + } |
|
| 190 | + } catch (Throwable $e) { |
|
| 191 | + // make sure we dont hard crash if logging fails |
|
| 192 | + } |
|
| 193 | + } |
|
| 194 | + |
|
| 195 | + public function getLogLevel(array $context, string $message): int { |
|
| 196 | + if ($this->nestingLevel > 1) { |
|
| 197 | + return ILogger::WARN; |
|
| 198 | + } |
|
| 199 | + |
|
| 200 | + $this->nestingLevel++; |
|
| 201 | + /** |
|
| 202 | + * @psalm-var array{ |
|
| 203 | + * shared_secret?: string, |
|
| 204 | + * users?: string[], |
|
| 205 | + * apps?: string[], |
|
| 206 | + * matches?: array<array-key, array{ |
|
| 207 | + * shared_secret?: string, |
|
| 208 | + * users?: string[], |
|
| 209 | + * apps?: string[], |
|
| 210 | + * message?: string, |
|
| 211 | + * loglevel: 0|1|2|3|4, |
|
| 212 | + * }> |
|
| 213 | + * } $logCondition |
|
| 214 | + */ |
|
| 215 | + $logCondition = $this->config->getValue('log.condition', []); |
|
| 216 | + |
|
| 217 | + $userId = false; |
|
| 218 | + |
|
| 219 | + /** |
|
| 220 | + * check for a special log condition - this enables an increased log on |
|
| 221 | + * a per request/user base |
|
| 222 | + */ |
|
| 223 | + if ($this->logConditionSatisfied === null) { |
|
| 224 | + // default to false to just process this once per request |
|
| 225 | + $this->logConditionSatisfied = false; |
|
| 226 | + if (!empty($logCondition)) { |
|
| 227 | + // check for secret token in the request |
|
| 228 | + if (isset($logCondition['shared_secret']) && $this->checkLogSecret($logCondition['shared_secret'])) { |
|
| 229 | + $this->logConditionSatisfied = true; |
|
| 230 | + } |
|
| 231 | + |
|
| 232 | + // check for user |
|
| 233 | + if (isset($logCondition['users'])) { |
|
| 234 | + $user = \OCP\Server::get(IUserSession::class)->getUser(); |
|
| 235 | + |
|
| 236 | + if ($user === null) { |
|
| 237 | + // User is not known for this request yet |
|
| 238 | + $this->logConditionSatisfied = null; |
|
| 239 | + } elseif (in_array($user->getUID(), $logCondition['users'], true)) { |
|
| 240 | + // if the user matches set the log condition to satisfied |
|
| 241 | + $this->logConditionSatisfied = true; |
|
| 242 | + } else { |
|
| 243 | + $userId = $user->getUID(); |
|
| 244 | + } |
|
| 245 | + } |
|
| 246 | + } |
|
| 247 | + } |
|
| 248 | + |
|
| 249 | + // if log condition is satisfied change the required log level to DEBUG |
|
| 250 | + if ($this->logConditionSatisfied) { |
|
| 251 | + $this->nestingLevel--; |
|
| 252 | + return ILogger::DEBUG; |
|
| 253 | + } |
|
| 254 | + |
|
| 255 | + if ($userId === false && isset($logCondition['matches'])) { |
|
| 256 | + $user = \OCP\Server::get(IUserSession::class)->getUser(); |
|
| 257 | + $userId = $user === null ? false : $user->getUID(); |
|
| 258 | + } |
|
| 259 | + |
|
| 260 | + if (isset($context['app'])) { |
|
| 261 | + /** |
|
| 262 | + * check log condition based on the context of each log message |
|
| 263 | + * once this is met -> change the required log level to debug |
|
| 264 | + */ |
|
| 265 | + if (in_array($context['app'], $logCondition['apps'] ?? [], true)) { |
|
| 266 | + $this->nestingLevel--; |
|
| 267 | + return ILogger::DEBUG; |
|
| 268 | + } |
|
| 269 | + } |
|
| 270 | + |
|
| 271 | + if (!isset($logCondition['matches'])) { |
|
| 272 | + $configLogLevel = $this->config->getValue('loglevel', ILogger::WARN); |
|
| 273 | + if (is_numeric($configLogLevel)) { |
|
| 274 | + $this->nestingLevel--; |
|
| 275 | + return min((int)$configLogLevel, ILogger::FATAL); |
|
| 276 | + } |
|
| 277 | + |
|
| 278 | + // Invalid configuration, warn the user and fall back to default level of WARN |
|
| 279 | + error_log('Nextcloud configuration: "loglevel" is not a valid integer'); |
|
| 280 | + $this->nestingLevel--; |
|
| 281 | + return ILogger::WARN; |
|
| 282 | + } |
|
| 283 | + |
|
| 284 | + foreach ($logCondition['matches'] as $option) { |
|
| 285 | + if ( |
|
| 286 | + (!isset($option['shared_secret']) || $this->checkLogSecret($option['shared_secret'])) |
|
| 287 | + && (!isset($option['users']) || in_array($userId, $option['users'], true)) |
|
| 288 | + && (!isset($option['apps']) || (isset($context['app']) && in_array($context['app'], $option['apps'], true))) |
|
| 289 | + && (!isset($option['message']) || str_contains($message, $option['message'])) |
|
| 290 | + ) { |
|
| 291 | + if (!isset($option['apps']) && !isset($option['loglevel']) && !isset($option['message'])) { |
|
| 292 | + /* Only user and/or secret are listed as conditions, we can cache the result for the rest of the request */ |
|
| 293 | + $this->logConditionSatisfied = true; |
|
| 294 | + $this->nestingLevel--; |
|
| 295 | + return ILogger::DEBUG; |
|
| 296 | + } |
|
| 297 | + $this->nestingLevel--; |
|
| 298 | + return $option['loglevel'] ?? ILogger::DEBUG; |
|
| 299 | + } |
|
| 300 | + } |
|
| 301 | + |
|
| 302 | + $this->nestingLevel--; |
|
| 303 | + return ILogger::WARN; |
|
| 304 | + } |
|
| 305 | + |
|
| 306 | + protected function checkLogSecret(string $conditionSecret): bool { |
|
| 307 | + $request = \OCP\Server::get(IRequest::class); |
|
| 308 | + |
|
| 309 | + if ($request->getMethod() === 'PUT' |
|
| 310 | + && !str_contains($request->getHeader('Content-Type'), 'application/x-www-form-urlencoded') |
|
| 311 | + && !str_contains($request->getHeader('Content-Type'), 'application/json')) { |
|
| 312 | + return hash_equals($conditionSecret, ''); |
|
| 313 | + } |
|
| 314 | + |
|
| 315 | + // if token is found in the request change set the log condition to satisfied |
|
| 316 | + return hash_equals($conditionSecret, $request->getParam('log_secret', '')); |
|
| 317 | + } |
|
| 318 | + |
|
| 319 | + /** |
|
| 320 | + * Logs an exception very detailed |
|
| 321 | + * |
|
| 322 | + * @param Exception|Throwable $exception |
|
| 323 | + * @param array $context |
|
| 324 | + * @return void |
|
| 325 | + * @since 8.2.0 |
|
| 326 | + */ |
|
| 327 | + public function logException(Throwable $exception, array $context = []): void { |
|
| 328 | + $app = $context['app'] ?? 'no app in context'; |
|
| 329 | + $level = $context['level'] ?? ILogger::ERROR; |
|
| 330 | + |
|
| 331 | + $minLevel = $this->getLogLevel($context, $context['message'] ?? $exception->getMessage()); |
|
| 332 | + if ($level < $minLevel |
|
| 333 | + && (($this->crashReporters?->hasReporters() ?? false) === false) |
|
| 334 | + && (($this->eventDispatcher?->hasListeners(BeforeMessageLoggedEvent::class) ?? false) === false)) { |
|
| 335 | + return; // no crash reporter, no listeners, we can stop for lower log level |
|
| 336 | + } |
|
| 337 | + |
|
| 338 | + // if an error is raised before the autoloader is properly setup, we can't serialize exceptions |
|
| 339 | + try { |
|
| 340 | + $serializer = $this->getSerializer(); |
|
| 341 | + } catch (Throwable $e) { |
|
| 342 | + $this->error('Failed to load ExceptionSerializer serializer while trying to log ' . $exception->getMessage()); |
|
| 343 | + return; |
|
| 344 | + } |
|
| 345 | + $data = $context; |
|
| 346 | + unset($data['app']); |
|
| 347 | + unset($data['level']); |
|
| 348 | + $data = array_merge($serializer->serializeException($exception), $data); |
|
| 349 | + $data = $this->interpolateMessage($data, isset($context['message']) && $context['message'] !== '' ? $context['message'] : ('Exception thrown: ' . get_class($exception)), 'CustomMessage'); |
|
| 350 | + |
|
| 351 | + array_walk($context, [$this->normalizer, 'format']); |
|
| 352 | + |
|
| 353 | + $this->eventDispatcher?->dispatchTyped(new BeforeMessageLoggedEvent($app, $level, $data)); |
|
| 354 | + |
|
| 355 | + try { |
|
| 356 | + if ($level >= $minLevel) { |
|
| 357 | + if (!$this->logger instanceof IFileBased) { |
|
| 358 | + $data = json_encode($data, JSON_PARTIAL_OUTPUT_ON_ERROR | JSON_UNESCAPED_SLASHES); |
|
| 359 | + } |
|
| 360 | + $this->writeLog($app, $data, $level); |
|
| 361 | + } |
|
| 362 | + |
|
| 363 | + $context['level'] = $level; |
|
| 364 | + if (!is_null($this->crashReporters)) { |
|
| 365 | + $this->crashReporters->delegateReport($exception, $context); |
|
| 366 | + } |
|
| 367 | + } catch (Throwable $e) { |
|
| 368 | + // make sure we dont hard crash if logging fails |
|
| 369 | + } |
|
| 370 | + } |
|
| 371 | + |
|
| 372 | + public function logData(string $message, array $data, array $context = []): void { |
|
| 373 | + $app = $context['app'] ?? 'no app in context'; |
|
| 374 | + $level = $context['level'] ?? ILogger::ERROR; |
|
| 375 | + |
|
| 376 | + $minLevel = $this->getLogLevel($context, $message); |
|
| 377 | + |
|
| 378 | + array_walk($context, [$this->normalizer, 'format']); |
|
| 379 | + |
|
| 380 | + try { |
|
| 381 | + if ($level >= $minLevel) { |
|
| 382 | + $data['message'] = $message; |
|
| 383 | + if (!$this->logger instanceof IFileBased) { |
|
| 384 | + $data = json_encode($data, JSON_PARTIAL_OUTPUT_ON_ERROR | JSON_UNESCAPED_SLASHES); |
|
| 385 | + } |
|
| 386 | + $this->writeLog($app, $data, $level); |
|
| 387 | + } |
|
| 388 | + |
|
| 389 | + $context['level'] = $level; |
|
| 390 | + } catch (Throwable $e) { |
|
| 391 | + // make sure we dont hard crash if logging fails |
|
| 392 | + error_log('Error when trying to log exception: ' . $e->getMessage() . ' ' . $e->getTraceAsString()); |
|
| 393 | + } |
|
| 394 | + } |
|
| 395 | + |
|
| 396 | + /** |
|
| 397 | + * @param string $app |
|
| 398 | + * @param string|array $entry |
|
| 399 | + * @param int $level |
|
| 400 | + */ |
|
| 401 | + protected function writeLog(string $app, $entry, int $level): void { |
|
| 402 | + $this->logger->write($app, $entry, $level); |
|
| 403 | + } |
|
| 404 | + |
|
| 405 | + public function getLogPath():string { |
|
| 406 | + if ($this->logger instanceof IFileBased) { |
|
| 407 | + return $this->logger->getLogFilePath(); |
|
| 408 | + } |
|
| 409 | + throw new \RuntimeException('Log implementation has no path'); |
|
| 410 | + } |
|
| 411 | + |
|
| 412 | + /** |
|
| 413 | + * Interpolate $message as defined in PSR-3 |
|
| 414 | + * |
|
| 415 | + * Returns an array containing the context without the interpolated |
|
| 416 | + * parameters placeholders and the message as the 'message' - or |
|
| 417 | + * user-defined - key. |
|
| 418 | + */ |
|
| 419 | + private function interpolateMessage(array $context, string $message, string $messageKey = 'message'): array { |
|
| 420 | + $replace = []; |
|
| 421 | + $usedContextKeys = []; |
|
| 422 | + foreach ($context as $key => $val) { |
|
| 423 | + $fullKey = '{' . $key . '}'; |
|
| 424 | + $replace[$fullKey] = $val; |
|
| 425 | + if (str_contains($message, $fullKey)) { |
|
| 426 | + $usedContextKeys[$key] = true; |
|
| 427 | + } |
|
| 428 | + } |
|
| 429 | + return array_merge(array_diff_key($context, $usedContextKeys), [$messageKey => strtr($message, $replace)]); |
|
| 430 | + } |
|
| 431 | + |
|
| 432 | + /** |
|
| 433 | + * @throws Throwable |
|
| 434 | + */ |
|
| 435 | + protected function getSerializer(): ExceptionSerializer { |
|
| 436 | + $serializer = new ExceptionSerializer($this->config); |
|
| 437 | + try { |
|
| 438 | + /** @var Coordinator $coordinator */ |
|
| 439 | + $coordinator = \OCP\Server::get(Coordinator::class); |
|
| 440 | + foreach ($coordinator->getRegistrationContext()->getSensitiveMethods() as $registration) { |
|
| 441 | + $serializer->enlistSensitiveMethods($registration->getName(), $registration->getValue()); |
|
| 442 | + } |
|
| 443 | + // For not every app might be initialized at this time, we cannot assume that the return value |
|
| 444 | + // of getSensitiveMethods() is complete. Running delegates in Coordinator::registerApps() is |
|
| 445 | + // not possible due to dependencies on the one hand. On the other it would work only with |
|
| 446 | + // adding public methods to the PsrLoggerAdapter and this class. |
|
| 447 | + // Thus, serializer cannot be a property. |
|
| 448 | + } catch (Throwable $t) { |
|
| 449 | + // ignore app-defined sensitive methods in this case - they weren't loaded anyway |
|
| 450 | + } |
|
| 451 | + return $serializer; |
|
| 452 | + } |
|
| 453 | 453 | } |