1
|
|
|
<?php |
2
|
|
|
/* |
3
|
|
|
* SPDX-License-Identifier: AGPL-3.0-only |
4
|
|
|
* SPDX-FileCopyrightText: Copyright 2016 - 2018 Kopano b.v. |
5
|
|
|
* SPDX-FileCopyrightText: Copyright 2020-2024 grommunio GmbH |
6
|
|
|
* |
7
|
|
|
* A wrapper for Monolog Logger. |
8
|
|
|
*/ |
9
|
|
|
|
10
|
|
|
namespace grommunio\DAV; |
11
|
|
|
|
12
|
|
|
use grommunio\DAV\MonologWrapper as Logger; |
13
|
|
|
use Monolog\Formatter\LineFormatter; |
14
|
|
|
use Monolog\Handler\ErrorLogHandler; |
15
|
|
|
use Monolog\Handler\NullHandler; |
16
|
|
|
use Monolog\Handler\StreamHandler; |
17
|
|
|
use Monolog\Processor\ProcessIdProcessor; |
18
|
|
|
use Sabre\HTTP\RequestInterface; |
19
|
|
|
use Sabre\HTTP\ResponseInterface; |
20
|
|
|
|
21
|
|
|
/** |
22
|
|
|
* GLogger: wraps the monolog Logger. |
23
|
|
|
* |
24
|
|
|
* If you want other methods of Logger please add a wrapper method to this class. |
25
|
|
|
*/ |
26
|
|
|
class GLogger { |
27
|
|
|
protected static $listOfLoggers = []; |
28
|
|
|
protected static $parentLogger; |
29
|
|
|
protected $logger; |
30
|
|
|
|
31
|
|
|
/** |
32
|
|
|
* Constructor. |
33
|
|
|
* |
34
|
|
|
* @param mixed $name |
35
|
|
|
*/ |
36
|
|
|
public function __construct($name) { |
37
|
|
|
$this->logger = self::$parentLogger->withName($name); |
38
|
|
|
|
39
|
|
|
// keep an output puffer in case we do debug logging |
40
|
|
|
if ($this->logger->isHandling(Logger::DEBUG)) { |
41
|
|
|
ob_start(); |
42
|
|
|
} |
43
|
|
|
|
44
|
|
|
// let GLogger handle error messages |
45
|
|
|
set_error_handler('\grommunio\DAV\GLogger::ErrorHandler'); |
46
|
|
|
} |
47
|
|
|
|
48
|
|
|
/** |
49
|
|
|
* Configures parent monolog Logger. |
50
|
|
|
* |
51
|
|
|
* This method needs to be called before the first logging event has |
52
|
|
|
* occurred. |
53
|
|
|
* |
54
|
|
|
* @param array|string $configuration either a path to the configuration |
55
|
|
|
* file, or a configuration array |
56
|
|
|
*/ |
57
|
|
|
public static function configure($configuration = null) { |
58
|
|
|
// Load configuration from ini-file if a file path (string) is given |
59
|
|
|
if (is_string($configuration)) { |
60
|
|
|
$configuration = parse_ini_file($configuration); |
61
|
|
|
if (!is_array($configuration)) { |
|
|
|
|
62
|
|
|
throw new \Exception('Invalid GLogger configuration file'); |
63
|
|
|
} |
64
|
|
|
} |
65
|
|
|
elseif (!is_array($configuration)) { |
66
|
|
|
throw new \Exception('GLogger configuration should be either a string with path to the configuration file, or a configuration array'); |
67
|
|
|
} |
68
|
|
|
|
69
|
|
|
// Log level |
70
|
|
|
if (!isset($configuration['level'])) { |
71
|
|
|
$configuration['level'] = 'INFO'; |
72
|
|
|
} |
73
|
|
|
elseif (!is_string($configuration['level'])) { |
74
|
|
|
throw new \Exception('GLogger configuration parameter "level" is not a string'); |
75
|
|
|
} |
76
|
|
|
|
77
|
|
|
$configuration['level'] = strtoupper($configuration['level']); |
78
|
|
|
$allLogLevels = Logger::getLevels(); |
79
|
|
|
|
80
|
|
|
if (!isset($allLogLevels[$configuration['level']])) { |
81
|
|
|
throw new \Exception('GLogger configuration parameter "level" is not known'); |
82
|
|
|
} |
83
|
|
|
|
84
|
|
|
$logLevel = $allLogLevels[$configuration['level']]; |
85
|
|
|
|
86
|
|
|
// Parent logger class |
87
|
|
|
static::$parentLogger = new Logger(''); |
88
|
|
|
|
89
|
|
|
// Without configuration parameter 'file' all log messages will go to error_log() |
90
|
|
|
if (isset($configuration['file'])) { |
91
|
|
|
if (!is_string($configuration['file'])) { |
92
|
|
|
throw new \Exception('GLogger configuration parameter "file" is not a string'); |
93
|
|
|
} |
94
|
|
|
|
95
|
|
|
$stream = new StreamHandler($configuration['file'], $logLevel); |
96
|
|
|
} |
97
|
|
|
else { |
98
|
|
|
$stream = new ErrorLogHandler(ErrorLogHandler::OPERATING_SYSTEM, $logLevel); |
99
|
|
|
} |
100
|
|
|
|
101
|
|
|
// Log messages formatting |
102
|
|
|
$lineFormat = null; |
103
|
|
|
|
104
|
|
|
if (isset($configuration['lineFormat']) && is_string($configuration['lineFormat'])) { |
105
|
|
|
$lineFormat = stripcslashes($configuration['lineFormat']); |
106
|
|
|
} // stripcslashes to recognize "\n" |
107
|
|
|
|
108
|
|
|
$timeFormat = null; |
109
|
|
|
|
110
|
|
|
if (isset($configuration['timeFormat']) && is_string($configuration['timeFormat'])) { |
111
|
|
|
$timeFormat = $configuration['timeFormat']; |
112
|
|
|
} |
113
|
|
|
|
114
|
|
|
if ($lineFormat || $timeFormat) { |
115
|
|
|
$formatter = new LineFormatter($lineFormat, $timeFormat, true, true); |
116
|
|
|
$stream->setFormatter($formatter); |
117
|
|
|
} |
118
|
|
|
|
119
|
|
|
static::$parentLogger->pushHandler($stream); |
120
|
|
|
|
121
|
|
|
// Add processor id (pid) to log messages |
122
|
|
|
static::$parentLogger->pushProcessor(new ProcessIdProcessor()); |
123
|
|
|
} |
124
|
|
|
|
125
|
|
|
/** |
126
|
|
|
* Destroy configurations for logger definitions. |
127
|
|
|
*/ |
128
|
|
|
public function resetConfiguration() { |
129
|
|
|
if (static::$parentLogger) { |
130
|
|
|
static::$parentLogger->reset(); |
131
|
|
|
static::$parentLogger->pushHandler(new NullHandler()); |
132
|
|
|
} |
133
|
|
|
$this->logger = self::$parentLogger; |
134
|
|
|
} |
135
|
|
|
|
136
|
|
|
public function getGPSR3Logger() { |
137
|
|
|
return $this->logger; |
138
|
|
|
} |
139
|
|
|
|
140
|
|
|
/** |
141
|
|
|
* Returns a GLogger by name. If it does not exist, it will be created. |
142
|
|
|
* |
143
|
|
|
* @param mixed $class |
144
|
|
|
* |
145
|
|
|
* @return Logger |
146
|
|
|
*/ |
147
|
|
|
public static function GetLogger($class) { |
148
|
|
|
if (!isset(static::$listOfLoggers[$class])) { |
149
|
|
|
static::$listOfLoggers[$class] = new GLogger(static::GetClassnameOnly($class)); |
150
|
|
|
} |
151
|
|
|
|
152
|
|
|
return static::$listOfLoggers[$class]; |
153
|
|
|
} |
154
|
|
|
|
155
|
|
|
/** |
156
|
|
|
* Cuts of the namespace and returns just the classname. |
157
|
|
|
* |
158
|
|
|
* @param string $namespaceWithClass |
159
|
|
|
* |
160
|
|
|
* @return string |
161
|
|
|
*/ |
162
|
|
|
protected static function GetClassnameOnly($namespaceWithClass) { |
163
|
|
|
if (strpos($namespaceWithClass, '\\') == false) { |
|
|
|
|
164
|
|
|
return $namespaceWithClass; |
165
|
|
|
} |
166
|
|
|
|
167
|
|
|
return substr(strrchr($namespaceWithClass, '\\'), 1); |
168
|
|
|
} |
169
|
|
|
|
170
|
|
|
/** |
171
|
|
|
* Logs the incoming data (headers + body) to debug. |
172
|
|
|
*/ |
173
|
|
|
public function LogIncoming(RequestInterface $request) { |
174
|
|
|
// only do any of this is we are looking for debug messages |
175
|
|
|
if ($this->logger->isHandling(Logger::DEBUG)) { |
176
|
|
|
$inputHeader = $request->getMethod() . ' ' . $request->getUrl() . ' HTTP/' . $request->getHTTPVersion() . "\r\n"; |
177
|
|
|
foreach ($request->getHeaders() as $key => $value) { |
178
|
|
|
if ($key === 'Authorization') { |
179
|
|
|
list($value) = explode(' ', implode(',', $value), 2); |
180
|
|
|
$value = [$value . ' REDACTED']; |
181
|
|
|
} |
182
|
|
|
$inputHeader .= $key . ": " . implode(',', $value) . "\r\n"; |
183
|
|
|
} |
184
|
|
|
// reopen the input so we can read it (again) |
185
|
|
|
$inputBody = stream_get_contents(fopen('php://input', 'r')); |
186
|
|
|
// format incoming xml to be better human readable |
187
|
|
|
if (stripos($inputBody, '<?xml') === 0) { |
188
|
|
|
$dom = new \DOMDocument('1.0', 'utf-8'); |
189
|
|
|
$dom->preserveWhiteSpace = false; |
190
|
|
|
$dom->formatOutput = true; |
191
|
|
|
$dom->recover = true; |
192
|
|
|
$dom->loadXML($inputBody); |
193
|
|
|
$inputBody = $dom->saveXML(); |
194
|
|
|
} |
195
|
|
|
// log incoming data |
196
|
|
|
$this->debug("INPUT\n" . $inputHeader . "\n" . $inputBody); |
197
|
|
|
} |
198
|
|
|
} |
199
|
|
|
|
200
|
|
|
/** |
201
|
|
|
* Logs the outgoing data (headers + body) to debug. |
202
|
|
|
*/ |
203
|
|
|
public function LogOutgoing(ResponseInterface $response) { |
204
|
|
|
// only do any of this is we are looking for debug messages |
205
|
|
|
if ($this->logger->isHandling(Logger::DEBUG)) { |
206
|
|
|
$output = 'HTTP/' . $response->getHttpVersion() . ' ' . $response->getStatus() . ' ' . $response->getStatusText() . "\n"; |
207
|
|
|
foreach ($response->getHeaders() as $key => $value) { |
208
|
|
|
$output .= $key . ": " . implode(',', $value) . "\n"; |
209
|
|
|
} |
210
|
|
|
$outputBody = ob_get_contents(); |
211
|
|
|
if (stripos($outputBody, '<?xml') === 0) { |
212
|
|
|
$dom = new \DOMDocument('1.0', 'utf-8'); |
213
|
|
|
$dom->preserveWhiteSpace = false; |
214
|
|
|
$dom->formatOutput = true; |
215
|
|
|
$dom->recover = true; |
216
|
|
|
$dom->loadXML($outputBody); |
217
|
|
|
$outputBody = $dom->saveXML(); |
218
|
|
|
} |
219
|
|
|
$this->debug("OUTPUT:\n" . $output . "\n" . $outputBody); |
220
|
|
|
|
221
|
|
|
ob_end_flush(); |
222
|
|
|
} |
223
|
|
|
} |
224
|
|
|
|
225
|
|
|
/** |
226
|
|
|
* Runs the arguments through sprintf() and sends it to the logger. |
227
|
|
|
* |
228
|
|
|
* @param int $level |
229
|
|
|
* @param array $args |
230
|
|
|
* @param string $suffix an optional suffix that is appended to the message |
231
|
|
|
*/ |
232
|
|
|
protected function writeLog($level, $args, $suffix = '') { |
233
|
|
|
$outArgs = []; |
234
|
|
|
foreach ($args as $arg) { |
235
|
|
|
if (is_array($arg)) { |
236
|
|
|
$outArgs[] = print_r($arg, true); |
237
|
|
|
} |
238
|
|
|
$outArgs[] = $arg; |
239
|
|
|
} |
240
|
|
|
// Call sprintf() with the arguments only if there are format parameters because |
241
|
|
|
// otherwise sprintf will complain about too few arguments. |
242
|
|
|
// This also prevents throwing errors if there are %-chars in the $outArgs. |
243
|
|
|
$message = (count($outArgs) > 1) ? call_user_func_array('sprintf', $outArgs) : $outArgs[0]; |
244
|
|
|
// prepend class+method and log the message |
245
|
|
|
$this->logger->log($level, $this->getCaller(2) . $message . $suffix); |
246
|
|
|
} |
247
|
|
|
|
248
|
|
|
/** |
249
|
|
|
* Verifies if the dynamic amount of logging arguments matches the amount of variables (%) in the message. |
250
|
|
|
* |
251
|
|
|
* @param array $arguments |
252
|
|
|
* |
253
|
|
|
* @return bool |
254
|
|
|
*/ |
255
|
|
|
protected function verifyLogSyntax($arguments) { |
256
|
|
|
$count = count($arguments); |
257
|
|
|
$quoted_procent = substr_count($arguments[0], "%%"); |
258
|
|
|
$t = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 3); |
259
|
|
|
|
260
|
|
|
if ($count == 0) { |
261
|
|
|
$this->logger->error(sprintf( |
262
|
|
|
"No arguments in %s->%s() logging to '%s' in %s:%d", |
263
|
|
|
static::GetClassnameOnly($t[2]['class']), |
264
|
|
|
$t[2]['function'], |
265
|
|
|
$t[1]['function'], |
266
|
|
|
$t[1]['file'], |
267
|
|
|
$t[1]['line'] |
268
|
|
|
)); |
269
|
|
|
|
270
|
|
|
return false; |
271
|
|
|
} |
272
|
|
|
// Only check formatting if there are format parameters. Otherwise there will be |
273
|
|
|
// an error log if the $arguments[0] contain %-chars. |
274
|
|
|
if (($count > 1) && ((substr_count($arguments[0], "%") - $quoted_procent * 2) !== $count - 1)) { |
275
|
|
|
$this->logger->error(sprintf( |
276
|
|
|
"Wrong number of arguments in %s->%s() logging to '%s' in %s:%d", |
277
|
|
|
static::GetClassnameOnly($t[2]['class']), |
278
|
|
|
$t[2]['function'], |
279
|
|
|
$t[1]['function'], |
280
|
|
|
$t[1]['file'], |
281
|
|
|
$t[1]['line'] |
282
|
|
|
)); |
283
|
|
|
|
284
|
|
|
return false; |
285
|
|
|
} |
286
|
|
|
|
287
|
|
|
return true; |
288
|
|
|
} |
289
|
|
|
|
290
|
|
|
/** |
291
|
|
|
* Returns a string in the form of "Class->Method(): " or "file:line" if requested. |
292
|
|
|
* |
293
|
|
|
* @param number $level the level you want the info from, default 1 |
294
|
|
|
* @param bool $fileline returns "file:line" if set to true |
295
|
|
|
* |
296
|
|
|
* @return string |
297
|
|
|
*/ |
298
|
|
|
protected function getCaller($level = 1, $fileline = false) { |
299
|
|
|
$wlevel = $level + 1; |
300
|
|
|
$t = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, $wlevel + 1); |
|
|
|
|
301
|
|
|
if (isset($t[$wlevel]['function'])) { |
302
|
|
|
if ($fileline) { |
303
|
|
|
return ($t[$wlevel]['file'] ?? "unknown file") . ":" . ($t[$wlevel]['line'] ?? "unknown line"); |
304
|
|
|
} |
305
|
|
|
|
306
|
|
|
return $this->GetClassnameOnly($t[$wlevel]['class']) . '->' . $t[$wlevel]['function'] . '(): '; |
307
|
|
|
} |
308
|
|
|
|
309
|
|
|
return ''; |
310
|
|
|
} |
311
|
|
|
|
312
|
|
|
/** |
313
|
|
|
* Format bytes to a more human readable value. |
314
|
|
|
* |
315
|
|
|
* @param int $bytes |
316
|
|
|
* @param int $precision |
317
|
|
|
* |
318
|
|
|
* @return string |
319
|
|
|
*/ |
320
|
|
|
public function FormatBytes($bytes, $precision = 2) { |
321
|
|
|
if ($bytes <= 0) { |
322
|
|
|
return '0 B'; |
323
|
|
|
} |
324
|
|
|
|
325
|
|
|
$units = ['B', 'KiB', 'MiB', 'GiB', 'TiB', 'PiB', 'EiB', 'ZiB']; |
326
|
|
|
$base = log($bytes, 1024); |
327
|
|
|
$fBase = floor($base); |
328
|
|
|
$pow = pow(1024, $base - $fBase); |
329
|
|
|
|
330
|
|
|
return sprintf("%.{$precision}f %s", $pow, $units[$fBase]); |
331
|
|
|
} |
332
|
|
|
|
333
|
|
|
/** |
334
|
|
|
* The GrommunioDav error handler. |
335
|
|
|
* |
336
|
|
|
* @param int $errno |
337
|
|
|
* @param string $errstr |
338
|
|
|
* @param string $errfile |
339
|
|
|
* @param int $errline |
340
|
|
|
* @param mixed $errcontext |
341
|
|
|
*/ |
342
|
|
|
public static function ErrorHandler($errno, $errstr, $errfile, $errline, $errcontext = []) { |
|
|
|
|
343
|
|
|
if (defined('LOG_ERROR_MASK')) { |
344
|
|
|
$errno &= \LOG_ERROR_MASK; |
|
|
|
|
345
|
|
|
} |
346
|
|
|
|
347
|
|
|
$logger = new GLogger('error'); |
348
|
|
|
|
349
|
|
|
switch ($errno) { |
350
|
|
|
case 0: |
351
|
|
|
// logging disabled by LOG_ERROR_MASK |
352
|
|
|
break; |
353
|
|
|
|
354
|
|
|
case E_DEPRECATED: |
355
|
|
|
// do not handle this message |
356
|
|
|
break; |
357
|
|
|
|
358
|
|
|
case E_NOTICE: |
359
|
|
|
case E_WARNING: |
360
|
|
|
$logger->warn("{$errfile}:{$errline} {$errstr} ({$errno})"); |
361
|
|
|
break; |
362
|
|
|
|
363
|
|
|
default: |
364
|
|
|
$bt = debug_backtrace(); |
365
|
|
|
$logger->error("trace error: {$errfile}:{$errline} {$errstr} ({$errno}) - backtrace: " . (count($bt) - 1) . " steps"); |
366
|
|
|
for ($i = 1, $bt_length = count($bt); $i < $bt_length; ++$i) { |
367
|
|
|
$file = $bt[$i]['file'] ?? "unknown file"; |
368
|
|
|
$line = $bt[$i]['line'] ?? "unknown line"; |
369
|
|
|
|
370
|
|
|
$logger->error("trace {$i}: {$file}:{$line} - " . (isset($bt[$i]['class']) ? $bt[$i]['class'] . $bt[$i]['type'] : "") . $bt[$i]['function'] . "()"); |
371
|
|
|
} |
372
|
|
|
break; |
373
|
|
|
} |
374
|
|
|
} |
375
|
|
|
|
376
|
|
|
/** |
377
|
|
|
* Wrapper of the Logger class. |
378
|
|
|
*/ |
379
|
|
|
|
380
|
|
|
/** |
381
|
|
|
* Log a message object with the TRACE level. |
382
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
383
|
|
|
* if the loglevel is activated. |
384
|
|
|
* |
385
|
|
|
* @param mixed $message message |
386
|
|
|
*/ |
387
|
|
|
public function trace(...$message) { |
388
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
389
|
|
|
return; |
390
|
|
|
} |
391
|
|
|
if ($this->logger->isHandling(Logger::TRACE)) { |
392
|
|
|
$this->writeLog(Logger::TRACE, $message); |
393
|
|
|
} |
394
|
|
|
} |
395
|
|
|
|
396
|
|
|
/** |
397
|
|
|
* Log a message object with the DEBUG level. |
398
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
399
|
|
|
* if the loglevel is activated. |
400
|
|
|
* |
401
|
|
|
* @param mixed $message message |
402
|
|
|
*/ |
403
|
|
|
public function debug(...$message) { |
404
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
405
|
|
|
return; |
406
|
|
|
} |
407
|
|
|
if ($this->logger->isHandling(Logger::DEBUG)) { |
408
|
|
|
$this->writeLog(Logger::DEBUG, $message); |
409
|
|
|
} |
410
|
|
|
} |
411
|
|
|
|
412
|
|
|
/** |
413
|
|
|
* Log a message object with the INFO level. |
414
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
415
|
|
|
* if the loglevel is activated. |
416
|
|
|
* |
417
|
|
|
* @param mixed $message message |
418
|
|
|
*/ |
419
|
|
|
public function info(...$message) { |
420
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
421
|
|
|
return; |
422
|
|
|
} |
423
|
|
|
if ($this->logger->isHandling(Logger::INFO)) { |
424
|
|
|
$this->writeLog(Logger::INFO, $message); |
425
|
|
|
} |
426
|
|
|
} |
427
|
|
|
|
428
|
|
|
/** |
429
|
|
|
* Log a message object with the WARN level. |
430
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
431
|
|
|
* if the loglevel is activated. |
432
|
|
|
* |
433
|
|
|
* @param mixed $message message |
434
|
|
|
*/ |
435
|
|
|
public function warn(...$message) { |
436
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
437
|
|
|
return; |
438
|
|
|
} |
439
|
|
|
if ($this->logger->isHandling(Logger::WARNING)) { |
440
|
|
|
$this->writeLog(Logger::WARNING, $message, ' - ' . $this->getCaller(1, true)); |
441
|
|
|
} |
442
|
|
|
} |
443
|
|
|
|
444
|
|
|
/** |
445
|
|
|
* Log a message object with the ERROR level. |
446
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
447
|
|
|
* if the loglevel is activated. |
448
|
|
|
* |
449
|
|
|
* @param mixed $message message |
450
|
|
|
*/ |
451
|
|
|
public function error(...$message) { |
452
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
453
|
|
|
return; |
454
|
|
|
} |
455
|
|
|
if ($this->logger->isHandling(Logger::ERROR)) { |
456
|
|
|
$this->writeLog(Logger::ERROR, $message, ' - ' . $this->getCaller(1, true)); |
457
|
|
|
} |
458
|
|
|
} |
459
|
|
|
|
460
|
|
|
/** |
461
|
|
|
* Log a message object with the FATAL level. |
462
|
|
|
* It has the same footprint as sprintf(), but arguments are only processed |
463
|
|
|
* if the loglevel is activated. |
464
|
|
|
* |
465
|
|
|
* @param mixed $message message |
466
|
|
|
*/ |
467
|
|
|
public function fatal(...$message) { |
468
|
|
|
if (DEVELOPER_MODE && !$this->verifyLogSyntax($message)) { |
469
|
|
|
return; |
470
|
|
|
} |
471
|
|
|
if ($this->logger->isHandling(Logger::CRITICAL)) { |
472
|
|
|
$this->writeLog(Logger::CRITICAL, $message, ' - ' . $this->getCaller(1, true)); |
473
|
|
|
} |
474
|
|
|
} |
475
|
|
|
} |
476
|
|
|
|