diff --git a/core/core.services.yml b/core/core.services.yml index 21a3e590ba..4b81990543 100644 --- a/core/core.services.yml +++ b/core/core.services.yml @@ -441,6 +441,8 @@ services: queue.database: class: Drupal\Core\Queue\QueueDatabaseFactory arguments: ['@database'] + queue.memory: + class: Drupal\Core\Queue\QueueMemoryFactory path.alias_whitelist: class: Drupal\Core\Path\AliasWhitelist tags: diff --git a/core/lib/Drupal/Core/Queue/QueueMemoryFactory.php b/core/lib/Drupal/Core/Queue/QueueMemoryFactory.php new file mode 100644 index 0000000000..77c1abc293 --- /dev/null +++ b/core/lib/Drupal/Core/Queue/QueueMemoryFactory.php @@ -0,0 +1,34 @@ + + */ + protected $queues = []; + + /** + * Constructs a new queue object for a given name. + * + * @param string $name + * The name of the queue + * + * @return \Drupal\Core\Queue\Memory + * A memory store implementation for the given queue. + */ + public function get($name) { + if (!isset($this->queues[$name])) { + $this->queues[$name] = new Memory($name); + } + + return $this->queues[$name]; + } + +} diff --git a/core/modules/dblog/config/install/dblog.settings.yml b/core/modules/dblog/config/install/dblog.settings.yml index 88add889ac..041ad6adb6 100644 --- a/core/modules/dblog/config/install/dblog.settings.yml +++ b/core/modules/dblog/config/install/dblog.settings.yml @@ -1 +1,5 @@ row_limit: 1000 +queue: + enabled: false + level: 4 + diff --git a/core/modules/dblog/config/schema/dblog.schema.yml b/core/modules/dblog/config/schema/dblog.schema.yml index d7196da6da..51d5580733 100644 --- a/core/modules/dblog/config/schema/dblog.schema.yml +++ b/core/modules/dblog/config/schema/dblog.schema.yml @@ -7,3 +7,14 @@ dblog.settings: row_limit: type: integer label: 'Database log messages to keep' + queue: + type: mapping + label: 'Queue-related settings' + mapping: + enabled: + type: boolean + label: 'Is the log queue enabled?' + level: + type: int + label: 'The level below which queue start flushing automatically. Must be a PSR/3 level.' + translatable: false diff --git a/core/modules/dblog/dblog.module b/core/modules/dblog/dblog.module index 700ceeaa6b..4413366610 100644 --- a/core/modules/dblog/dblog.module +++ b/core/modules/dblog/dblog.module @@ -10,6 +10,7 @@ */ use Drupal\Core\Form\FormStateInterface; +use Drupal\Core\Logger\RfcLogLevel; use Drupal\Core\Routing\RouteMatchInterface; use Drupal\Core\StringTranslation\TranslatableMarkup; use Drupal\views\ViewEntityInterface; @@ -98,14 +99,35 @@ function _dblog_get_message_types() { */ function dblog_form_system_logging_settings_alter(&$form, FormStateInterface $form_state) { $row_limits = [100, 1000, 10000, 100000, 1000000]; - $form['dblog_row_limit'] = [ + $config = \Drupal::configFactory()->getEditable('dblog.settings'); + $form['dblog'] = [ + '#type' => 'details', + '#open' => TRUE, + '#title' => t('Database logging'), + ]; + + $form['dblog']['dblog_row_limit'] = [ '#type' => 'select', '#title' => t('Database log messages to keep'), - '#default_value' => \Drupal::configFactory()->getEditable('dblog.settings')->get('row_limit'), + '#default_value' => $config->get('row_limit'), '#options' => [0 => t('All')] + array_combine($row_limits, $row_limits), '#description' => t('The maximum number of messages to keep in the database log. Requires a cron maintenance task.', [':cron' => \Drupal::url('system.status')]) ]; + $form['dblog']['dblog_queue_enabled'] = [ + '#type' => 'checkbox', + '#title' => t('Log queue enabled?'), + '#default_value' => $config->get('queue.enabled'), + ]; + + $form['dblog']['dblog_queue_level'] = [ + '#description' => t('Least-significant level causing a synchronous write to the database, even with queue enabled.'), + '#title' => t('Flush level'), + '#type' => 'select', + '#options' => array_reverse(RfcLogLevel::getLevels()), + '#default_value' => $config->get('queue.level'), + ]; + $form['#submit'][] = 'dblog_logging_settings_submit'; } @@ -115,7 +137,11 @@ function dblog_form_system_logging_settings_alter(&$form, FormStateInterface $fo * @see dblog_form_system_logging_settings_alter() */ function dblog_logging_settings_submit($form, FormStateInterface $form_state) { - \Drupal::configFactory()->getEditable('dblog.settings')->set('row_limit', $form_state->getValue('dblog_row_limit'))->save(); + \Drupal::configFactory()->getEditable('dblog.settings') + ->set('row_limit', $form_state->getValue('dblog_row_limit')) + ->set('queue.enabled', $form_state->getValue('dblog_queue_enabled')) + ->set('queue.level', $form_state->getValue('dblog_queue_level')) + ->save(); } /** diff --git a/core/modules/dblog/dblog.services.yml b/core/modules/dblog/dblog.services.yml index 96ac2ee948..50daa48448 100644 --- a/core/modules/dblog/dblog.services.yml +++ b/core/modules/dblog/dblog.services.yml @@ -1,7 +1,12 @@ services: logger.dblog: class: Drupal\dblog\Logger\DbLog - arguments: ['@database', '@logger.log_message_parser'] + arguments: + - '@database' + - '@logger.log_message_parser' + - '@queue.memory' + - '@config.factory' tags: - { name: logger } - { name: backend_overridable } + - { name: event_subscriber } diff --git a/core/modules/dblog/src/Logger/DbLog.php b/core/modules/dblog/src/Logger/DbLog.php index 97b0b7b305..9ced05d912 100644 --- a/core/modules/dblog/src/Logger/DbLog.php +++ b/core/modules/dblog/src/Logger/DbLog.php @@ -3,26 +3,43 @@ namespace Drupal\dblog\Logger; use Drupal\Component\Utility\Unicode; +use Drupal\Core\Config\ConfigFactoryInterface; use Drupal\Core\Database\Connection; use Drupal\Core\Database\Database; use Drupal\Core\Database\DatabaseException; use Drupal\Core\DependencyInjection\DependencySerializationTrait; use Drupal\Core\Logger\LogMessageParserInterface; use Drupal\Core\Logger\RfcLoggerTrait; +use Drupal\Core\Logger\RfcLogLevel; +use Drupal\Core\Queue\QueueMemoryFactory; use Psr\Log\LoggerInterface; +use Psr\Log\LogLevel; +use Symfony\Component\EventDispatcher\Event; +use Symfony\Component\EventDispatcher\EventSubscriberInterface; +use Symfony\Component\HttpKernel\KernelEvents; /** * Logs events in the watchdog database table. */ -class DbLog implements LoggerInterface { +class DbLog implements LoggerInterface, EventSubscriberInterface { use RfcLoggerTrait; use DependencySerializationTrait; + /** + * The name of the configuration used by this module. + */ + const CONFIG_NAME = 'dblog.settings'; + /** * The dedicated database connection target to use for log entries. */ const DEDICATED_DBLOG_CONNECTION_TARGET = 'dedicated_dblog'; + /** + * The name of the memory queue used to defer database writes. + */ + const QUEUE_NAME = 'dblog'; + /** * The database connection object. * @@ -30,6 +47,13 @@ class DbLog implements LoggerInterface { */ protected $connection; + /** + * The level below which queue gets flushed. + * + * @var string + */ + protected $flushLevel; + /** * The message's placeholders parser. * @@ -37,6 +61,20 @@ class DbLog implements LoggerInterface { */ protected $parser; + /** + * The deferred log queue. + * + * @var \Drupal\Core\Queue\Memory + */ + protected $queue; + + /** + * Does the loger use queueing? + * + * @var bool + */ + protected $useQueue; + /** * Constructs a DbLog object. * @@ -44,23 +82,31 @@ class DbLog implements LoggerInterface { * The database connection object. * @param \Drupal\Core\Logger\LogMessageParserInterface $parser * The parser to use when extracting message variables. + * @param \Drupal\Core\Queue\QueueMemoryFactory $queueFactory + * A queue factory service. + * @param \Drupal\Core\Config\ConfigFactoryInterface $configFactory + * The config.factory service. */ - public function __construct(Connection $connection, LogMessageParserInterface $parser) { + public function __construct(Connection $connection, LogMessageParserInterface $parser, QueueMemoryFactory $queueFactory, ConfigFactoryInterface $configFactory) { + $config = $configFactory->get(static::CONFIG_NAME); $this->connection = $connection; $this->parser = $parser; + $this->useQueue = $config->get('queue.enabled'); + + // Conditionals. + $this->flushLevel = $this->useQueue ? $config->get('queue.level') : LogLevel::DEBUG; + $this->queue = $this->useQueue ? $queueFactory->get(static::QUEUE_NAME) : NULL; } /** - * {@inheritdoc} + * Write a single event to the database. + * + * @param int $level + * @param string $message + * @param array $message_placeholders + * @param array $context */ - public function log($level, $message, array $context = []) { - // Remove any backtraces since they may contain an unserializable variable. - unset($context['backtrace']); - - // Convert PSR3-style messages to SafeMarkup::format() style, so they can be - // translated too in runtime. - $message_placeholders = $this->parser->parseMessagePlaceholders($message, $context); - + protected function dbLog($level, $message, array $message_placeholders, array $context = []) { try { $this->connection ->insert('watchdog') @@ -109,4 +155,59 @@ public function log($level, $message, array $context = []) { } } + protected function dbLogQueue() { + // TODO convert to multi-value insert. + // TODO probably convert to something like cron->run() and a QueueWorker. + while ($item = $this->queue->claimItem()) { + call_user_func_array([$this, 'dbLog'], $item->data); + $this->queue->deleteItem($item); + } + } + + /** + * {@inheritdoc} + */ + public static function getSubscribedEvents() { + return [KernelEvents::TERMINATE => ['onTerminate']]; + } + + /** + * {@inheritdoc} + */ + public function log($level, $message, array $context = []) { + // Remove any backtraces since they may contain an unserializable variable. + unset($context['backtrace']); + + // Convert PSR3-style messages to SafeMarkup::format() style, so they can be + // translated too in runtime. + $message_placeholders = $this->parser->parseMessagePlaceholders($message, $context); + + if (!$this->useQueue) { + // ksm("Not queued write $message"); + $this->dbLog($level, $message, $message_placeholders, $context); + } + elseif ($level <= $this->flushLevel) { + // ksm("Queued flush write $message"); + // Log previously stored message. + $this->dbLogQueue(); + // Then log this one to preserve ordering. + $this->dbLog($level, $message, $message_placeholders, $context); + } + else { + // ksm("Enqueueing $message"); + $this->queue->createItem(compact('level', 'message', 'message_placeholders', 'context')); + } + } + + /** + * Handler for KernelEvents::TERMINATE. + * + * @param \Symfony\Component\EventDispatcher\Event $event + */ + public function onTerminate(Event $event) { + if ($this->useQueue) { + $this->dbLogQueue(); + } + } + }