diff --git a/composer.json b/composer.json index 61bf184..5f3c43e 100644 --- a/composer.json +++ b/composer.json @@ -20,9 +20,11 @@ "ext-json": "*", "ext-simplexml": "*", "symfony/console": "^5.4", - "psr/container": "^1.1 || ^2.0.1" + "psr/container": "^1.1 || ^2.0.1", + "psr/log": "^1.1 || ^2.0" }, "require-dev": { + "monolog/monolog": "^2.0 || ^3.0", "yoast/phpunit-polyfills": "^1.0" }, "suggest": { diff --git a/src/xPDO/Logging/xPDOLogger.php b/src/xPDO/Logging/xPDOLogger.php new file mode 100644 index 0000000..d0441cb --- /dev/null +++ b/src/xPDO/Logging/xPDOLogger.php @@ -0,0 +1,263 @@ + + * + * For the full copyright and license information, please view the LICENSE + * file that was distributed with this source code. + */ + +namespace xPDO\Logging; + +use Psr\Log\AbstractLogger; +use Psr\Log\LogLevel; +use xPDO\Cache\xPDOCacheManager; +use xPDO\xPDO; + +/** + * Minimal PSR-3 logger that preserves the legacy xPDO line format. + * + * Context interpolation replaces {placeholders} using stringified values: + * scalars are cast, DateTimeInterface uses DATE_ATOM, and arrays/objects + * fall back to print_r(). + */ +class xPDOLogger extends AbstractLogger +{ + /** + * @var xPDO + */ + protected $xpdo; + /** + * @var string|array|null + */ + protected $target = null; + /** + * @var array + */ + protected $targetOptions = array(); + + public function __construct(xPDO $xpdo, array $options = array()) + { + $this->xpdo = $xpdo; + if (array_key_exists('target', $options)) { + $this->target = $options['target']; + } + if (array_key_exists('target_options', $options) && is_array($options['target_options'])) { + $this->targetOptions = $options['target_options']; + } + } + + /** + * Logs with an arbitrary level. + * + * @param int|string $level + * @param mixed $message + * @param array $context + * @return void + */ + public function log($level, $message, array $context = array()): void + { + $isLegacy = !empty($context['xpdo_legacy']); + if ($isLegacy) { + unset($context['xpdo_legacy']); + $legacyLevel = is_int($level) ? $level : intval($level); + } else { + $legacyLevel = $this->mapPsrLevel($level); + } + if (!$this->shouldLog($legacyLevel)) { + return; + } + + $def = isset($context['def']) ? $context['def'] : ''; + $file = isset($context['file']) ? $context['file'] : ''; + $line = isset($context['line']) ? $context['line'] : ''; + list($file, $line) = $this->resolveLogLocation($file, $line); + + $target = $this->resolveTarget($context); + $targetOptions = $this->targetOptions; + if (is_array($target)) { + $targetOptions = array(); + if (isset($target['options'])) { + $targetOptions = &$target['options']; + } + $target = isset($target['target']) ? $target['target'] : 'ECHO'; + } + + $levelText = $this->getLegacyLevelLabel($legacyLevel); + $defText = !empty($def) ? " in {$def}" : ''; + $fileText = !empty($file) ? " @ {$file}" : ''; + $lineText = !empty($line) ? " : {$line}" : ''; + + $messageText = $isLegacy ? $message : $this->formatMessage($message, $context); + + if ($target === 'HTML') { + $content = '
' . $messageText . '' . "\n"; + } else { + $content = '[' . date('Y-m-d H:i:s') . '] (' . $levelText . $defText . $fileText . $lineText . ') ' . $messageText . "\n"; + } + + if ($this->writeToTarget($target, $targetOptions, $content, $levelText, $messageText, $defText, $fileText, $lineText)) { + return; + } + + echo $content; + } + + protected function shouldLog($legacyLevel): bool + { + if ($this->xpdo->getDebug() === true) { + return true; + } + if ($legacyLevel === xPDO::LOG_LEVEL_FATAL) { + return true; + } + return $legacyLevel <= $this->xpdo->getLogLevel(); + } + + protected function resolveTarget(array $context) + { + if (array_key_exists('target', $context)) { + return $context['target']; + } + if ($this->target !== null) { + return $this->target; + } + return $this->xpdo->getLogTarget(); + } + + protected function writeToTarget($target, & $targetOptions, $content, $levelText, $messageText, $defText, $fileText, $lineText): bool + { + if ($target === 'FILE' && $this->xpdo->getCacheManager()) { + $filename = isset($targetOptions['filename']) ? $targetOptions['filename'] : 'error.log'; + $filepath = isset($targetOptions['filepath']) ? $targetOptions['filepath'] : $this->xpdo->getCachePath() . xPDOCacheManager::LOG_DIR; + $this->xpdo->cacheManager->writeFile($filepath . $filename, $content, 'a'); + return true; + } + + if ( + $target === 'ARRAY' && + isset($targetOptions['var']) && + (is_array($targetOptions['var']) || $targetOptions['var'] instanceof \ArrayAccess) + ) { + $targetOptions['var'][] = $content; + return true; + } + + if ( + $target === 'ARRAY_EXTENDED' && + isset($targetOptions['var']) && + (is_array($targetOptions['var']) || $targetOptions['var'] instanceof \ArrayAccess) + ) { + $targetOptions['var'][] = array( + 'content' => $content, + 'level' => $levelText, + 'msg' => $messageText, + 'def' => $defText, + 'file' => $fileText, + 'line' => $lineText, + ); + return true; + } + + return false; + } + + protected function formatMessage($message, array $context): string + { + $messageText = $this->stringifyValue($message); + if (strpos($messageText, '{') === false) { + return $messageText; + } + + $replace = array(); + foreach ($context as $key => $value) { + $replace['{' . $key . '}'] = $this->stringifyValue($value); + } + + return strtr($messageText, $replace); + } + + protected function stringifyValue($value): string + { + if (is_string($value)) { + return $value; + } + if (is_null($value)) { + return 'null'; + } + if (is_bool($value)) { + return $value ? 'true' : 'false'; + } + if (is_int($value) || is_float($value)) { + return (string) $value; + } + if ($value instanceof \DateTimeInterface) { + return $value->format(DATE_ATOM); + } + if (is_object($value) && method_exists($value, '__toString')) { + return (string) $value; + } + return print_r($value, true); + } + + protected function resolveLogLocation($file, $line): array + { + if (empty($file)) { + if (version_compare(phpversion(), '5.4.0', '>=')) { + $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 3); + } elseif (version_compare(phpversion(), '5.3.6', '>=')) { + $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); + } else { + $backtrace = debug_backtrace(); + } + if ($backtrace && isset($backtrace[2])) { + $file = $backtrace[2]['file']; + $line = $backtrace[2]['line']; + } + } + if (empty($file) && isset($_SERVER['SCRIPT_NAME'])) { + $file = $_SERVER['SCRIPT_NAME']; + } + return array($file, $line); + } + + protected function mapPsrLevel($level): int + { + $level = strtolower((string) $level); + switch ($level) { + case LogLevel::DEBUG: + return xPDO::LOG_LEVEL_DEBUG; + case LogLevel::INFO: + return xPDO::LOG_LEVEL_INFO; + case LogLevel::NOTICE: + return xPDO::LOG_LEVEL_INFO; + case LogLevel::WARNING: + return xPDO::LOG_LEVEL_WARN; + case LogLevel::ERROR: + return xPDO::LOG_LEVEL_ERROR; + case LogLevel::CRITICAL: + case LogLevel::ALERT: + case LogLevel::EMERGENCY: + return xPDO::LOG_LEVEL_FATAL; + default: + return xPDO::LOG_LEVEL_INFO; + } + } + + protected function getLegacyLevelLabel($legacyLevel): string + { + switch ($legacyLevel) { + case xPDO::LOG_LEVEL_DEBUG: + return 'DEBUG'; + case xPDO::LOG_LEVEL_INFO: + return 'INFO'; + case xPDO::LOG_LEVEL_WARN: + return 'WARN'; + case xPDO::LOG_LEVEL_ERROR: + return 'ERROR'; + default: + return 'FATAL'; + } + } +} diff --git a/src/xPDO/xPDO.php b/src/xPDO/xPDO.php index 6a81c25..f99029c 100644 --- a/src/xPDO/xPDO.php +++ b/src/xPDO/xPDO.php @@ -20,6 +20,9 @@ use Composer\Autoload\ClassLoader; use Psr\Container\ContainerInterface; +use Psr\Log\LoggerInterface; +use Psr\Log\LogLevel; +use xPDO\Logging\xPDOLogger; use xPDO\Om\xPDOCriteria; use xPDO\Om\xPDOQuery; @@ -155,6 +158,10 @@ class xPDO { * classes for this xPDO instance. */ public $services= null; + /** + * @var LoggerInterface|null A PSR-3 logger instance for this xPDO instance. + */ + public $logger= null; /** * @var float Start time of the request, initialized when the constructor is * called. @@ -278,6 +285,7 @@ public function __construct($dsn, $username= '', $password= '', $options= array( if ($this->services === null) { $this->services = new xPDOContainer(); } + $this->initLogger(); $this->setLogLevel($this->getOption('log_level', null, xPDO::LOG_LEVEL_FATAL, true)); $this->setLogTarget($this->getOption('log_target', null, php_sapi_name() === 'cli' ? 'ECHO' : 'HTML', true)); if (!empty($dsn)) { @@ -359,6 +367,101 @@ protected function initConfig($data) { return $data; } + /** + * Initialize a PSR-3 logger from constructor options, if provided. + * + * @return void + */ + protected function initLogger() { + $logger = null; + + if ($this->services instanceof ContainerInterface) { + if ($this->services->has(LoggerInterface::class)) { + $logger = $this->services->get(LoggerInterface::class); + } elseif ($this->services->has('logger')) { + $logger = $this->services->get('logger'); + } + } + + if ($logger === null && is_array($this->config)) { + if (array_key_exists(LoggerInterface::class, $this->config)) { + $logger = $this->config[LoggerInterface::class]; + } elseif (isset($this->config['logger'])) { + $logger = $this->config['logger']; + } + } + + if ($logger instanceof LoggerInterface) { + $this->logger = $logger; + } + + if ($this->logger === null) { + $this->logger = new xPDOLogger($this); + } + + $this->registerLoggerService($this->logger); + } + + /** + * Register a logger in the services container (when supported). + * + * @param LoggerInterface $logger + * @param bool $overwrite + * @return void + */ + protected function registerLoggerService(LoggerInterface $logger, $overwrite = false) + { + if (!$this->services instanceof ContainerInterface) { + return; + } + + if (method_exists($this->services, 'add')) { + if ($overwrite || !$this->services->has(LoggerInterface::class)) { + $this->services->add(LoggerInterface::class, $logger); + } + if ($overwrite || !$this->services->has('logger')) { + $this->services->add('logger', $logger); + } + return; + } + + if ($this->services instanceof \ArrayAccess) { + if ($overwrite || !$this->services->has(LoggerInterface::class)) { + $this->services[LoggerInterface::class] = $logger; + } + if ($overwrite || !$this->services->has('logger')) { + $this->services['logger'] = $logger; + } + } + } + + /** + * Get the active PSR-3 logger for this xPDO instance. + * + * @return LoggerInterface + */ + public function getLogger(): LoggerInterface + { + if (!$this->logger instanceof LoggerInterface) { + $this->logger = new xPDOLogger($this); + $this->registerLoggerService($this->logger, true); + } + + return $this->logger; + } + + /** + * Set the active PSR-3 logger for this xPDO instance. + * + * @param LoggerInterface $logger + * @return void + */ + public function setLogger(LoggerInterface $logger): void + { + $this->logger = $logger; + $this->registerLoggerService($this->logger, true); + } + /** * Add an xPDOConnection instance to the xPDO connection pool. * @@ -2047,6 +2150,32 @@ protected function _log($level, $msg, $target= '', $def= '', $file= '', $line= ' if ($level !== xPDO::LOG_LEVEL_FATAL && $level > $this->logLevel && $this->_debug !== true) { return; } + list($file, $line) = $this->resolveLogLocation($file, $line); + if ($this->logger instanceof xPDOLogger) { + if ($level === xPDO::LOG_LEVEL_FATAL) { + while (ob_get_level() && @ob_end_flush()) {} + exit ('[' . date('Y-m-d H:i:s') . '] (' . $this->_getLogLevel($level) . $def . $file . $line . ') ' . $msg . "\n" . ($this->getDebug() === true ? '
' . "\n" . print_r(debug_backtrace(), true) . "\n" . '' : '')); + } + $context = array( + 'def' => $def, + 'file' => $file, + 'line' => $line, + 'xpdo_legacy' => true, + ); + if (!empty($target)) { + $context['target'] = $target; + } + $this->logger->log($level, $msg, $context); + return; + } + if ($this->logger instanceof LoggerInterface) { + $this->logToPsr($level, $msg, $def, $file, $line); + if ($level === xPDO::LOG_LEVEL_FATAL) { + while (ob_get_level() && @ob_end_flush()) {} + exit ('[' . date('Y-m-d H:i:s') . '] (' . $this->_getLogLevel($level) . $def . $file . $line . ') ' . $msg . "\n" . ($this->getDebug() === true ? '
' . "\n" . print_r(debug_backtrace(), true) . "\n" . '' : '')); + } + return; + } if (empty ($target)) { $target = $this->logTarget; } @@ -2055,22 +2184,6 @@ protected function _log($level, $msg, $target= '', $def= '', $file= '', $line= ' if (isset($target['options'])) $targetOptions =& $target['options']; $target = isset($target['target']) ? $target['target'] : 'ECHO'; } - if (empty($file)) { - if (version_compare(phpversion(), '5.4.0', '>=')) { - $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 3); - } elseif (version_compare(phpversion(), '5.3.6', '>=')) { - $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); - } else { - $backtrace = debug_backtrace(); - } - if ($backtrace && isset($backtrace[2])) { - $file = $backtrace[2]['file']; - $line = $backtrace[2]['line']; - } - } - if (empty($file) && isset($_SERVER['SCRIPT_NAME'])) { - $file = $_SERVER['SCRIPT_NAME']; - } if ($level === xPDO::LOG_LEVEL_FATAL) { while (ob_get_level() && @ob_end_flush()) {} exit ('[' . date('Y-m-d H:i:s') . '] (' . $this->_getLogLevel($level) . $def . $file . $line . ') ' . $msg . "\n" . ($this->getDebug() === true ? '
' . "\n" . print_r(debug_backtrace(), true) . "\n" . '' : '')); @@ -2124,6 +2237,93 @@ protected function _log($level, $msg, $target= '', $def= '', $file= '', $line= ' } } + /** + * Resolve the log file and line for a log entry. + * + * @param string $file + * @param string $line + * @return array + */ + protected function resolveLogLocation($file, $line) { + if (empty($file)) { + if (version_compare(phpversion(), '5.4.0', '>=')) { + $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 3); + } elseif (version_compare(phpversion(), '5.3.6', '>=')) { + $backtrace = debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS); + } else { + $backtrace = debug_backtrace(); + } + if ($backtrace && isset($backtrace[2])) { + $file = $backtrace[2]['file']; + $line = $backtrace[2]['line']; + } + } + if (empty($file) && isset($_SERVER['SCRIPT_NAME'])) { + $file = $_SERVER['SCRIPT_NAME']; + } + return array($file, $line); + } + + /** + * Send a log entry to a PSR-3 logger. + * + * @param integer $level + * @param mixed $msg + * @param string $def + * @param string $file + * @param string $line + * @return void + */ + protected function logToPsr($level, $msg, $def, $file, $line) { + $message = $this->normalizePsrMessage($msg); + $context = array( + 'def' => $def, + 'file' => $file, + 'line' => $line, + 'xpdo_level' => $level, + ); + $this->logger->log($this->getPsrLogLevel($level), $message, $context); + } + + /** + * Normalize a log message for PSR-3 loggers. + * + * @param mixed $msg + * @return string + */ + protected function normalizePsrMessage($msg) { + if (is_string($msg)) { + return $msg; + } + if (is_object($msg) && method_exists($msg, '__toString')) { + return (string) $msg; + } + return print_r($msg, true); + } + + /** + * Map an xPDO log level to a PSR-3 log level. + * + * @param integer $level + * @return string + */ + protected function getPsrLogLevel($level) { + switch ($level) { + case xPDO::LOG_LEVEL_DEBUG: + return LogLevel::DEBUG; + case xPDO::LOG_LEVEL_INFO: + return LogLevel::INFO; + case xPDO::LOG_LEVEL_WARN: + return LogLevel::WARNING; + case xPDO::LOG_LEVEL_ERROR: + return LogLevel::ERROR; + case xPDO::LOG_LEVEL_FATAL: + return LogLevel::CRITICAL; + default: + return LogLevel::NOTICE; + } + } + /** * Returns an abbreviated backtrace of debugging information. * diff --git a/test/complete.phpunit.xml b/test/complete.phpunit.xml index 1531af4..2514653 100644 --- a/test/complete.phpunit.xml +++ b/test/complete.phpunit.xml @@ -18,6 +18,9 @@
Html message<\\/pre>\\n$/';
+ $this->assertMatchesRegularExpression($htmlPattern, $htmlOutput);
+ }
+
+ public function testMonologLoggerReceivesMessages()
+ {
+ if (!class_exists(Logger::class) || !class_exists(TestHandler::class)) {
+ $this->markTestSkipped('Monolog is not installed.');
+ }
+
+ $handler = new TestHandler();
+ $logger = new Logger('xpdo');
+ $logger->pushHandler($handler);
+
+ $this->xpdo->logger = $logger;
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $output = array();
+ $target = array(
+ 'target' => 'ARRAY',
+ 'options' => array(
+ 'var' => &$output,
+ ),
+ );
+
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, 'Monolog works', $target, 'UnitTest', __FILE__, 678);
+
+ $this->assertCount(0, $output);
+ if (method_exists($handler, 'getRecords')) {
+ $records = $handler->getRecords();
+ } else {
+ $ref = new \ReflectionProperty($handler, 'records');
+ $ref->setAccessible(true);
+ $records = $ref->getValue($handler);
+ }
+ $this->assertNotEmpty($records);
+ $record = $records[0];
+ $message = is_array($record) ? $record['message'] : $record->message;
+ $this->assertSame('Monolog works', $message);
+ }
+}
+
+class SpyLogger extends AbstractLogger
+{
+ public $records = array();
+
+ public function log($level, $message, array $context = array()): void
+ {
+ $this->records[] = array(
+ 'level' => $level,
+ 'message' => $message,
+ 'context' => $context,
+ );
+ }
+}
diff --git a/test/xPDO/Test/Logging/xPDOLoggingFatalTest.php b/test/xPDO/Test/Logging/xPDOLoggingFatalTest.php
new file mode 100644
index 0000000..887d620
--- /dev/null
+++ b/test/xPDO/Test/Logging/xPDOLoggingFatalTest.php
@@ -0,0 +1,134 @@
+markTestSkipped('proc_open is required to run fatal log subprocess.');
+ }
+
+ $msg = 'fatal log message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ $result = $this->runFatalLogSubprocess((bool)$debug, $msg, $def, $file, $line);
+ $stdout = $result['stdout'];
+
+ $this->assertSame(0, $result['exitCode'], 'Fatal log subprocess should exit with status 0.');
+ $this->assertSame('', $result['stderr'], 'Fatal log subprocess should not write to STDERR.');
+
+ if ($expectBacktrace) {
+ $pattern = '/\\A\\['
+ . '\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}'
+ . '\\] \\('
+ . preg_quote('FATAL' . $def . $file . $line, '/')
+ . '\\) '
+ . preg_quote($msg, '/')
+ . "\\r?\\n\\r?\\n/s";
+
+ $this->assertMatchesRegularExpression($pattern, $stdout);
+ $this->assertMatchesRegularExpression('/\\r?\\nArray\\r?\\n\\(/', $stdout);
+ $this->assertStringContainsString('', $stdout);
+ } else {
+ $pattern = '/\\A\\['
+ . '\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}'
+ . '\\] \\('
+ . preg_quote('FATAL' . $def . $file . $line, '/')
+ . '\\) '
+ . preg_quote($msg, '/')
+ . "\\r?\\n\\z/";
+
+ $this->assertMatchesRegularExpression($pattern, $stdout);
+ }
+ }
+
+ public function providerFatalLogOutputs()
+ {
+ return array(
+ 'debug off' => array(false, false),
+ 'debug on' => array(true, true),
+ );
+ }
+
+ private function runFatalLogSubprocess($debug, $msg, $def, $file, $line)
+ {
+ $projectRoot = dirname(__DIR__, 4);
+ $bootstrapPath = $projectRoot . '/src/bootstrap.php';
+ $propertiesPath = $projectRoot . '/test/properties.inc.php';
+ $scriptPath = tempnam(sys_get_temp_dir(), 'xpdo-fatal-');
+
+ if ($scriptPath === false) {
+ $this->fail('Unable to create temporary script for fatal log test.');
+ }
+
+ $script = sprintf(
+ "setDebug(%s);\n" .
+ "\$xpdo->log(\\xPDO\\xPDO::LOG_LEVEL_FATAL, %s, 'ECHO', %s, %s, %s);\n",
+ var_export($bootstrapPath, true),
+ var_export($propertiesPath, true),
+ var_export((bool)$debug, true),
+ var_export($msg, true),
+ var_export($def, true),
+ var_export($file, true),
+ var_export($line, true)
+ );
+
+ try {
+ if (file_put_contents($scriptPath, $script) === false) {
+ $this->fail('Unable to write temporary script for fatal log test.');
+ }
+
+ $driver = getenv('TEST_DRIVER') ?: 'sqlite';
+ putenv("TEST_DRIVER={$driver}");
+
+ $command = escapeshellarg(PHP_BINARY) . ' ' . escapeshellarg($scriptPath);
+ $descriptorSpec = array(
+ 1 => array('pipe', 'w'),
+ 2 => array('pipe', 'w'),
+ );
+
+ $process = proc_open($command, $descriptorSpec, $pipes, $projectRoot);
+ if (!is_resource($process)) {
+ $this->fail('Unable to start fatal log subprocess.');
+ }
+
+ $stdout = stream_get_contents($pipes[1]);
+ fclose($pipes[1]);
+ $stderr = stream_get_contents($pipes[2]);
+ fclose($pipes[2]);
+ $exitCode = proc_close($process);
+ } finally {
+ if (is_string($scriptPath) && file_exists($scriptPath)) {
+ @unlink($scriptPath);
+ }
+ }
+
+ return array(
+ 'exitCode' => $exitCode,
+ 'stdout' => $stdout,
+ 'stderr' => $stderr,
+ );
+ }
+}
diff --git a/test/xPDO/Test/Logging/xPDOLoggingHistoricTest.php b/test/xPDO/Test/Logging/xPDOLoggingHistoricTest.php
new file mode 100644
index 0000000..6ea19db
--- /dev/null
+++ b/test/xPDO/Test/Logging/xPDOLoggingHistoricTest.php
@@ -0,0 +1,495 @@
+cacheManagerSpy = new xPDOLoggingHistoricTestCacheManager($this->xpdo);
+ $this->xpdo->cacheManager = $this->cacheManagerSpy;
+ }
+
+ /**
+ * @after
+ */
+ public function tearDownCacheManagerSpy()
+ {
+ $this->cacheManagerSpy = null;
+ }
+
+ private function assertPlainLogLineMatches($output, $levelText, $msg, $def = '', $file = '', $line = '')
+ {
+ $defPart = ($def !== '') ? " in {$def}" : '';
+ $filePart = ($file !== '') ? " @ {$file}" : '';
+ $linePart = ($line !== '') ? " : {$line}" : '';
+
+ $pattern = '/\\A\\['
+ . '\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}'
+ . '\\] \\('
+ . preg_quote($levelText . $defPart . $filePart . $linePart, '/')
+ . '\\) '
+ . preg_quote($msg, '/')
+ . "\\n\\z/";
+
+ $this->assertMatchesRegularExpression($pattern, $output);
+ }
+
+ private function assertHtmlLogLineMatches($output, $levelText, $msg, $def = '', $file = '', $line = '')
+ {
+ $defPart = ($def !== '') ? " in {$def}" : '';
+ $filePart = ($file !== '') ? " @ {$file}" : '';
+ $linePart = ($line !== '') ? " : {$line}" : '';
+
+ $pattern = '/\\A\\['
+ . '\\d{4}-\\d{2}-\\d{2} \\d{2}:\\d{2}:\\d{2}'
+ . '\\] \\('
+ . preg_quote($levelText . $defPart . $filePart . $linePart, '/')
+ . '\\)<\\/h5>'
+ . preg_quote($msg, '/')
+ . '<\\/pre>'
+ . "\\n\\z/";
+
+ $this->assertMatchesRegularExpression($pattern, $output);
+ }
+
+ private function captureLogOutput($level, $msg, $target, $def, $file, $line)
+ {
+ ob_start();
+ $this->xpdo->log($level, $msg, $target, $def, $file, $line);
+ return ob_get_clean();
+ }
+
+ public function testLogEchoWritesOnlyStdout()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'ECHO',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'echo-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, 'INFO', $msg, $def, $file, $line);
+ $this->assertSame([], $sink, 'ECHO target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ECHO target must not write to FILE.');
+ }
+
+ public function testLogHtmlWritesOnlyStdout()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'HTML',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'html-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertHtmlLogLineMatches($output, 'INFO', $msg, $def, $file, $line);
+ $this->assertSame([], $sink, 'HTML target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'HTML target must not write to FILE.');
+ }
+
+ public function testLogUnknownTargetDefaultsToPlainStdout()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'UNKNOWN',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'unknown-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, 'INFO', $msg, $def, $file, $line);
+ $this->assertSame([], $sink, 'Unknown target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'Unknown target must not write to FILE.');
+ }
+
+ public function testLogFileWritesOnlyFileWithDefaults()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'FILE',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'file-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertSame('', $output, 'FILE target must not write to STDOUT.');
+ $this->assertSame([], $sink, 'FILE target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+
+ $this->assertCount(1, $this->cacheManagerSpy->writeCalls);
+ $call = $this->cacheManagerSpy->writeCalls[0];
+
+ $expectedFilename = $this->xpdo->getCachePath() . xPDOCacheManager::LOG_DIR . 'error.log';
+ $this->assertSame($expectedFilename, $call['filename']);
+ $this->assertSame('a', $call['mode']);
+ $this->assertSame([], $call['options']);
+ $this->assertPlainLogLineMatches($call['content'], 'INFO', $msg, $def, $file, $line);
+ }
+
+ public function testLogFileWritesOnlyFileWithCustomOptions()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'FILE',
+ 'options' => array(
+ 'filename' => 'custom.log',
+ 'filepath' => '/custom/path/',
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'file-target custom options message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertSame('', $output, 'FILE target must not write to STDOUT.');
+ $this->assertSame([], $sink, 'FILE target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+
+ $this->assertCount(1, $this->cacheManagerSpy->writeCalls);
+ $call = $this->cacheManagerSpy->writeCalls[0];
+
+ $this->assertSame('/custom/path/custom.log', $call['filename']);
+ $this->assertSame('a', $call['mode']);
+ $this->assertSame([], $call['options']);
+ $this->assertPlainLogLineMatches($call['content'], 'INFO', $msg, $def, $file, $line);
+ }
+
+ public function testLogArrayAppendsOnlyToArraySink()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'ARRAY',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'array-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_WARN, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertSame('', $output, 'ARRAY target must not write to STDOUT.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ARRAY target must not write to FILE.');
+
+ $this->assertCount(1, $sink);
+ $this->assertIsString($sink[0]);
+ $this->assertPlainLogLineMatches($sink[0], 'WARN', $msg, $def, $file, $line);
+ }
+
+ public function testLogArrayWithoutVarFallsBackToStdout()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $target = array(
+ 'target' => 'ARRAY',
+ 'options' => array(),
+ );
+
+ $msg = 'array-target no var message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, 'INFO', $msg, $def, $file, $line);
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ARRAY target with invalid options must not write to FILE.');
+ }
+
+ public function testLogArrayExtendedAppendsOnlyToArraySinkWithStructuredData()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'ARRAY_EXTENDED',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'array-extended-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_ERROR, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertSame('', $output, 'ARRAY_EXTENDED target must not write to STDOUT.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ARRAY_EXTENDED target must not write to FILE.');
+
+ $this->assertCount(1, $sink);
+ $this->assertIsArray($sink[0]);
+ $this->assertSame(
+ array('content', 'level', 'msg', 'def', 'file', 'line'),
+ array_keys($sink[0])
+ );
+
+ $this->assertPlainLogLineMatches($sink[0]['content'], 'ERROR', $msg, $def, $file, $line);
+ $this->assertSame('ERROR', $sink[0]['level']);
+ $this->assertSame($msg, $sink[0]['msg']);
+ $this->assertSame(" in {$def}", $sink[0]['def']);
+ $this->assertSame(" @ {$file}", $sink[0]['file']);
+ $this->assertSame(" : {$line}", $sink[0]['line']);
+ }
+
+ public function testLogArrayExtendedWithoutVarFallsBackToStdout()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $target = array(
+ 'target' => 'ARRAY_EXTENDED',
+ 'options' => array(),
+ );
+
+ $msg = 'array-extended-target no var message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, $target, $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, 'INFO', $msg, $def, $file, $line);
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ARRAY_EXTENDED target with invalid options must not write to FILE.');
+ }
+
+ public function testLogUsesInstanceLogTargetWhenTargetParamEmpty()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $sink = [];
+ $this->xpdo->setLogTarget(array(
+ 'target' => 'ARRAY',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ ));
+
+ $msg = 'instance-target message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, '', $def, $file, $line);
+ $output = ob_get_clean();
+
+ $this->assertSame('', $output, 'Instance ARRAY target must not write to STDOUT.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'Instance ARRAY target must not write to FILE.');
+ $this->assertCount(1, $sink);
+ $this->assertPlainLogLineMatches($sink[0], 'INFO', $msg, $def, $file, $line);
+ }
+
+ /**
+ * @dataProvider providerDebugAndLogLevelFiltering
+ */
+ public function testLogRespectsDebugAndLogLevel($debug, $logLevel, $level, $shouldLog, $expectedLevelText)
+ {
+ $this->xpdo->setDebug($debug);
+ $this->xpdo->setLogLevel($logLevel);
+
+ $sink = [];
+ $target = array(
+ 'target' => 'ECHO',
+ 'options' => array(
+ 'var' => &$sink,
+ ),
+ );
+
+ $msg = 'log filtering message';
+ $def = 'DefiningStruct';
+ $file = 'example.php';
+ $line = '123';
+
+ $output = $this->captureLogOutput($level, $msg, $target, $def, $file, $line);
+
+ if ($shouldLog) {
+ $this->assertPlainLogLineMatches($output, $expectedLevelText, $msg, $def, $file, $line);
+ } else {
+ $this->assertSame('', $output, 'Filtered message must not write to STDOUT.');
+ }
+
+ $this->assertSame([], $sink, 'ECHO target must not append to ARRAY/ARRAY_EXTENDED sinks.');
+ $this->assertSame([], $this->cacheManagerSpy->writeCalls, 'ECHO target must not write to FILE.');
+ }
+
+ public function providerDebugAndLogLevelFiltering()
+ {
+ return array(
+ 'debug overrides log level' => array(true, xPDO::LOG_LEVEL_WARN, xPDO::LOG_LEVEL_DEBUG, true, 'DEBUG'),
+ 'level at log level' => array(false, xPDO::LOG_LEVEL_WARN, xPDO::LOG_LEVEL_WARN, true, 'WARN'),
+ 'level above log level' => array(false, xPDO::LOG_LEVEL_WARN, xPDO::LOG_LEVEL_DEBUG, false, 'DEBUG'),
+ );
+ }
+
+ /**
+ * Verify backtrace file/line resolution when file/line params are omitted.
+ */
+ public function testLogResolvesFileAndLineFromBacktraceWhenNotProvided()
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $msg = 'backtrace resolution message';
+ $def = 'DefiningStruct';
+
+ $line = __LINE__ + 2;
+ ob_start();
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, 'ECHO', $def);
+ //$this->getLog($msg, $def);
+ // Modern tests need this
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, 'INFO', $msg, $def, __FILE__, (string)$line);
+ }
+
+ /**
+ * Verify _getLogLevel mapping via _log output.
+ *
+ * @dataProvider providerLogLevels
+ */
+ public function testLogLevelTextMapping($level, $expectedText)
+ {
+ $this->xpdo->setDebug(false);
+ $this->xpdo->setLogLevel(xPDO::LOG_LEVEL_DEBUG);
+
+ $msg = 'level-mapping message';
+
+ ob_start();
+ $this->xpdo->log($level, $msg, 'ECHO', 'DefiningStruct', 'example.php', '123');
+ $output = ob_get_clean();
+
+ $this->assertPlainLogLineMatches($output, $expectedText, $msg, 'DefiningStruct', 'example.php', '123');
+ }
+
+ public function providerLogLevels()
+ {
+ return array(
+ array(xPDO::LOG_LEVEL_DEBUG, 'DEBUG'),
+ array(xPDO::LOG_LEVEL_INFO, 'INFO'),
+ array(xPDO::LOG_LEVEL_WARN, 'WARN'),
+ array(xPDO::LOG_LEVEL_ERROR, 'ERROR'),
+ );
+ }
+
+ /**
+ * @param string $msg
+ * @param string $def
+ * @return void
+ */
+ private function getLog(string $msg, string $def): void
+ {
+ $this->xpdo->log(xPDO::LOG_LEVEL_INFO, $msg, 'ECHO', $def);
+ }
+}
+
+class xPDOLoggingHistoricTestCacheManager extends xPDOCacheManager
+{
+ /** @var array */
+ public $writeCalls = [];
+
+ public function writeFile($filename, $content, $mode = 'wb', $options = array())
+ {
+ $this->writeCalls[] = array(
+ 'filename' => $filename,
+ 'content' => $content,
+ 'mode' => $mode,
+ 'options' => $options,
+ );
+
+ return true;
+ }
+}