GLogger::error()   A
last analyzed

Complexity

Conditions 4
Paths 3

Size

Total Lines 6
Code Lines 4

Duplication

Lines 0
Ratio 0 %

Importance

Changes 1
Bugs 0 Features 0
Metric Value
cc 4
eloc 4
c 1
b 0
f 0
nc 3
nop 1
dl 0
loc 6
rs 10
1
<?php
2
3
/*
4
 * SPDX-License-Identifier: AGPL-3.0-only
5
 * SPDX-FileCopyrightText: Copyright 2016 - 2018 Kopano b.v.
6
 * SPDX-FileCopyrightText: Copyright 2020-2024 grommunio GmbH
7
 *
8
 * A wrapper for Monolog Logger.
9
 */
10
11
namespace grommunio\DAV;
12
13
use grommunio\DAV\MonologWrapper as Logger;
14
use Monolog\Formatter\LineFormatter;
15
use Monolog\Handler\ErrorLogHandler;
16
use Monolog\Handler\NullHandler;
17
use Monolog\Handler\StreamHandler;
18
use Monolog\Processor\ProcessIdProcessor;
19
use Sabre\HTTP\RequestInterface;
20
use Sabre\HTTP\ResponseInterface;
21
22
/**
23
 * GLogger: wraps the monolog Logger.
24
 *
25
 * If you want other methods of Logger please add a wrapper method to this class.
26
 */
27
class GLogger {
28
	protected static $listOfLoggers = [];
29
	protected static $parentLogger;
30
	protected $logger;
31
32
	/**
33
	 * Constructor.
34
	 *
35
	 * @param mixed $name
36
	 */
37
	public function __construct($name) {
38
		$this->logger = self::$parentLogger->withName($name);
39
40
		// keep an output puffer in case we do debug logging
41
		if ($this->logger->isHandling(Logger::DEBUG)) {
42
			ob_start();
43
		}
44
45
		// let GLogger handle error messages
46
		set_error_handler('\grommunio\DAV\GLogger::ErrorHandler');
47
	}
48
49
	/**
50
	 * Configures parent monolog Logger.
51
	 *
52
	 * This method needs to be called before the first logging event has
53
	 * occurred.
54
	 *
55
	 * @param array|string $configuration either a path to the configuration
56
	 *                                    file, or a configuration array
57
	 */
58
	public static function configure($configuration = null) {
59
		// Load configuration from ini-file if a file path (string) is given
60
		if (is_string($configuration)) {
61
			$configuration = parse_ini_file($configuration);
62
			if (!is_array($configuration)) {
0 ignored issues
show
introduced by
The condition is_array($configuration) is always true.
Loading history...
63
				throw new \Exception('Invalid GLogger configuration file');
64
			}
65
		}
66
		elseif (!is_array($configuration)) {
67
			throw new \Exception('GLogger configuration should be either a string with path to the configuration file, or a configuration array');
68
		}
69
70
		// Log level
71
		if (!isset($configuration['level'])) {
72
			$configuration['level'] = 'INFO';
73
		}
74
		elseif (!is_string($configuration['level'])) {
75
			throw new \Exception('GLogger configuration parameter "level" is not a string');
76
		}
77
78
		$configuration['level'] = strtoupper($configuration['level']);
79
		$allLogLevels = Logger::getLevels();
80
81
		if (!isset($allLogLevels[$configuration['level']])) {
82
			throw new \Exception('GLogger configuration parameter "level" is not known');
83
		}
84
85
		$logLevel = $allLogLevels[$configuration['level']];
86
87
		// Parent logger class
88
		static::$parentLogger = new Logger('');
89
90
		// Without configuration parameter 'file' all log messages will go to error_log()
91
		if (isset($configuration['file'])) {
92
			if (!is_string($configuration['file'])) {
93
				throw new \Exception('GLogger configuration parameter "file" is not a string');
94
			}
95
96
			$stream = new StreamHandler($configuration['file'], $logLevel);
97
		}
98
		else {
99
			$stream = new ErrorLogHandler(ErrorLogHandler::OPERATING_SYSTEM, $logLevel);
100
		}
101
102
		// Log messages formatting
103
		$lineFormat = null;
104
105
		if (isset($configuration['lineFormat']) && is_string($configuration['lineFormat'])) {
106
			$lineFormat = stripcslashes($configuration['lineFormat']);
107
		} // stripcslashes to recognize "\n"
108
109
		$timeFormat = null;
110
111
		if (isset($configuration['timeFormat']) && is_string($configuration['timeFormat'])) {
112
			$timeFormat = $configuration['timeFormat'];
113
		}
114
115
		if ($lineFormat || $timeFormat) {
116
			$formatter = new LineFormatter($lineFormat, $timeFormat, true, true);
117
			$stream->setFormatter($formatter);
118
		}
119
120
		static::$parentLogger->pushHandler($stream);
121
122
		// Add processor id (pid) to log messages
123
		static::$parentLogger->pushProcessor(new ProcessIdProcessor());
124
	}
125
126
	/**
127
	 * Destroy configurations for logger definitions.
128
	 */
129
	public function resetConfiguration() {
130
		if (static::$parentLogger) {
131
			static::$parentLogger->reset();
132
			static::$parentLogger->pushHandler(new NullHandler());
133
		}
134
		$this->logger = self::$parentLogger;
135
	}
136
137
	public function getGPSR3Logger() {
138
		return $this->logger;
139
	}
140
141
	/**
142
	 * Returns a GLogger by name. If it does not exist, it will be created.
143
	 *
144
	 * @param mixed $class
145
	 *
146
	 * @return Logger
147
	 */
148
	public static function GetLogger($class) {
149
		if (!isset(static::$listOfLoggers[$class])) {
150
			static::$listOfLoggers[$class] = new GLogger(static::GetClassnameOnly($class));
151
		}
152
153
		return static::$listOfLoggers[$class];
154
	}
155
156
	/**
157
	 * Cuts of the namespace and returns just the classname.
158
	 *
159
	 * @param string $namespaceWithClass
160
	 *
161
	 * @return string
162
	 */
163
	protected static function GetClassnameOnly($namespaceWithClass) {
164
		if (strpos($namespaceWithClass, '\\') == false) {
0 ignored issues
show
Bug Best Practice introduced by
It seems like you are loosely comparing strpos($namespaceWithClass, '\') of type integer to the boolean false. If you are specifically checking for 0, consider using something more explicit like === 0 instead.
Loading history...
165
			return $namespaceWithClass;
166
		}
167
168
		return substr(strrchr($namespaceWithClass, '\\'), 1);
169
	}
170
171
	/**
172
	 * Logs the incoming data (headers + body) to debug.
173
	 */
174
	public function LogIncoming(RequestInterface $request) {
175
		// only do any of this is we are looking for debug messages
176
		if ($this->logger->isHandling(Logger::DEBUG)) {
177
			$inputHeader = $request->getMethod() . ' ' . $request->getUrl() . ' HTTP/' . $request->getHTTPVersion() . "\r\n";
178
			foreach ($request->getHeaders() as $key => $value) {
179
				if ($key === 'Authorization') {
180
					list($value) = explode(' ', implode(',', $value), 2);
181
					$value = [$value . ' REDACTED'];
182
				}
183
				$inputHeader .= $key . ": " . implode(',', $value) . "\r\n";
184
			}
185
			// reopen the input so we can read it (again)
186
			$inputBody = stream_get_contents(fopen('php://input', 'r'));
187
			// format incoming xml to be better human readable
188
			if (stripos($inputBody, '<?xml') === 0) {
189
				$dom = new \DOMDocument('1.0', 'utf-8');
190
				$dom->preserveWhiteSpace = false;
191
				$dom->formatOutput = true;
192
				$dom->recover = true;
193
				$dom->loadXML($inputBody);
194
				$inputBody = $dom->saveXML();
195
			}
196
			// log incoming data
197
			$this->debug("INPUT\n" . $inputHeader . "\n" . $inputBody);
198
		}
199
	}
200
201
	/**
202
	 * Logs the outgoing data (headers + body) to debug.
203
	 */
204
	public function LogOutgoing(ResponseInterface $response) {
205
		// only do any of this is we are looking for debug messages
206
		if ($this->logger->isHandling(Logger::DEBUG)) {
207
			$output = 'HTTP/' . $response->getHttpVersion() . ' ' . $response->getStatus() . ' ' . $response->getStatusText() . "\n";
208
			foreach ($response->getHeaders() as $key => $value) {
209
				$output .= $key . ": " . implode(',', $value) . "\n";
210
			}
211
			$outputBody = ob_get_contents();
212
			if (stripos($outputBody, '<?xml') === 0) {
213
				$dom = new \DOMDocument('1.0', 'utf-8');
214
				$dom->preserveWhiteSpace = false;
215
				$dom->formatOutput = true;
216
				$dom->recover = true;
217
				$dom->loadXML($outputBody);
218
				$outputBody = $dom->saveXML();
219
			}
220
			$this->debug("OUTPUT:\n" . $output . "\n" . $outputBody);
221
222
			ob_end_flush();
223
		}
224
	}
225
226
	/**
227
	 * Runs the arguments through sprintf() and sends it to the logger.
228
	 *
229
	 * @param int    $level
230
	 * @param array  $args
231
	 * @param string $suffix an optional suffix that is appended to the message
232
	 */
233
	protected function writeLog($level, $args, $suffix = '') {
234
		$outArgs = [];
235
		foreach ($args as $arg) {
236
			if (is_array($arg)) {
237
				$outArgs[] = print_r($arg, true);
238
			}
239
			$outArgs[] = $arg;
240
		}
241
		// Call sprintf() with the arguments only if there are format parameters because
242
		// otherwise sprintf will complain about too few arguments.
243
		// This also prevents throwing errors if there are %-chars in the $outArgs.
244
		$message = (count($outArgs) > 1) ? call_user_func_array('sprintf', $outArgs) : $outArgs[0];
245
		// prepend class+method and log the message
246
		$this->logger->log($level, $this->getCaller(2) . $message . $suffix);
247
	}
248
249
	/**
250
	 * Verifies if the dynamic amount of logging arguments matches the amount of variables (%) in the message.
251
	 *
252
	 * @param array $arguments
253
	 *
254
	 * @return bool
255
	 */
256
	protected function verifyLogSyntax($arguments) {
257
		$count = count($arguments);
258
		$quoted_procent = substr_count($arguments[0], "%%");
259
		$t = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 3);
260
261
		if ($count == 0) {
262
			$this->logger->error(sprintf(
263
				"No arguments in %s->%s() logging to '%s' in %s:%d",
264
				static::GetClassnameOnly($t[2]['class']),
265
				$t[2]['function'],
266
				$t[1]['function'],
267
				$t[1]['file'],
268
				$t[1]['line']
269
			));
270
271
			return false;
272
		}
273
		// Only check formatting if there are format parameters. Otherwise there will be
274
		// an error log if the $arguments[0] contain %-chars.
275
		if (($count > 1) && ((substr_count($arguments[0], "%") - $quoted_procent * 2) !== $count - 1)) {
276
			$this->logger->error(sprintf(
277
				"Wrong number of arguments in %s->%s() logging to '%s' in %s:%d",
278
				static::GetClassnameOnly($t[2]['class']),
279
				$t[2]['function'],
280
				$t[1]['function'],
281
				$t[1]['file'],
282
				$t[1]['line']
283
			));
284
285
			return false;
286
		}
287
288
		return true;
289
	}
290
291
	/**
292
	 * Returns a string in the form of "Class->Method(): " or "file:line" if requested.
293
	 *
294
	 * @param number $level    the level you want the info from, default 1
295
	 * @param bool   $fileline returns "file:line" if set to true
296
	 *
297
	 * @return string
298
	 */
299
	protected function getCaller($level = 1, $fileline = false) {
300
		$wlevel = $level + 1;
301
		$t = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, $wlevel + 1);
0 ignored issues
show
Bug introduced by
$wlevel + 1 of type double is incompatible with the type integer expected by parameter $limit of debug_backtrace(). ( Ignorable by Annotation )

If this is a false-positive, you can also ignore this issue in your code via the ignore-type  annotation

301
		$t = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, /** @scrutinizer ignore-type */ $wlevel + 1);
Loading history...
302
		if (isset($t[$wlevel]['function'])) {
303
			if ($fileline) {
304
				return ($t[$wlevel]['file'] ?? "unknown file") . ":" . ($t[$wlevel]['line'] ?? "unknown line");
305
			}
306
307
			return $this->GetClassnameOnly($t[$wlevel]['class']) . '->' . $t[$wlevel]['function'] . '(): ';
308
		}
309
310
		return '';
311
	}
312
313
	/**
314
	 * Format bytes to a more human readable value.
315
	 *
316
	 * @param int $bytes
317
	 * @param int $precision
318
	 *
319
	 * @return string
320
	 */
321
	public function FormatBytes($bytes, $precision = 2) {
322
		if ($bytes <= 0) {
323
			return '0 B';
324
		}
325
326
		$units = ['B', 'KiB', 'MiB', 'GiB', 'TiB', 'PiB', 'EiB', 'ZiB'];
327
		$base = log($bytes, 1024);
328
		$fBase = floor($base);
329
		$pow = pow(1024, $base - $fBase);
330
331
		return sprintf("%.{$precision}f %s", $pow, $units[$fBase]);
332
	}
333
334
	/**
335
	 * The GrommunioDav error handler.
336
	 *
337
	 * @param int    $errno
338
	 * @param string $errstr
339
	 * @param string $errfile
340
	 * @param int    $errline
341
	 * @param mixed  $errcontext
342
	 */
343
	public static function ErrorHandler($errno, $errstr, $errfile, $errline, $errcontext = []) {
0 ignored issues
show
Unused Code introduced by
The parameter $errcontext is not used and could be removed. ( Ignorable by Annotation )

If this is a false-positive, you can also ignore this issue in your code via the ignore-unused  annotation

343
	public static function ErrorHandler($errno, $errstr, $errfile, $errline, /** @scrutinizer ignore-unused */ $errcontext = []) {

This check looks for parameters that have been defined for a function or method, but which are not used in the method body.

Loading history...
344
		if (defined('LOG_ERROR_MASK')) {
345
			$errno &= \LOG_ERROR_MASK;
0 ignored issues
show
Bug introduced by
The constant LOG_ERROR_MASK was not found. Maybe you did not declare it correctly or list all dependencies?
Loading history...
346
		}
347
348
		$logger = new GLogger('error');
349
350
		switch ($errno) {
351
			case 0:
352
				// logging disabled by LOG_ERROR_MASK
353
				break;
354
355
			case E_DEPRECATED:
356
				// do not handle this message
357
				break;
358
359
			case E_NOTICE:
360
			case E_WARNING:
361
				$logger->warn("{$errfile}:{$errline} {$errstr} ({$errno})");
362
				break;
363
364
			default:
365
				$bt = debug_backtrace();
366
				$logger->error("trace error: {$errfile}:{$errline} {$errstr} ({$errno}) - backtrace: " . (count($bt) - 1) . " steps");
367
				for ($i = 1, $bt_length = count($bt); $i < $bt_length; ++$i) {
368
					$file = $bt[$i]['file'] ?? "unknown file";
369
					$line = $bt[$i]['line'] ?? "unknown line";
370
371
					$logger->error("trace {$i}: {$file}:{$line} - " . (isset($bt[$i]['class']) ? $bt[$i]['class'] . $bt[$i]['type'] : "") . $bt[$i]['function'] . "()");
372
				}
373
				break;
374
		}
375
	}
376
377
	/**
378
	 * Wrapper of the Logger class.
379
	 */
380
381
	/**
382
	 * Log a message object with the TRACE level.
383
	 * It has the same footprint as sprintf(), but arguments are only processed
384
	 * if the loglevel is activated.
385
	 *
386
	 * @param mixed $message message
387
	 */
388
	public function trace(...$message) {
389
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
390
			return;
391
		}
392
		if ($this->logger->isHandling(Logger::TRACE)) {
393
			$this->writeLog(Logger::TRACE, $message);
394
		}
395
	}
396
397
	/**
398
	 * Log a message object with the DEBUG level.
399
	 * It has the same footprint as sprintf(), but arguments are only processed
400
	 * if the loglevel is activated.
401
	 *
402
	 * @param mixed $message message
403
	 */
404
	public function debug(...$message) {
405
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
406
			return;
407
		}
408
		if ($this->logger->isHandling(Logger::DEBUG)) {
409
			$this->writeLog(Logger::DEBUG, $message);
410
		}
411
	}
412
413
	/**
414
	 * Log a message object with the INFO level.
415
	 * It has the same footprint as sprintf(), but arguments are only processed
416
	 * if the loglevel is activated.
417
	 *
418
	 * @param mixed $message message
419
	 */
420
	public function info(...$message) {
421
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
422
			return;
423
		}
424
		if ($this->logger->isHandling(Logger::INFO)) {
425
			$this->writeLog(Logger::INFO, $message);
426
		}
427
	}
428
429
	/**
430
	 * Log a message object with the WARN level.
431
	 * It has the same footprint as sprintf(), but arguments are only processed
432
	 * if the loglevel is activated.
433
	 *
434
	 * @param mixed $message message
435
	 */
436
	public function warn(...$message) {
437
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
438
			return;
439
		}
440
		if ($this->logger->isHandling(Logger::WARNING)) {
441
			$this->writeLog(Logger::WARNING, $message, ' - ' . $this->getCaller(1, true));
442
		}
443
	}
444
445
	/**
446
	 * Log a message object with the ERROR level.
447
	 * It has the same footprint as sprintf(), but arguments are only processed
448
	 * if the loglevel is activated.
449
	 *
450
	 * @param mixed $message message
451
	 */
452
	public function error(...$message) {
453
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
454
			return;
455
		}
456
		if ($this->logger->isHandling(Logger::ERROR)) {
457
			$this->writeLog(Logger::ERROR, $message, ' - ' . $this->getCaller(1, true));
458
		}
459
	}
460
461
	/**
462
	 * Log a message object with the FATAL level.
463
	 * It has the same footprint as sprintf(), but arguments are only processed
464
	 * if the loglevel is activated.
465
	 *
466
	 * @param mixed $message message
467
	 */
468
	public function fatal(...$message) {
469
		if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) {
470
			return;
471
		}
472
		if ($this->logger->isHandling(Logger::CRITICAL)) {
473
			$this->writeLog(Logger::CRITICAL, $message, ' - ' . $this->getCaller(1, true));
474
		}
475
	}
476
}
477