Improve Client Logging

CHANGELOG.md

@@ -10,6 +10,7 @@ All notable changes to this project will be documented in this file based on the
 ### Added
 
 ### Improvements
+- Elastica\Client constructor now accepts a LoggerInterface and will log both successful and failed requests. #1069
 
 ### Deprecated
 

lib/Elastica/Client.php

@@ -5,9 +5,9 @@
 use Elastica\Bulk\Action;
 use Elastica\Exception\ConnectionException;
 use Elastica\Exception\InvalidException;
-use Elastica\Exception\RuntimeException;
 use Elastica\Script\AbstractScript;
 use Psr\Log\LoggerInterface;
+use Psr\Log\NullLogger;
 
 /**
  * Client to connect the the elasticsearch server.
@@ -46,7 +46,7 @@ class Client
     /**
      * @var callback
      */
-    protected $_callback = null;
+    protected $_callback;
 
     /**
      * @var \Elastica\Request
@@ -61,22 +61,30 @@ class Client
     /**
      * @var LoggerInterface
      */
-    protected $_logger = null;
+    protected $_logger;
+
     /**
      * @var Connection\ConnectionPool
      */
-    protected $_connectionPool = null;
+    protected $_connectionPool;
 
     /**
      * Creates a new Elastica client.
      *
-     * @param array    $config   OPTIONAL Additional config options
+     * @param array $config OPTIONAL Additional config options
      * @param callback $callback OPTIONAL Callback function which can be used to be notified about errors (for example connection down)
+     * @param LoggerInterface $logger
      */
-    public function __construct(array $config = array(), $callback = null)
+    public function __construct(array $config = array(), $callback = null, LoggerInterface $logger = null)
     {
-        $this->setConfig($config);
         $this->_callback = $callback;
+
+        if (!$logger && isset($config['log']) && $config['log']) {
+            $logger = new Log($config['log']);
+        }
+        $this->_logger = $logger ?: new NullLogger();
+
+        $this->setConfig($config);
         $this->_initConnections();
     }
 
@@ -614,32 +622,39 @@ public function bulk(array $params)
      *
      * @throws Exception\ConnectionException|\Exception
      *
-     * @return \Elastica\Response Response object
+     * @return Response Response object
      */
     public function request($path, $method = Request::GET, $data = array(), array $query = array())
     {
         $connection = $this->getConnection();
-        try {
-            $request = new Request($path, $method, $data, $query, $connection);
-
-            $this->_log($request);
-
-            $response = $request->send();
-
-            $this->_lastRequest = $request;
-            $this->_lastResponse = $response;
+        $request = $this->_lastRequest = new Request($path, $method, $data, $query, $connection);
 
-            return $response;
+        try {
+            $response = $this->_lastResponse = $request->send();
         } catch (ConnectionException $e) {
             $this->_connectionPool->onFail($connection, $e, $this);
 
+            $this->_logger->error('Elastica Request Failure', [
+                'exception' => $e,
+                'request' => $request->toArray(),
+                'retry' => $this->hasConnection()
+            ]);
+
             // In case there is no valid connection left, throw exception which caused the disabling of the connection.
             if (!$this->hasConnection()) {
                 throw $e;
             }
 
             return $this->request($path, $method, $data, $query);
         }
+
+        $this->_logger->debug('Elastica Request', [
+            'request' => $request->toArray(),
+            'response' => $response->getData(),
+            'responseStatus' => $response->getStatus()
+        ]);
+
+        return $response;
     }
 
     /**
@@ -669,48 +684,23 @@ public function refreshAll()
     }
 
     /**
-     * logging.
-     *
-     * @param string|\Elastica\Request $context
-     *
-     * @throws Exception\RuntimeException
-     */
-    protected function _log($context)
-    {
-        $log = $this->getConfig('log');
-        if ($log && !class_exists('Psr\Log\AbstractLogger')) {
-            throw new RuntimeException('Class Psr\Log\AbstractLogger not found');
-        } elseif (!$this->_logger && $log) {
-            $this->setLogger(new Log($this->getConfig('log')));
-        }
-        if ($this->_logger) {
-            if ($context instanceof Request) {
-                $data = $context->toArray();
-            } else {
-                $data = array('message' => $context);
-            }
-            $this->_logger->debug('logging Request', $data);
-        }
-    }
-
-    /**
-     * @return \Elastica\Request
+     * @return Request
      */
     public function getLastRequest()
     {
         return $this->_lastRequest;
     }
 
     /**
-     * @return \Elastica\Response
+     * @return Response
      */
     public function getLastResponse()
     {
         return $this->_lastResponse;
     }
 
     /**
-     * set Logger.
+     * Replace the existing logger.
      *
      * @param LoggerInterface $logger
      *

test/lib/Elastica/Test/Base.php

@@ -5,6 +5,7 @@
 use Elastica\Client;
 use Elastica\Connection;
 use Elastica\Index;
+use Psr\Log\LoggerInterface;
 
 class Base extends \PHPUnit_Framework_TestCase
 {
@@ -54,12 +55,13 @@ protected function finishCollectErrors()
     }
 
     /**
-     * @param array    $params   Additional configuration params. Host and Port are already set
+     * @param array $params Additional configuration params. Host and Port are already set
      * @param callback $callback
+     * @param LoggerInterface $logger
      *
      * @return Client
      */
-    protected function _getClient(array $params = array(), $callback = null)
+    protected function _getClient(array $params = array(), $callback = null, LoggerInterface $logger = null)
     {
         $config = array(
             'host' => $this->_getHost(),
@@ -68,7 +70,7 @@ protected function _getClient(array $params = array(), $callback = null)
 
         $config = array_merge($config, $params);
 
-        return new Client($config, $callback);
+        return new Client($config, $callback, $logger);
     }
 
     /**

test/lib/Elastica/Test/ClientTest.php

@@ -1172,4 +1172,52 @@ public function testPassBigIntSettingsToConnectionConfig()
 
         $this->assertTrue($client->getConnection()->getConfig('bigintConversion'));
     }
+
+    /**
+     * @group functional
+     */
+    public function testLogger()
+    {
+        $logger = $this->getMock('Psr\\Log\\LoggerInterface');
+        $client = $this->_getClient([], null, $logger);
+
+        $logger->expects($this->once())
+            ->method('debug')
+            ->with(
+                'Elastica Request',
+                $this->logicalAnd(
+                    $this->arrayHasKey('request'),
+                    $this->arrayHasKey('response'),
+                    $this->arrayHasKey('responseStatus')
+                )
+            );
+
+        $client->request('_stats', Request::GET);
+    }
+
+    /**
+     * @expectedException \Elastica\Exception\Connection\HttpException
+     * @group functional
+     */
+    public function testLoggerOnFailure()
+    {
+        $logger = $this->getMock('Psr\\Log\\LoggerInterface');
+        $client = $this->_getClient(array('connections' => array(
+            array('host' => $this->_getHost(), 'port' => 9201),
+        )), null, $logger);
+
+        $logger->expects($this->once())
+            ->method('error')
+            ->with(
+                'Elastica Request Failure',
+                $this->logicalAnd(
+                    $this->arrayHasKey('exception'),
+                    $this->arrayHasKey('request'),
+                    $this->arrayHasKey('retry'),
+                    $this->logicalNot($this->arrayHasKey('response'))
+                )
+            );
+
+        $client->request('_stats', Request::GET);
+    }
 }