Unverified Commit 0e5821b2 authored by Armando Lüscher's avatar Armando Lüscher Committed by GitHub

Merge pull request #964 from noplanman/psr3-logger

Use PSR-3 LoggerInterface to allow custom logging implementations.
parents c8329d63 377173e8
......@@ -11,7 +11,9 @@ Exclamation symbols (:exclamation:) note something of importance e.g. breaking c
- Use PSR-12 for code style.
- Some general housekeeping. (#972)
- [:exclamation:][unreleased-bc] Return an empty array for Entity properties with no items, instead of `null`. (#969)
- `TelegramLog` now adheres to [PSR-3] `LoggerInterface` and allows custom logger implementations.
### Deprecated
- Old logging that uses Monolog still works but will be removed in the near future. Use `TelegramLog::initialize($logger, $update_logger);` from now on.
### Removed
- Botan.io integration completely removed.
### Fixed
......@@ -290,6 +292,7 @@ Exclamation symbols (:exclamation:) note something of importance e.g. breaking c
[0.45.0-bc-up-download-directory]: https://github.com/php-telegram-bot/core/wiki/Breaking-backwards-compatibility#up-download-directory
[0.44.0-bc-update-content-type]: https://github.com/php-telegram-bot/core/wiki/Breaking-backwards-compatibility#update-getupdatecontent
[example-bot]: https://github.com/php-telegram-bot/example-bot
[PSR-3]: https://www.php-fig.org/psr/psr-3
[Unreleased]: https://github.com/php-telegram-bot/core/compare/master...develop
[0.57.0]: https://github.com/php-telegram-bot/core/compare/0.56.0...0.57.0
......
......@@ -28,6 +28,7 @@
"ext-curl": "*",
"ext-json": "*",
"ext-mbstring": "*",
"psr/log": "^1.1",
"monolog/monolog": "^1.24",
"guzzlehttp/guzzle": "^6.3"
},
......
......@@ -4,7 +4,7 @@
"Read more about it at https://getcomposer.org/doc/01-basic-usage.md#installing-dependencies",
"This file is @generated automatically"
],
"content-hash": "b3ac8abe31dc69491d76f5b4bb65ca26",
"content-hash": "07b4a4919442371656638370b1b75f85",
"packages": [
{
"name": "guzzlehttp/guzzle",
......
## Logging
PHP Telegram Bot library features [Monolog](https://github.com/Seldaek/monolog) to store logs.
PHP Telegram Bot library features [PSR-3] compatible logging to store logs.
You can find a list of compatible packages that can be used on [Packagist][PSR-3-providers].
Logs are divided into the following streams:
### Error
Collects all the exceptions thrown by the library:
```php
TelegramLog::initErrorLog($path . '/' . $BOT_NAME . '_error.log');
```
- `error`: Collects all the exceptions thrown by the library.
- `debug`: Stores requests made to the Telegram API, useful for debugging.
- `update`: Incoming raw updates (JSON string from Webhook and getUpdates).
### Initialisation
To initialise the logger, you can pass any `LoggerInterface` objects to the `TelegramLog::initialize` method.
The first parameter is the main logger, the second one is used for the raw updates.
### Debug
Stores requests made to the Telegram API, useful for debugging:
(in this example we're using [Monolog])
```php
TelegramLog::initDebugLog($path . '/' . $BOT_NAME . '_debug.log');
use Monolog\Formatter\LineFormatter;
use Monolog\Handler\StreamHandler;
use Monolog\Logger;
use Longman\TelegramBot\TelegramLog;
TelegramLog::initialize(
// Main logger that handles all 'error' and 'debug' logs.
new Logger('telegram_bot', [
(new StreamHandler(__DIR__ . "/logs/{$bot_username}_debug.log", Logger::DEBUG))->setFormatter(new LineFormatter(null, null, true)),
(new StreamHandler(__DIR__ . "/logs/{$bot_username}_error.log", Logger::ERROR))->setFormatter(new LineFormatter(null, null, true)),
]),
// Updates logger for raw updates.
new Logger('telegram_bot_updates', [
(new StreamHandler(__DIR__ . "/logs/{$bot_username}_update.log", Logger::INFO))->setFormatter(new LineFormatter('%message%' . PHP_EOL)),
])
);
```
### Raw data
Incoming updates (JSON string from Webhook and getUpdates) get logged in a text file:
```php
TelegramLog::initUpdateLog($path . '/' . $BOT_NAME . '_update.log');
```
Why do I need to log the raw updates?
Telegram API changes continuously and it often happens that the database schema is not up to date with new entities/features. So it can happen that your table schema doesn't allow storing new valuable information coming from Telegram.
If you store the raw data you can import all updates on the newest table schema by simply using [this script](../utils/importFromLog.php).
Remember to always backup first!!
## Stream and external sources
Error and Debug streams rely on the `bot_log` instance that can be provided from an external source:
```php
TelegramLog::initialize($monolog);
```
Raw data relies on the `bot_update_log` instance that uses a custom format.
[PSR-3]: https://www.php-fig.org/psr/psr-3
[PSR-3-providers]: https://packagist.org/providers/psr/log-implementation
[Monolog]: https://github.com/Seldaek/monolog
......@@ -538,7 +538,7 @@ class Telegram
public function enableAdmin($admin_id)
{
if (!is_int($admin_id) || $admin_id <= 0) {
TelegramLog::error('Invalid value "%s" for admin.', $admin_id);
TelegramLog::error('Invalid value "' . $admin_id . '" for admin.');
} elseif (!in_array($admin_id, $this->admins_list, true)) {
$this->admins_list[] = $admin_id;
}
......@@ -631,7 +631,7 @@ class Telegram
public function addCommandsPath($path, $before = true)
{
if (!is_dir($path)) {
TelegramLog::error('Commands path "%s" does not exist.', $path);
TelegramLog::error('Commands path "' . $path . '" does not exist.');
} elseif (!in_array($path, $this->commands_paths, true)) {
if ($before) {
array_unshift($this->commands_paths, $path);
......
......@@ -10,31 +10,50 @@
namespace Longman\TelegramBot;
use Exception;
use Longman\TelegramBot\Exception\TelegramLogException;
use Monolog\Formatter\LineFormatter;
use Monolog\Handler\StreamHandler;
use Monolog\Logger;
use Psr\Log\LoggerInterface;
use Psr\Log\NullLogger;
/**
* Class TelegramLog
*
* @todo Clean out all deprecated code in the near future!
*
* @method static void emergency(string $message, array $context = [])
* @method static void alert(string $message, array $context = [])
* @method static void critical(string $message, array $context = [])
* @method static void error(string $message, array $context = [])
* @method static void warning(string $message, array $context = [])
* @method static void notice(string $message, array $context = [])
* @method static void info(string $message, array $context = [])
* @method static void debug(string $message, array $context = [])
* @method static void update(string $message, array $context = [])
*/
class TelegramLog
{
/**
* Monolog instance
* Logger instance
*
* @var Logger
* @var LoggerInterface|Logger
*/
protected static $monolog;
protected static $logger;
/**
* Monolog instance for update
* Logger instance for update
*
* @var Logger
* @var LoggerInterface|Logger
*/
protected static $monolog_update;
protected static $update_logger;
/**
* Path for error log
*
* @var string
* @deprecated
*/
protected static $error_log_path;
......@@ -42,6 +61,7 @@ class TelegramLog
* Path for debug log
*
* @var string
* @deprecated
*/
protected static $debug_log_path;
......@@ -49,6 +69,7 @@ class TelegramLog
* Path for update log
*
* @var string
* @deprecated
*/
protected static $update_log_path;
......@@ -60,82 +81,128 @@ class TelegramLog
protected static $debug_log_temp_stream_handle;
/**
* Initialize Monolog Logger instance, optionally passing an existing one
*
* @param Logger
* Initialise Logger instance, optionally passing an existing one.
*
* @return Logger
* @param LoggerInterface|null $logger
* @param LoggerInterface|null $update_logger
*/
public static function initialize(Logger $external_monolog = null)
public static function initialize(LoggerInterface $logger = null, LoggerInterface $update_logger = null)
{
if (self::$monolog === null) {
if ($external_monolog !== null) {
self::$monolog = $external_monolog;
foreach (self::$monolog->getHandlers() as $handler) {
if (method_exists($handler, 'getLevel') && $handler->getLevel() === 400) {
// Clearly deprecated code still being executed.
if ($logger === null) {
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error('A PSR-3 compatible LoggerInterface object must be provided. Initialise with a preconfigured logger instance.', E_USER_DEPRECATED);
$logger = new Logger('bot_log');
} elseif ($logger instanceof Logger) {
foreach ($logger->getHandlers() as $handler) {
if (method_exists($handler, 'getLevel') && $handler->getLevel() === Logger::ERROR) {
self::$error_log_path = 'true';
}
if (method_exists($handler, 'getLevel') && $handler->getLevel() === 100) {
if (method_exists($handler, 'getLevel') && $handler->getLevel() === Logger::DEBUG) {
self::$debug_log_path = 'true';
}
}
} else {
self::$monolog = new Logger('bot_log');
}
}
return self::$monolog;
// Fallback to NullLogger.
self::$logger = $logger ?: new NullLogger();
self::$update_logger = $update_logger ?: new NullLogger();
}
/**
* Initialize error log
* Initialise error log (deprecated)
*
* @param string $path
*
* @return Logger
* @throws TelegramLogException
* @throws \InvalidArgumentException
* @throws \Exception
* @return LoggerInterface
* @throws Exception
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function initErrorLog($path)
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
if ($path === null || $path === '') {
throw new TelegramLogException('Empty path for error log');
}
self::initialize();
// Deprecated code used as fallback.
if (self::$logger instanceof Logger) {
self::$error_log_path = $path;
return self::$monolog->pushHandler(
self::$logger->pushHandler(
(new StreamHandler(self::$error_log_path, Logger::ERROR))
->setFormatter(new LineFormatter(null, null, true))
);
}
return self::$logger;
}
/**
* Initialize debug log
* Initialise debug log (deprecated)
*
* @param string $path
*
* @return Logger
* @throws TelegramLogException
* @throws \InvalidArgumentException
* @throws \Exception
* @return LoggerInterface
* @throws Exception
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function initDebugLog($path)
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
if ($path === null || $path === '') {
throw new TelegramLogException('Empty path for debug log');
}
self::initialize();
// Deprecated code used as fallback.
if (self::$logger instanceof Logger) {
self::$debug_log_path = $path;
return self::$monolog->pushHandler(
self::$logger->pushHandler(
(new StreamHandler(self::$debug_log_path, Logger::DEBUG))
->setFormatter(new LineFormatter(null, null, true))
);
}
return self::$logger;
}
/**
* Initialise update log (deprecated)
*
* @param string $path
*
* @return LoggerInterface
* @throws Exception
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function initUpdateLog($path)
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
if ($path === null || $path === '') {
throw new TelegramLogException('Empty path for update log');
}
self::$update_log_path = $path;
if (self::$update_logger === null || self::$update_logger instanceof NullLogger) {
self::$update_logger = new Logger('bot_update_log');
self::$update_logger->pushHandler(
(new StreamHandler(self::$update_log_path, Logger::INFO))
->setFormatter(new LineFormatter('%message%' . PHP_EOL))
);
}
return self::$update_logger;
}
/**
* Get the stream handle of the temporary debug output
*
......@@ -143,14 +210,9 @@ class TelegramLog
*/
public static function getDebugLogTempStream()
{
if (self::$debug_log_temp_stream_handle === null) {
if (!self::isDebugLogActive()) {
return false;
}
if ($temp_stream_handle = fopen('php://temp', 'wb+')) {
if ((self::$debug_log_temp_stream_handle === null) && $temp_stream_handle = fopen('php://temp', 'wb+')) {
self::$debug_log_temp_stream_handle = $temp_stream_handle;
}
}
return self::$debug_log_temp_stream_handle;
}
......@@ -164,48 +226,22 @@ class TelegramLog
{
if (is_resource(self::$debug_log_temp_stream_handle)) {
rewind(self::$debug_log_temp_stream_handle);
self::debug($message, stream_get_contents(self::$debug_log_temp_stream_handle));
self::debug(sprintf($message, stream_get_contents(self::$debug_log_temp_stream_handle)));
fclose(self::$debug_log_temp_stream_handle);
self::$debug_log_temp_stream_handle = null;
}
}
/**
* Initialize update log
*
* @param string $path
*
* @return Logger
* @throws TelegramLogException
* @throws \InvalidArgumentException
* @throws \Exception
*/
public static function initUpdateLog($path)
{
if ($path === null || $path === '') {
throw new TelegramLogException('Empty path for update log');
}
self::$update_log_path = $path;
if (self::$monolog_update === null) {
self::$monolog_update = new Logger('bot_update_log');
self::$monolog_update->pushHandler(
(new StreamHandler(self::$update_log_path, Logger::INFO))
->setFormatter(new LineFormatter('%message%' . PHP_EOL))
);
}
return self::$monolog_update;
}
/**
* Is error log active
*
* @return bool
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function isErrorLogActive()
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
return self::$error_log_path !== null;
}
......@@ -213,9 +249,12 @@ class TelegramLog
* Is debug log active
*
* @return bool
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function isDebugLogActive()
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
return self::$debug_log_path !== null;
}
......@@ -223,69 +262,71 @@ class TelegramLog
* Is update log active
*
* @return bool
*
* @deprecated Initialise a preconfigured logger instance instead.
*/
public static function isUpdateLogActive()
{
(defined('PHPUNIT_TESTSUITE') && PHPUNIT_TESTSUITE) || trigger_error(__METHOD__ . ' is deprecated and will be removed soon. Initialise with a preconfigured logger instance instead using "TelegramLog::initialize($logger)".', E_USER_DEPRECATED);
return self::$update_log_path !== null;
}
/**
* Report error log
* Handle any logging method call.
*
* @param string $text
* @param string $name
* @param array $arguments
*/
public static function error($text)
public static function __callStatic($name, array $arguments)
{
if (self::isErrorLogActive()) {
$text = self::getLogText($text, func_get_args());
self::$monolog->error($text);
}
// Get the correct logger instance.
$logger = null;
if (in_array($name, ['emergency', 'alert', 'critical', 'error', 'warning', 'notice', 'info', 'debug',], true)) {
$logger = self::$logger;
} elseif ($name === 'update') {
$logger = self::$update_logger;
$name = 'info';
} else {
return;
}
/**
* Report debug log
*
* @param string $text
*/
public static function debug($text)
{
if (self::isDebugLogActive()) {
$text = self::getLogText($text, func_get_args());
self::$monolog->debug($text);
self::initialize(self::$logger, self::$update_logger);
// Replace any placeholders from the passed context.
if (count($arguments) >= 2) {
if (is_array($arguments[1])) {
$arguments[0] = self::interpolate($arguments[0], $arguments[1]);
} else {
// @todo Old parameter passing active, should be removed in the near future.
$arguments[0] = vsprintf($arguments[0], array_splice($arguments, 1));
}
}
/**
* Report update log
*
* @param string $text
*/
public static function update($text)
{
if (self::isUpdateLogActive()) {
$text = self::getLogText($text, func_get_args());
self::$monolog_update->info($text);
}
call_user_func_array([$logger, $name], $arguments);
}
/**
* Applies vsprintf to the text if placeholder replacements are passed along.
* Interpolates context values into the message placeholders.
*
* @see https://www.php-fig.org/psr/psr-3/#12-message
*
* @param string $text
* @param array $args
* @param string $message
* @param array $context
*
* @return string
*/
protected static function getLogText($text, array $args = [])
protected static function interpolate($message, array $context = [])
{
// Pop the $text off the array, as it gets passed via func_get_args().
array_shift($args);
// If no placeholders have been passed, don't parse the text.
if (empty($args)) {
return $text;
// build a replacement array with braces around the context keys
$replace = [];
foreach ($context as $key => $val) {
// check that the value can be casted to string
if (!is_array($val) && (!is_object($val) || method_exists($val, '__toString'))) {
$replace['{' . $key . '}'] = $val;
}
}
return vsprintf($text, $args);
// interpolate replacement values into the message and return
return strtr($message, $replace);
}
}
......@@ -35,8 +35,9 @@ class TelegramLogTest extends TestCase
protected function setUp()
{
// Make sure no monolog instance is set before each test.
TestHelpers::setStaticProperty(TelegramLog::class, 'monolog', null);
// Make sure no logger instance is set before each test.
TestHelpers::setStaticProperty('Longman\TelegramBot\TelegramLog', 'logger', null);
TestHelpers::setStaticProperty('Longman\TelegramBot\TelegramLog', 'update_logger', null);
}
protected function tearDown()
......@@ -78,12 +79,14 @@ class TelegramLogTest extends TestCase
TelegramLog::initErrorLog($file);
TelegramLog::error('my error');
TelegramLog::error('my 50% error');
TelegramLog::error('my %s error', 'placeholder');
TelegramLog::error('my old %s %s error', 'custom', 'placeholder');
TelegramLog::error('my new {place} {holder} error', ['place' => 'custom', 'holder' => 'placeholder']);
$this->assertFileExists($file);
$error_log = file_get_contents($file);
$this->assertContains('bot_log.ERROR: my error', $error_log);
$this->assertContains('bot_log.ERROR: my 50% error', $error_log);
$this->assertContains('bot_log.ERROR: my placeholder error', $error_log);
$this->assertContains('bot_log.ERROR: my old custom placeholder error', $error_log);
$this->assertContains('bot_log.ERROR: my new custom placeholder error', $error_log);
}
public function testDebugStream()
......@@ -93,12 +96,14 @@ class TelegramLogTest extends TestCase
TelegramLog::initDebugLog($file);
TelegramLog::debug('my debug');
TelegramLog::debug('my 50% debug');
TelegramLog::debug('my %s debug', 'placeholder');
TelegramLog::debug('my old %s %s debug', 'custom', 'placeholder');
TelegramLog::debug('my new {place} {holder} debug', ['place' => 'custom', 'holder' => 'placeholder']);
$this->assertFileExists($file);
$debug_log = file_get_contents($file);
$this->assertContains('bot_log.DEBUG: my debug', $debug_log);
$this->assertContains('bot_log.DEBUG: my 50% debug', $debug_log);
$this->assertContains('bot_log.DEBUG: my placeholder debug', $debug_log);
$this->assertContains('bot_log.DEBUG: my old custom placeholder debug', $debug_log);
$this->assertContains('bot_log.DEBUG: my new custom placeholder debug', $debug_log);
}
public function testUpdateStream()
......@@ -108,12 +113,14 @@ class TelegramLogTest extends TestCase
TelegramLog::initUpdateLog($file);
TelegramLog::update('my update');
TelegramLog::update('my 50% update');
TelegramLog::update('my %s update', 'placeholder');
TelegramLog::update('my old %s %s update', 'custom', 'placeholder');
TelegramLog::update('my new {place} {holder} update', ['place' => 'custom', 'holder' => 'placeholder']);
$this->assertFileExists($file);
$debug_log = file_get_contents($file);
$this->assertContains('my update', $debug_log);
$this->assertContains('my 50% update', $debug_log);
$this->assertContains('my placeholder update', $debug_log);
$update_log = file_get_contents($file);
$this->assertContains('my update', $update_log);
$this->assertContains('my 50% update', $update_log);
$this->assertContains('my old custom placeholder update', $update_log);
$this->assertContains('my new custom placeholder update', $update_log);
}
public function testExternalStream()
......@@ -121,25 +128,29 @@ class TelegramLogTest extends TestCase
$file = self::$logfiles['external'];
$this->assertFileNotExists($file);
$external_monolog = new Logger('bot_update_log');
$external_monolog = new Logger('bot_external_log');
$external_monolog->pushHandler(new StreamHandler($file, Logger::ERROR));
$external_monolog->pushHandler(new StreamHandler($file, Logger::DEBUG));
TelegramLog::initialize($external_monolog);
TelegramLog::error('my error');
TelegramLog::error('my 50% error');
TelegramLog::error('my %s error', 'placeholder');
TelegramLog::error('my old %s %s error', 'custom', 'placeholder');
TelegramLog::error('my new {place} {holder} error', ['place' => 'custom', 'holder' => 'placeholder']);
TelegramLog::debug('my debug');
TelegramLog::debug('my 50% debug');
TelegramLog::debug('my %s debug', 'placeholder');
TelegramLog::debug('my old %s %s debug', 'custom', 'placeholder');
TelegramLog::debug('my new {place} {holder} debug', ['place' => 'custom', 'holder' => 'placeholder']);
$this->assertFileExists($file);
$file_contents = file_get_contents($file);
$this->assertContains('bot_update_log.ERROR: my error', $file_contents);
$this->assertContains('bot_update_log.ERROR: my 50% error', $file_contents);
$this->assertContains('bot_update_log.ERROR: my placeholder error', $file_contents);
$this->assertContains('bot_update_log.DEBUG: my debug', $file_contents);
$this->assertContains('bot_update_log.DEBUG: my 50% debug', $file_contents);
$this->assertContains('bot_update_log.DEBUG: my placeholder debug', $file_contents);
$this->assertContains('bot_external_log.ERROR: my error', $file_contents);
$this->assertContains('bot_external_log.ERROR: my 50% error', $file_contents);
$this->assertContains('bot_external_log.ERROR: my old custom placeholder error', $file_contents);
$this->assertContains('bot_external_log.ERROR: my new custom placeholder error', $file_contents);
$this->assertContains('bot_external_log.DEBUG: my debug', $file_contents);
$this->assertContains('bot_external_log.DEBUG: my 50% debug', $file_contents);
$this->assertContains('bot_external_log.DEBUG: my old custom placeholder debug', $file_contents);
$this->assertContains('bot_external_log.DEBUG: my new custom placeholder debug', $file_contents);
}
}
Markdown is supported
0% or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment