<?php
namespace MDM\LoggerBundle\EventSubscriber;
use MDM\LoggerBundle\Events\RetrieveTransactionIdEvent;
use MDM\LoggerBundle\Logger\LoggerService;
use MDM\LoggerBundle\Messenger\Stamps\TransactionIdStamp;
use Symfony\Component\Console\Command\Command;
use Symfony\Component\Console\ConsoleEvents;
use Symfony\Component\Console\Event\ConsoleCommandEvent;
use Symfony\Component\Console\Event\ConsoleErrorEvent;
use Symfony\Component\Console\Event\ConsoleTerminateEvent;
use Symfony\Component\EventDispatcher\EventSubscriberInterface;
use Symfony\Component\HttpKernel\Event\ControllerEvent;
use Symfony\Component\HttpKernel\Event\ExceptionEvent;
use Symfony\Component\HttpKernel\Event\RequestEvent;
use Symfony\Component\HttpKernel\Event\ResponseEvent;
use Symfony\Component\HttpKernel\Event\TerminateEvent;
use Symfony\Component\HttpKernel\KernelEvents;
use Symfony\Component\Messenger\Event\AbstractWorkerMessageEvent;
use Symfony\Component\Messenger\Event\WorkerMessageFailedEvent;
use Symfony\Component\Messenger\Event\WorkerMessageHandledEvent;
use Symfony\Component\Messenger\Event\WorkerMessageReceivedEvent;
use Symfony\Component\Stopwatch\Stopwatch;
/**
* Class LoggingSubscriber
* @package App\EventSubscriber
*/
class LoggingSubscriber implements EventSubscriberInterface
{
private const STOPWATCH_REQUEST = 'request';
private const STOPWATCH_WORKER = 'worker';
private const STOPWATCH_COMMAND = 'command';
/**
* @var LoggerService
*/
private $loggerService;
/**
* @var string|null
*/
private $routeName;
/**
* @var Stopwatch
*/
private $stopwatch;
private $transactionId;
/**
* LoggingSubscriber constructor.
* @param LoggerService $loggerService
*/
public function __construct(LoggerService $loggerService)
{
$this->stopwatch = new Stopwatch();
$this->loggerService = $loggerService;
}
/**
* @inheritDoc
*/
public static function getSubscribedEvents()
{
return [
KernelEvents::REQUEST => ['onKernelRequest', 50],
KernelEvents::CONTROLLER => ['onKernelController', 50],
KernelEvents::TERMINATE => ['onKernelTerminate', -10],
KernelEvents::EXCEPTION => ['onKernelException', 20],
WorkerMessageReceivedEvent::class => ['onWorkerMessageReceived', 30],
WorkerMessageFailedEvent::class => ['onWorkerMessageFailed', 20],
WorkerMessageHandledEvent::class => ['onWorkerMessageHandled', 20],
RetrieveTransactionIdEvent::class => 'onRetrieveTransactionId',
ConsoleEvents::COMMAND => ['onConsoleCommand'],
ConsoleEvents::ERROR => ['onConsoleError'],
ConsoleEvents::TERMINATE => ['onConsoleTerminate', -10]
];
}
/**
* @param ConsoleCommandEvent $event
*/
public function onConsoleCommand(ConsoleCommandEvent $event)
{
$this->stopwatch->reset();
$this->stopwatch->start(self::STOPWATCH_COMMAND);
$this->transactionId = uniqid('', true);
$this->loggerService->debug("New TransactionId created: {$this->transactionId}");
$this->loggerService->addContext([
'transaction_id' => $this->transactionId,
'trigger' => 'Command: ' . $event->getCommand()->getName()
]);
}
/**
* @param ConsoleErrorEvent $event
*/
public function onConsoleError(ConsoleErrorEvent $event)
{
$this->loggerService->logException($event->getError());
}
/**
* @param ConsoleTerminateEvent $event
*/
public function onConsoleTerminate(ConsoleTerminateEvent $event)
{
if ($this->stopwatch->isStarted(self::STOPWATCH_COMMAND)) {
$this->stopwatch->stop(self::STOPWATCH_COMMAND);
$duration = $this->stopwatch->getEvent(self::STOPWATCH_COMMAND)->getDuration();
$this->loggerService->addContext(['duration' => $duration]);
}
$success = $event->getExitCode() === Command::SUCCESS;
$this->loggerService->addContext(['status' => $success ? 'successful' : 'failed']);
$this->loggerService->publishLog(
sprintf("%s command %s", $event->getCommand()->getName(), $success ? 'successful' : 'failed')
);
$this->loggerService->clearContext();
}
/**
* @param RequestEvent $event
*/
public function onKernelRequest(RequestEvent $event)
{
$this->stopwatch->start(self::STOPWATCH_REQUEST);
$request = $event->getRequest();
// Attempt to retrieve existing request. If this event is triggered multiple times, we do not
// want to overwrite an already generated ID
if (!$this->transactionId) {
$this->transactionId = $request->headers->get('transaction-id');
}
if (is_null($this->transactionId)) {
$this->transactionId = uniqid('', true);
$this->loggerService->debug("New TransactionId created: {$this->transactionId}");
}
$request->attributes->set('transaction-id', $this->transactionId);
$this->loggerService->addContext([
'transaction_id' => $this->transactionId,
'basic_auth_user' => $request->headers->get('php-auth-user') ?? 'unknown',
'trigger' => 'Request: ' . $event->getRequest()->getPathInfo()
]);
$this->loggerService->logRequest($request);
}
/**
* @param ControllerEvent $event
*/
public function onKernelController(ControllerEvent $event)
{
$request = $event->getRequest();
$this->routeName = $request->attributes->get('_route');
}
/**
* @param TerminateEvent $event
*/
public function onKernelTerminate(TerminateEvent $event)
{
$response = $event->getResponse();
$this->loggerService->logResponse($response, $this->routeName);
if ($this->stopwatch->isStarted(self::STOPWATCH_REQUEST)) {
$this->stopwatch->stop(self::STOPWATCH_REQUEST);
$duration = $this->stopwatch->getEvent(self::STOPWATCH_REQUEST)->getDuration();
$this->loggerService->addContext(['duration' => $duration]);
$this->stopwatch->reset();
}
$this->loggerService->addContext(
[
'status' => ($response->getStatusCode() < 400) ? 'successful' : 'failed',
'status_code' => $response->getStatusCode()
]
);
$this->loggerService->publishLog(
sprintf('%s %s', $this->routeName, $response->isSuccessful() ? 'successful' : 'failed')
);
}
/**
* @param RetrieveTransactionIdEvent $event
*/
public function onRetrieveTransactionId(RetrieveTransactionIdEvent $event)
{
if (!$this->transactionId) {
$this->loggerService->warning('TransactionId not set yet!');
}
$event->setTransactionId($this->transactionId);
}
/**
* @param ExceptionEvent $event
*/
public function onKernelException(ExceptionEvent $event)
{
$this->loggerService->logException($event->getThrowable());
}
/**
* @param WorkerMessageReceivedEvent $event
*/
public function onWorkerMessageReceived(WorkerMessageReceivedEvent $event)
{
/** @var TransactionIdStamp $id */
$id = $event->getEnvelope()->last(TransactionIdStamp::class);
$this->stopwatch->reset();
$this->stopwatch->start(self::STOPWATCH_WORKER);
$this->transactionId = $id ? $id->getTransactionId() : null;
if (is_null($this->transactionId)) {
$this->transactionId = uniqid('', true);
$this->loggerService->debug("New TransactionId created: {$this->transactionId}");
}
$this->loggerService->addContext([
'transaction_id' => $this->transactionId,
'trigger' => 'Message: ' . $event->getReceiverName()
]);
}
/**
* @param WorkerMessageHandledEvent $event
*/
public function onWorkerMessageHandled(WorkerMessageHandledEvent $event)
{
$this->onWorkerComplete($event, true);
}
/**
* @param WorkerMessageFailedEvent $event
*/
public function onWorkerMessageFailed(WorkerMessageFailedEvent $event)
{
$this->onWorkerComplete($event, false);
}
/**
* @param AbstractWorkerMessageEvent $event
* @param bool $success
*/
protected function onWorkerComplete(AbstractWorkerMessageEvent $event, bool $success)
{
if ($this->stopwatch->isStarted(self::STOPWATCH_WORKER)) {
$this->stopwatch->stop(self::STOPWATCH_WORKER);
$duration = $this->stopwatch->getEvent(self::STOPWATCH_WORKER)->getDuration();
$this->loggerService->addContext(['duration' => $duration]);
}
$this->loggerService->addContext(['status' => $success ? 'successful' : 'failed']);
$this->loggerService->publishLog(
sprintf("%s Worker %s", $event->getReceiverName(), $success ? 'successful' : 'failed')
);
$this->loggerService->clearContext();
}
}