Merge pull request #35 from cego/lejo/add-truncation-of-body-and-fix-exception

Lejo/add truncation of body and fix exception

Author: LauJosefsen

publishable/config/request-log.php

@@ -14,6 +14,8 @@
 
     'enabled' => env('REQUEST_LOG_ENABLED', false),
 
+    'truncateBodyLength' => env('REQUEST_LOG_TRUNCATE_BODY_LENGTH', 10000), // Truncate the length of body of request or response to maximum this size. Set to -1 to disable.
+
     /*
     | Set of headers and query parameters to redact from the log
     */

src/RequestLog/Middleware/LogRequest.php

@@ -75,6 +75,23 @@ protected function routeIsBlacklisted($request)
         return false;
     }
 
+    /**
+     * Truncate a string to a given length
+     *
+     * @param string $string
+     * @param int $length
+     *
+     * @return string
+     */
+    protected function truncate(string $string, int $length): string
+    {
+        if($length <= 0) {
+            return $string;
+        }
+
+        return mb_substr($string, 0, $length);
+    }
+
     /**
      * @param Request $request
      * @param Response $response
@@ -93,6 +110,8 @@ private function logRequest(Request $request, Response $response): void
             $responseHeaders = $response->headers->all();
             unset($responseHeaders['set-cookie']);
 
+            $truncateBodyLength = config('request-log.truncateBodyLength');
+
             (new RequestLog(
                 method: $request->method(),
                 url: $request->url(),
@@ -101,12 +120,12 @@ private function logRequest(Request $request, Response $response): void
                 queryString: SecurityUtility::getQueryWithMaskingApplied($request),
                 requestHeaders: SecurityUtility::getHeadersWithMaskingApplied($request),
                 requestCookies: SecurityUtility::getCookiesWithMaskingApplied($this->requestCookies, $request),
-                requestBody: SecurityUtility::getBodyWithMaskingApplied($request) ?: '{}',
+                requestBody: $this->truncate(SecurityUtility::getBodyWithMaskingApplied($request) ?: '{}', $truncateBodyLength),
                 status: $response->getStatusCode(),
                 responseHeaders: $responseHeaders,
                 responseCookies: SecurityUtility::getResponseCookiesWithMaskingApplied($response->headers->getCookies(), $request),
-                responseBody: $response->getContent() ?: '{}',
-                responseException: $response->exception,
+                responseBody: $this->truncate($response->getContent() ?: '{}', $truncateBodyLength),
+                responseException: $response->exception ?? null,
                 executionTimeNs: $executionTimeNs
             ))->log(Log::getLogger());
 

tests/Unit/LogRequestTest.php

@@ -3,8 +3,10 @@
 namespace Tests\Unit;
 
 use Cego\RequestLog\Services\RequestLogOptionsService;
+use Illuminate\Http\Request;
 use Illuminate\Support\Facades\Log;
 use Monolog\Logger;
+use Symfony\Component\HttpFoundation\Response;
 use Tests\TestCase;
 use Cego\RequestLog\Models\RequestLog;
 use Illuminate\Support\Facades\Config;
@@ -219,4 +221,109 @@ public function it_masks_response_cookies(): void
         // Act
         $this->post('/test', [], $headers);
     }
+
+    /** @test */
+    public function it_doesnt_crash_if_exception_on_response_doesnt_exist(): void
+    {
+        $loggerMock = $this->createMock(Logger::class);
+        Log::partialMock()->shouldReceive('getLogger')->once()->withAnyArgs()->andReturn($loggerMock);
+        Log::partialMock()->shouldNotReceive('error');
+
+
+        $middleware = new LogRequest();
+
+        $request = new Request();
+
+        $response = new Response();
+
+        $middleware->terminate($request, $response);
+    }
+
+    /** @test */
+    public function it_truncates_very_long_json_bodies(): void
+    {
+        // Set config request-log.truncateBodyLength to 100
+        Config::set('request-log.truncateBodyLength', 100);
+
+        $loggerMock = $this->createMock(Logger::class);
+        Log::partialMock()->shouldReceive('getLogger')->once()->withAnyArgs()->andReturn($loggerMock);
+
+        $loggerMock->expects($this->once())->method('debug')->with($this->stringStartsWith('Timing for'))->willReturnCallback(function ($message, $context) {
+            $this->assertEquals(100, strlen($context['http']['request']['body']['content']));
+            $this->assertEquals(100, strlen($context['http']['response']['body']['content']));
+        });
+
+
+        $middleware = new LogRequest();
+
+
+        $request = new Request();
+        // Set request body to a very long json string
+        $request->initialize([], [], [], [], [], [], json_encode(range(0, 10000)));
+
+        $response = new Response();
+        // Set response body to a very long json string
+        $response->setContent(json_encode(range(0, 10000)));
+
+        $middleware->terminate($request, $response);
+    }
+
+    /** @test */
+    public function it_doesnt_truncate_very_long_json_bodies_if_disabled(): void
+    {
+        // Set config request-log.truncateBodyLength to 100
+        Config::set('request-log.truncateBodyLength', -1);
+
+        $loggerMock = $this->createMock(Logger::class);
+        Log::partialMock()->shouldReceive('getLogger')->once()->withAnyArgs()->andReturn($loggerMock);
+
+        $loggerMock->expects($this->once())->method('debug')->with($this->stringStartsWith('Timing for'))->willReturnCallback(function ($message, $context) {
+            $this->assertEquals(48897, strlen($context['http']['request']['body']['content']));
+            $this->assertEquals(48897, strlen($context['http']['response']['body']['content']));
+        });
+
+
+        $middleware = new LogRequest();
+
+
+        $request = new Request();
+        // Set request body to a very long json string
+        $request->initialize([], [], [], [], [], [], json_encode(range(0, 10000)));
+
+        $response = new Response();
+        // Set response body to a very long json string
+        $response->setContent(json_encode(range(0, 10000)));
+
+        $middleware->terminate($request, $response);
+    }
+
+    /** @test */
+    public function it_doesnt_truncate_bodies_shorter_than_truncate_limit(): void
+    {
+        // Set config request-log.truncateBodyLength to 100
+        Config::set('request-log.truncateBodyLength', 100);
+
+        $loggerMock = $this->createMock(Logger::class);
+        Log::partialMock()->shouldReceive('getLogger')->once()->withAnyArgs()->andReturn($loggerMock);
+
+        $loggerMock->expects($this->once())->method('debug')->with($this->stringStartsWith('Timing for'))->willReturnCallback(function ($message, $context) {
+            $this->assertEquals(3, strlen($context['http']['request']['body']['content']));
+            $this->assertEquals(3, strlen($context['http']['response']['body']['content']));
+        });
+
+
+        $middleware = new LogRequest();
+
+
+        $request = new Request();
+        // Set request body to a very long json string
+        $request->initialize([], [], [], [], [], [], "hej");
+
+        $response = new Response();
+        // Set response body to a very long json string
+        $response->setContent("hej");
+
+        $middleware->terminate($request, $response);
+    }
+
 }