View source
<?php
declare (strict_types=1);
namespace Drupal\mongodb_watchdog;
use Drupal\Component\Datetime\TimeInterface;
use Drupal\Component\Render\FormattableMarkup;
use Drupal\Component\Render\MarkupInterface;
use Drupal\Component\Utility\Xss;
use Drupal\Core\Config\ConfigFactoryInterface;
use Drupal\Core\Logger\LogMessageParserInterface;
use Drupal\Core\Logger\RfcLogLevel;
use Drupal\Core\Messenger\MessengerInterface;
use Drupal\Core\StringTranslation\StringTranslationTrait;
use MongoDB\Collection;
use MongoDB\Database;
use MongoDB\Driver\Cursor;
use MongoDB\Driver\Exception\InvalidArgumentException;
use MongoDB\Driver\Exception\RuntimeException;
use MongoDB\Driver\WriteConcern;
use MongoDB\Model\CollectionInfoIterator;
use Psr\Log\AbstractLogger;
use Psr\Log\LogLevel;
use Symfony\Component\HttpFoundation\RequestStack;
class Logger extends AbstractLogger {
use StringTranslationTrait;
const CONFIG_NAME = 'mongodb_watchdog.settings';
const CONFIG_ITEMS = 'items';
const CONFIG_REQUESTS = 'requests';
const CONFIG_LIMIT = 'limit';
const CONFIG_ITEMS_PER_PAGE = 'items_per_page';
const CONFIG_REQUEST_TRACKING = 'request_tracking';
const DB_LOGGER = 'logger';
const DEFAULT_CHANNEL = 'psr-3';
const MODULE = 'mongodb_watchdog';
const SERVICE_LOGGER = 'mongodb.logger';
const SERVICE_CHANNEL = 'logger.channel.mongodb_watchdog';
const SERVICE_REQUIREMENTS = 'mongodb.watchdog_requirements';
const SERVICE_SANITY_CHECK = 'mongodb.watchdog.sanity_check';
const TRACKER_COLLECTION = 'watchdog_tracker';
const TEMPLATE_COLLECTION = 'watchdog';
const EVENT_COLLECTION_PREFIX = 'watchdog_event_';
const EVENT_COLLECTIONS_PATTERN = '^watchdog_event_[[:xdigit:]]{32}$';
const LEGACY_TYPE_MAP = [
'typeMap' => [
'array' => 'array',
'document' => 'array',
'root' => 'array',
],
];
protected $rfc5424levels = [
LogLevel::EMERGENCY => RfcLogLevel::EMERGENCY,
LogLevel::ALERT => RfcLogLevel::ALERT,
LogLevel::CRITICAL => RfcLogLevel::CRITICAL,
LogLevel::ERROR => RfcLogLevel::ERROR,
LogLevel::WARNING => RfcLogLevel::WARNING,
LogLevel::NOTICE => RfcLogLevel::NOTICE,
LogLevel::INFO => RfcLogLevel::INFO,
LogLevel::DEBUG => RfcLogLevel::DEBUG,
];
protected $database;
protected $items;
protected $limit = RfcLogLevel::DEBUG;
protected $messenger;
protected $parser;
protected $requests;
protected $requestStack;
protected $requestTracking;
protected $sequence = 0;
protected $templates = [];
protected $time;
public function __construct(Database $database, LogMessageParserInterface $parser, ConfigFactoryInterface $configFactory, RequestStack $stack, MessengerInterface $messenger, TimeInterface $time) {
$this->database = $database;
$this->messenger = $messenger;
$this->parser = $parser;
$this->requestStack = $stack;
$this->time = $time;
$config = $configFactory
->get(static::CONFIG_NAME);
$this
->setLimit($config
->get(static::CONFIG_LIMIT) ?? RfcLogLevel::DEBUG);
$this->items = $config
->get(static::CONFIG_ITEMS) ?? 10000;
$this->requests = $config
->get(static::CONFIG_REQUESTS) ?? 100000;
$this->requestTracking = $config
->get(static::CONFIG_REQUEST_TRACKING) ?? FALSE;
}
protected function enhanceLogEntry(array &$entry, array $backtrace) : void {
static $ignored = [
'call_user_func_array' => 1,
'_drupal_log_error' => 1,
'_drupal_error_handler' => 1,
'_drupal_error_handler_real' => 1,
'Drupal\\mongodb_watchdog\\Logger::log' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::log' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::alert' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::critical' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::debug' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::emergency' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::error' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::info' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::notice' => 1,
'Drupal\\Core\\Logger\\LoggerChannel::warning' => 1,
'Psr\\Log\\AbstractLogger::alert' => 1,
'Psr\\Log\\AbstractLogger::critical' => 1,
'Psr\\Log\\AbstractLogger::debug' => 1,
'Psr\\Log\\AbstractLogger::emergency' => 1,
'Psr\\Log\\AbstractLogger::error' => 1,
'Psr\\Log\\AbstractLogger::info' => 1,
'Psr\\Log\\AbstractLogger::notice' => 1,
'Psr\\Log\\AbstractLogger::warning' => 1,
];
foreach ($backtrace as $bt) {
if (isset($bt['function'])) {
$function = empty($bt['class']) ? $bt['function'] : $bt['class'] . '::' . $bt['function'];
if (empty($ignored[$function])) {
$entry['%function'] = $function;
$entry['%line'] = $bt['line'] ?? NULL;
$file = $bt['file'] ?? '';
if (empty($file) && is_callable($function)) {
$reflectionObj = empty($bt['class']) ? new \ReflectionFunction($function) : new \ReflectionMethod($function);
$file = $reflectionObj
->getFileName();
}
$entry['%file'] = $file;
break;
}
elseif ($bt['function'] == '_drupal_exception_handler') {
$e = $bt['args'][0];
$this
->enhanceLogEntry($entry, $e
->getTrace());
}
}
}
}
public function log($level, $template, array $context = []) : void {
if (is_string($level)) {
$level = $this->rfc5424levels[$level];
}
if ($level > $this->limit) {
return;
}
$placeholders = $this->parser
->parseMessagePlaceholders($template, $context);
$type = $context['channel'] ?? static::DEFAULT_CHANNEL;
$location = [
'%type' => 1,
'@message' => 1,
'%function' => 1,
'%file' => 1,
'%line' => 1,
];
if (!empty(array_diff_key($location, $placeholders))) {
$this
->enhanceLogEntry($placeholders, debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS, 10));
}
$file = $placeholders['%file'];
$line = $placeholders['%line'];
$function = $placeholders['%function'];
$key = implode(":", [
$type,
$level,
$file,
$line,
$function,
]);
$templateId = md5($key);
$selector = [
'_id' => $templateId,
];
$update = [
'$inc' => [
'count' => 1,
],
'$set' => [
'_id' => $templateId,
'message' => $template,
'severity' => $level,
'changed' => $this->time
->getCurrentTime(),
'type' => mb_substr($type, 0, 64),
],
];
$options = [
'upsert' => TRUE,
];
$templateResult = $this->database
->selectCollection(static::TEMPLATE_COLLECTION)
->updateOne($selector, $update, $options);
if ($this->requestTracking && !isset($this->templates[$templateId])) {
$requestId = $this->requestStack
->getCurrentRequest()->server
->get('UNIQUE_ID');
$this->templates[$templateId] = 1;
$track = [
'requestId' => $requestId,
'templateId' => $templateId,
];
$this
->trackerCollection()
->insertOne($track);
}
else {
$requestId = '@@Not-a-valid-request@@';
}
$eventCollection = $this
->eventCollection($templateId);
if ($templateResult
->getUpsertedCount()) {
$options = [
'capped' => TRUE,
'size' => $this->items * 1024,
'max' => $this->items,
];
$this->database
->createCollection($eventCollection
->getCollectionName(), $options);
if ($this->requestTracking) {
$key = [
'requestTracking_id' => 1,
];
$options = [
'name' => 'admin-by-request',
];
$eventCollection
->createIndex($key, $options);
}
}
foreach ($placeholders as &$placeholder) {
if ($placeholder instanceof MarkupInterface) {
$placeholder = Xss::filterAdmin($placeholder);
}
}
$event = [
'hostname' => mb_substr($context['ip'] ?? '', 0, 128),
'link' => $context['link'] ?? NULL,
'location' => $context['request_uri'] ?? NULL,
'referer' => $context['referer'] ?? NULL,
'timestamp' => $context['timestamp'] ?? $this->time
->getCurrentTime(),
'user' => [
'uid' => $context['uid'] ?? 0,
],
'variables' => $placeholders,
];
if ($this->requestTracking) {
$event['requestTracking_id'] = $requestId;
$event['requestTracking_sequence'] = $this->sequence;
$this->sequence++;
}
$eventCollection
->insertOne($event);
}
public function ensureCappedCollection(string $name, int $size) : Collection {
if ($size === 0) {
$this->messenger
->addError($this
->t('Abnormal size 0 ensuring capped collection, defaulting.'));
$size = 100000;
}
$collection = $this
->ensureCollection($name);
$stats = $this->database
->command([
'collStats' => $name,
], static::LEGACY_TYPE_MAP)
->toArray()[0];
if (!empty($stats['capped'])) {
return $collection;
}
$command = [
'convertToCapped' => $name,
'size' => $size,
];
$this->database
->command($command);
$this->messenger
->addStatus($this
->t('@name converted to capped collection size @size.', [
'@name' => $name,
'@size' => $size,
]));
return $collection;
}
public function ensureCollection(string $name) : Collection {
$collection = $this->database
->selectCollection($name);
$info = current(iterator_to_array($this->database
->listCollections([
'filter' => [
'name' => $name,
],
])));
if ($info === FALSE) {
$res = $collection
->insertOne([
'_id' => 'dummy',
[
'writeConcern' => [
'w' => WriteConcern::MAJORITY,
'j' => TRUE,
],
],
]);
if (!$res
->isAcknowledged()) {
throw new RuntimeException("Failed inserting document during ensureCollection");
}
$collection
->deleteMany([]);
}
return $collection;
}
public function ensureSchema() : void {
$trackerCollection = $this
->ensureCappedCollection(static::TRACKER_COLLECTION, $this->requests * 1024);
$indexes = [
[
'name' => 'tracker-request',
'key' => [
'request_id' => 1,
],
],
];
$trackerCollection
->createIndexes($indexes);
$indexes = [
[
'name' => 'for-increments',
'key' => [
'line' => 1,
'changed' => -1,
],
],
[
'name' => 'overview-no-filters',
'key' => [
'changed' => -1,
],
],
[
'name' => 'overview-by-type',
'key' => [
'type' => 1,
'changed' => -1,
],
],
[
'name' => 'overview-by-severity',
'key' => [
'severity' => 1,
'changed' => -1,
],
],
[
'name' => 'overview-by-both',
'key' => [
'type' => 1,
'severity' => 1,
'changed' => -1,
],
],
];
$this
->templateCollection()
->createIndexes($indexes);
}
public function eventCollection($templateId) : Collection {
$name = static::EVENT_COLLECTION_PREFIX . $templateId;
if (!preg_match('/' . static::EVENT_COLLECTIONS_PATTERN . '/', $name)) {
throw new InvalidArgumentException(new FormattableMarkup('Invalid watchdog template id `@id`.', [
'@id' => $name,
]));
}
$collection = $this->database
->selectCollection($name);
return $collection;
}
public function eventCollections() : CollectionInfoIterator {
$options = [
'filter' => [
'name' => [
'$regex' => static::EVENT_COLLECTIONS_PATTERN,
],
],
];
$result = $this->database
->listCollections($options);
return $result;
}
public function eventCount(EventTemplate $template) : int {
return $this
->eventCollection($template->_id)
->countDocuments();
}
public function requestEvents($requestId, $skip = 0, $limit = 0) : array {
$templates = $this
->requestTemplates($requestId);
$selector = [
'requestTracking_id' => $requestId,
'requestTracking_sequence' => [
'$gte' => $skip,
'$lt' => $skip + $limit,
],
];
$events = [];
$options = [
'typeMap' => [
'array' => 'array',
'document' => 'array',
'root' => '\\Drupal\\mongodb_watchdog\\Event',
],
];
foreach ($templates as $templateId => $template) {
$eventCollection = $this
->eventCollection($templateId);
$cursor = $eventCollection
->find($selector, $options);
foreach ($cursor as $event) {
$events[$event->requestTracking_sequence] = [
$template,
$event,
];
}
}
ksort($events);
return $events;
}
public function requestEventsCount($requestId) : int {
if (empty($requestId)) {
return 0;
}
$templates = $this
->requestTemplates($requestId);
$count = 0;
foreach ($templates as $template) {
$eventCollection = $this
->eventCollection($template->_id);
$selector = [
'requestTracking_id' => $requestId,
];
$count += $eventCollection
->countDocuments($selector);
}
return $count;
}
public function setLimit(int $limit) : void {
$this->limit = $limit;
}
public function templatesCount() : int {
return $this
->templateCollection()
->countDocuments();
}
public function requestTemplates($unsafeRequestId) : array {
$selector = [
'requestId' => "{$unsafeRequestId}",
];
$cursor = $this
->trackerCollection()
->find($selector, static::LEGACY_TYPE_MAP + [
'projection' => [
'_id' => 0,
'template_id' => 1,
],
]);
$templateIds = [];
foreach ($cursor as $request) {
$templateIds[] = $request['template_id'];
}
if (empty($templateIds)) {
return [];
}
$selector = [
'_id' => [
'$in' => $templateIds,
],
];
$options = [
'typeMap' => [
'array' => 'array',
'document' => 'array',
'root' => '\\Drupal\\mongodb_watchdog\\EventTemplate',
],
];
$templates = [];
$cursor = $this
->templateCollection()
->find($selector, $options);
foreach ($cursor as $template) {
$templates[$template->_id] = $template;
}
return $templates;
}
public function trackerCollection() : Collection {
return $this->database
->selectCollection(static::TRACKER_COLLECTION);
}
public function templateCollection() : Collection {
return $this->database
->selectCollection(static::TEMPLATE_COLLECTION);
}
public function templates(array $types = [], array $levels = [], $skip = 0, $limit = 0) : Cursor {
$selector = [];
if (!empty($types)) {
$selector['type'] = [
'$in' => array_values($types),
];
}
if (!empty($levels) && count($levels) !== count(RfcLogLevel::getLevels())) {
$selector['severity'] = [
'$in' => array_values(array_map('intval', $levels)),
];
}
$options = [
'sort' => [
'count' => -1,
'changed' => -1,
],
'typeMap' => [
'array' => 'array',
'document' => 'array',
'root' => '\\Drupal\\mongodb_watchdog\\EventTemplate',
],
];
if ($skip) {
$options['skip'] = $skip;
}
if ($limit) {
$options['limit'] = $limit;
}
$cursor = $this
->templateCollection()
->find($selector, $options);
return $cursor;
}
public function templateTypes() : array {
$ret = $this
->templateCollection()
->distinct('type');
return $ret;
}
}