Logging possible des requêtes reçues et des temps de traitements (SQL, génération HAL).

CHANGELOG.md

 Journal des modifications
 =========================
 
+1.3.6
+-----
+- Logging possible des requêtes reçues et des temps de traitements (SQL, génération HAL).
+
 1.3.5
 -----
 

composer.json

@@ -25,7 +25,8 @@
         "unicaen/oracle": "^1.2",
         "doctrine/common": "^2.7",
         "zendframework/zend-mvc-console": "^1.2",
-        "zendframework/zend-log": "^2.11"
+        "zendframework/zend-log": "^2.11",
+        "monolog/monolog": "^1.26"
     },
     "require-dev": {
         "zendframework/zend-developer-tools": "^1.1",

docker-compose.yml

@@ -2,15 +2,16 @@ version: "2"
 
 services:
   sygal-import-ws:
-    container_name: sygal-import-ws-container
-    build:
-      context: .
-      args:
-        PHP_VERSION: 7.0
+    image: sygal-import-ws-image-php7.0
+    container_name: sygal-import-ws-container-php7.0
+    environment:
+      - http_proxy
+      - https_proxy
+      - no_proxy
     ports:
-     - "8080:80"
-     - "8443:443"
+      - "8443:443"
     volumes:
-     - .:/app
+      - .:/app
+      - /tmp:/tmp
     working_dir: /app
-    network_mode: bridge
+    network_mode: bridge
\ No newline at end of file

module/ImportData/config/module.config.php

 <?php
+
+use ImportData\ApiLogging;
+use ImportData\ApiLoggingFactory;
+
 return [
+    'logging' => [
+        'enabled' => false,
+        'params' => [
+            'name' => 'fetch_log',
+            'file_path' => '/tmp/api-logging.log',
+            'max_files' => 5,
+        ],
+    ],
     'doctrine' => [
         'driver' => [
             'orm_default_xml_driver' => [
@@ -2713,6 +2725,7 @@ return [
     'service_manager' => [
         'factories' => [
             \ImportData\V1\Rest\Version\VersionResource::class => \ImportData\V1\Rest\Version\VersionResourceFactory::class,
+            ApiLogging::class => ApiLoggingFactory::class,
         ],
     ],
 ];

module/ImportData/src/ApiLogging.php

+<?php
+
+namespace ImportData;
+
+use Doctrine\DBAL\Logging\SQLLogger;
+use Psr\Log\LoggerAwareTrait;
+use Zend\EventManager\EventInterface;
+use Zend\EventManager\EventManagerInterface;
+use Zend\EventManager\ListenerAggregateInterface;
+use Zend\EventManager\ListenerAggregateTrait;
+use ZF\Apigility\Doctrine\Server\Event\DoctrineResourceEvent;
+use ZF\ContentNegotiation\Request;
+use ZF\Hal\Plugin\Hal;
+use ZF\Rest\RestController;
+
+class ApiLogging implements ListenerAggregateInterface, SQLLogger
+{
+    use ListenerAggregateTrait;
+    use LoggerAwareTrait;
+
+    /**
+     * @var bool
+     */
+    private $enabled;
+
+    /**
+     * @var array
+     */
+    private $context;
+
+    /**
+     * @var float
+     */
+    private $sqlQuery;
+
+    /**
+     * @var float
+     */
+    private $getListStartTime;
+
+    /**
+     * @var float
+     */
+    private $sqlQueryStartTime;
+
+    /**
+     * @var float
+     */
+    private $renderStartTime;
+
+    /**
+     * ApiLogging constructor.
+     */
+    public function __construct()
+    {
+        $this->enabled = false;
+        $this->context = [];
+    }
+
+    /**
+     * @param bool $enabled
+     * @return self
+     */
+    public function setEnabled(bool $enabled): self
+    {
+        $this->enabled = $enabled;
+
+        return $this;
+    }
+
+    /**
+     * @return bool
+     */
+    public function isEnabled(): bool
+    {
+        return $this->enabled;
+    }
+
+    /**
+     * Ecoute de certains événements inteéressants pour chronométrer certains traitements.
+     *
+     * NB: Inutile d'écouter les évènements {@see DoctrineResourceEvent::EVENT_FETCH_ALL_PRE} et
+     * {@see DoctrineResourceEvent::EVENT_FETCH_ALL_POST} pour mesurer le temps écoulé entre les 2
+     * car en réalité les données ne sont réellement fetchée en BDD qu'au moment du parcours du paginator
+     * par le plugin {@see Hal::renderCollection()}.
+     *
+     * @param EventManagerInterface $events
+     * @param int $priority
+     */
+    public function attach(EventManagerInterface $events, $priority = 1)
+    {
+        if (! $this->isEnabled()) {
+            return;
+        }
+
+        $events->getSharedManager()->attach(
+            RestController::class,
+            'getList.pre',
+            [$this, 'preGetList']
+        );
+
+        $events->getSharedManager()->attach(
+            Hal::class,
+            'renderCollection',
+            [$this, 'preRenderCollection']
+        );
+        $events->getSharedManager()->attach(
+            Hal::class,
+            'renderCollection.post',
+            [$this, 'postRenderCollection']
+        );
+    }
+
+    /**
+     * Au début de {@see RestController::getList()}.
+     *
+     * @param EventInterface $e
+     */
+    public function preGetList(EventInterface $e)
+    {
+        $restController = $e->getTarget(); /** @var $restController RestController */
+        $request = $restController->getRequest(); /** @var $request Request */
+
+        $this->getListStartTime = microtime(true);
+        $this->context = [];
+
+        $message = $request->getMethod() . ' ' . $request->getUriString();
+
+        $this->logger->info($message);
+    }
+
+    /**
+     * Au début de la génération HAL.
+     *
+     * @param EventInterface $e
+     */
+    public function preRenderCollection(EventInterface $e)
+    {
+        $this->renderStartTime = microtime(true);
+    }
+
+    /**
+     * Avant l'exécution d'une requête SQL.
+     *
+     * @param string $sql
+     * @param array|null $params
+     * @param array|null $types
+     */
+    public function startQuery($sql, array $params = null, array $types = null)
+    {
+        $this->sqlQuery = $sql;
+        $this->sqlQueryStartTime = microtime(true);
+    }
+
+    /**
+     * Après l'exécution d'une requête SQL.
+     */
+    public function stopQuery()
+    {
+        $duration = microtime(true) - $this->sqlQueryStartTime;
+        $message = "  [SQL] " . substr($this->sqlQuery, 0, 30) . ' ... ' . substr($this->sqlQuery, -30);
+
+        $this->logger->info($message, [
+            'sql_query_duration' => sprintf("%f s", $duration),
+        ]);
+    }
+
+    /**
+     * À la fin de la génération HAL.
+     *
+     * @param EventInterface $e
+     */
+    public function postRenderCollection(EventInterface $e)
+    {
+        $duration = microtime(true) - $this->renderStartTime;
+        $this->context['render_duration'] = sprintf("%f s", $duration);
+
+        $totalDuration = microtime(true) - $this->getListStartTime;
+
+        $this->logger->info("  [Render]", ['render_duration' => sprintf("%f s", $duration)]);
+        $this->logger->info("  Total: " . sprintf("%f s", $totalDuration));
+    }
+}

module/ImportData/src/ApiLoggingFactory.php

+<?php
+
+namespace ImportData;
+
+use Doctrine\ORM\Configuration;
+use Interop\Container\ContainerInterface;
+use Monolog\Formatter\LineFormatter;
+use Monolog\Handler\RotatingFileHandler;
+use Monolog\Logger;
+use Webmozart\Assert\Assert;
+use Zend\ServiceManager\Factory\FactoryInterface;
+
+class ApiLoggingFactory implements FactoryInterface
+{
+    public function __invoke(ContainerInterface $container, $requestedName, array $options = null)
+    {
+        $config = $container->get('config');
+        Assert::keyExists($config, 'logging', "Clé 'logging' introuvable dans la config");
+
+        $loggingConfig = $config['logging'];
+        Assert::keyExists($loggingConfig, 'enabled', "Clé 'enabled' introuvable dans la config 'logging'");
+        Assert::keyExists($loggingConfig, 'params', "Clé 'params' introuvable dans la config 'logging'");
+
+        $enabled = $loggingConfig['enabled'];
+        $params = $loggingConfig['params'];
+        Assert::boolean($enabled, "La clé 'enabled' dans la config 'logging' doit être un booléen");
+        Assert::isArray($params, "Clé 'params' dans la config 'logging' doit être un tableau");
+
+        $logger = $this->createLogger($params);
+
+        $apiLogging = new ApiLogging();
+        $apiLogging->setLogger($logger);
+        $apiLogging->setEnabled($enabled);
+
+        if ($enabled) {
+            /** @var Configuration $doctrineConfiguration */
+            $doctrineConfiguration = $container->get('doctrine.configuration.orm_default');
+            $doctrineConfiguration->setSQLLogger($apiLogging);
+        }
+
+        return $apiLogging;
+    }
+
+    /**
+     * @param array $params
+     * @return Logger
+     */
+    private function createLogger(array $params)
+    {
+        Assert::keyExists($params, 'name', "Clé 'name' introuvable dans la config 'logging'");
+        Assert::keyExists($params, 'file_path', "Clé 'file_path' introuvable dans la config 'logging'");
+        Assert::keyExists($params, 'max_files', "Clé 'max_files' introuvable dans la config 'logging'");
+
+        $name = $params['name'];
+        $filePath = $params['file_path'];
+        $maxFiles = $params['max_files'];
+        Assert::integerish($maxFiles, "La clé 'max_files' doit correspondre à un entier");
+
+        $formatter = new LineFormatter();
+        $formatter->ignoreEmptyContextAndExtra(true);
+        $handler = new RotatingFileHandler($filePath, $maxFiles);
+        $handler->setFormatter($formatter);
+        $logger = new Logger($name);
+        $logger->pushHandler($handler);
+
+        return $logger;
+    }
+}
\ No newline at end of file

module/ImportData/src/Module.php

 <?php
 namespace ImportData;
 
+use Interop\Container\ContainerInterface;
+use Zend\EventManager\EventInterface;
+use Zend\ModuleManager\Feature\BootstrapListenerInterface;
+use ZF\Apigility\Application;
 use ZF\Apigility\Provider\ApigilityProviderInterface;
 
-class Module implements ApigilityProviderInterface
+class Module implements ApigilityProviderInterface, BootstrapListenerInterface
 {
     /**
      * @return array
@@ -14,4 +18,16 @@ class Module implements ApigilityProviderInterface
     {
         return include __DIR__ . '/../config/module.config.php';
     }
+
+    public function onBootstrap(EventInterface $e)
+    {
+        /** @var Application $application */
+        $application = $e->getTarget();
+        /** @var ContainerInterface $container */
+        $container = $application->getServiceManager();
+
+        /** @var ApiLogging $apiLogging */
+        $apiLogging = $container->get(ApiLogging::class);
+        $apiLogging->attach($application->getEventManager());
+    }
 }