feat: add StdOutLogger and LoggingTrait #578

Hectorhammett · 2024-09-04T21:46:32Z

Add logging support to the HTTP calls for easy debugging.

src/Logging/StdOutLogger.php

bshaffer · 2024-10-22T22:45:46Z

src/ApplicationDefaultCredentials.php

 use Google\Auth\Middleware\AuthTokenMiddleware;
 use Google\Auth\Middleware\ProxyAuthTokenMiddleware;
 use Google\Auth\Subscriber\AuthTokenSubscriber;
 use GuzzleHttp\Client;
 use InvalidArgumentException;
+use PHPUnit\TextUI\XmlConfiguration\Logging\Logging;


This isn't used - we should remove it

That's (partly) the reason the CS tests are failing

https://github.com/googleapis/google-auth-library-php/actions/runs/11411641502/job/31756272056

bshaffer · 2024-10-22T22:51:05Z

src/ApplicationDefaultCredentials.php

+        if (!is_string($loggingFlag)) {
+            if (is_array($loggingFlag)) {
+                trigger_error('The ' . self::SDK_DEBUG_FLAG . ' is set, but it is set to another value than false, true, 0 or 1. Logging is disabled');
+                return null;
+            }
+
+            return null;
+        }


I'm confused by this block - there is no way for the logging flag to be an array, as that only happens if you call getenv with no arguments (see here). So the only thing this is doing is returning null when the env var isn't set, which is what we also do for 0 and false.

Why not combine this with the validation below? (see suggestion below)

I remember having a specific issue that I needed to handle but I can't quite remember what was it exactly. Although it might have been related to PHPSTAN mentioning that it can return an array? But I am unsure.

Still let me take a look in order to make it cleaner :)

bshaffer · 2024-10-22T22:58:02Z

src/HttpHandler/Guzzle6HttpHandler.php

+            $requestEvent = new LogEvent();
+
+            $requestEvent->method = $request->getMethod();
+            $requestEvent->url = $request->getUri()->__toString();


absolute nit

Suggested change

$requestEvent->url = $request->getUri()->__toString();

$requestEvent->url = (string) $request->getUri();

bshaffer · 2024-10-22T22:59:08Z

src/HttpHandler/Guzzle6HttpHandler.php

+            $responseEvent = new LogEvent($requestEvent->timestamp);
+
+            $responseEvent->headers = $response->getHeaders();
+            $responseEvent->payload = $response->getBody()->getContents();


this could potentially be huge, depending on the response - is that still what we want to do? Maybe we should have some kind of checks to only send the first # of bytes?

Yeah, there was a discussion about truncating the data for this and there is no definite conclusion, but one idea is to truncate the length and be configurable via the StdOutLogger constructor.

bshaffer · 2024-10-22T23:00:41Z

src/HttpHandler/Guzzle6HttpHandler.php

+            $requestEvent->retryAttempt = $options['retryAttempt'] ?? null;
+            $requestEvent->serviceName = $options['serviceName'] ?? null;
+            $requestEvent->clientId = spl_object_id($this->client);
+            $requestEvent->requestId = spl_object_id($request);


since this code is duplicated above, why not have private methods like logHttpRequest($request) and logHttpResponse($response, $requestEvent)?

In my mind, formatting the LogEvent and filling that data is not duty of the log function. The log function takes the generic log object and turns it into a json string to the docs specification, that's why I decided to have this code "duplicated", which in my mind is not really "duplicated" but is basically the same, mostly because one is for the response and one is for the request, and I did it this way in order to keep them separate from the logging logic.

I also thought perhaps a function to make a logEvent but voted against it as it would have to be flexible enough to acomodate the small differences between response and request but it can definitely be done.

bshaffer · 2024-10-22T23:13:46Z

src/Logging/LoggingTrait.php

+
+    /**
+     * @param array<mixed> $headers
+     * @return null|array<mixed, mixed>


we can make this a little smarter

Suggested change

* @return null|array<mixed, mixed>

* @return null|array<string, string|false>

bshaffer · 2024-10-22T23:15:52Z

src/Logging/LoggingTrait.php

+        $stringifiedEvent = json_encode($debugEvent);
+
+        // There was an error stringifying the event, return to not break execution
+        if ($stringifiedEvent === false) {


do we still want to try to log the infoEvent even if the debug event fails? for instance do this instead?

if ($stringifiedEvent !== false) { $this->logger->debug($stringifiedEvent); }

bshaffer · 2024-10-22T23:17:08Z

src/Logging/StdOutLogger.php

+     * @return int
+     * @throws InvalidArgumentException
+     */
+    private function getLevelMap(string $levelName): int


nit: to me getLevelMap would return the levelMapping variable. What if we instead called it getLevelNumber or getLevelFromName?

I like it, let me change it.

bshaffer · 2024-10-22T23:19:49Z

tests/Logging/StdOutLoggerTest.php

+        $this->assertEquals($expectedString . "\n", $buffer);
+
+        ob_end_clean();
+    }


Instead of usign ob_start and ob_end_clean, use expectOutputString. See https://docs.phpunit.de/en/10.5/writing-tests-for-phpunit.html#testing-output for more info

bshaffer · 2024-10-22T23:22:21Z

src/ApplicationDefaultCredentials.php

+        // Env Var is not true
+        if ($loggingFlag !== 'true' && $loggingFlag !== '1') {
+            // Env var is set to a non valid value
+            if ($loggingFlag !== 'false' && $loggingFlag !== '0') {
+                trigger_error('The ' . self::SDK_DEBUG_FLAG . ' is set, but it is set to another value than false, true, 0 or 1. Logging is disabled');
+            }
+
+            return null;
+        }
+
+        return new StdOutLogger();


Having lots of !== is a bit hard to read. What about something like this?

NOTE: You may want to handle the case of empty string (e.g. someone sets GOOGLE_SDK_DEBUG_LOGGING= in their environment) to have the same behavior, which is why I included the empty string in the array.

Suggested change

// Env Var is not true

if ($loggingFlag !== 'true' && $loggingFlag !== '1') {

// Env var is set to a non valid value

if ($loggingFlag !== 'false' && $loggingFlag !== '0') {

trigger_error('The ' . self::SDK_DEBUG_FLAG . ' is set, but it is set to another value than false, true, 0 or 1. Logging is disabled');

}

return null;

}

return new StdOutLogger();

// Env Var is true

if ($loggingFlag === 'true' || $loggingFlag === '1') {

return StdOutLogger();

}

// Env Var is false or not specified

if (in_array($loggingFlag, [null, '', 'false', '0'], true)) {

return null;

}

// Env var is set to a non valid value

trigger_error('The ' . self::SDK_DEBUG_FLAG . ' is set, but it is set to another value than false, true, 0 or 1. Logging is disabled');

// still return null because we don't want debugging to halt execution

return null;

I personally think this reads a lot cleaner

Hectorhammett requested a review from a team as a code owner September 4, 2024 21:46

Hectorhammett added 2 commits September 4, 2024 22:01

Add the StdOutLogger and Logging Trait

2416bec

Fix types and style

dbce7ca

bshaffer changed the title ~~Feat: Add the StdOutLogger and Logging Trait~~ feat: add StdOutLogger and LoggingTrait Sep 5, 2024

bshaffer reviewed Sep 5, 2024

View reviewed changes

src/Logging/StdOutLogger.php Show resolved Hide resolved

fix typing for PSR-3 logger interface

6370690

Hectorhammett force-pushed the http-logging branch from 4122fb0 to 6370690 Compare September 5, 2024 21:49

Hectorhammett added 4 commits September 9, 2024 20:02

Add logging to the Guzzle6HttpHandler

7ce3e58

Change logic for getDefaultLogger

ce1e7db

Fix style issues

ad4699b

Fix phpstan typing for getJwtToken

b952d48

Hectorhammett requested a review from bshaffer September 9, 2024 22:12

Hectorhammett mentioned this pull request Sep 11, 2024

feat: add logging to the supported transports googleapis/gax-php#585

Open

Hectorhammett added 8 commits September 13, 2024 21:06

Add a flag for disabling logger

c80bdf6

Add logging to the invoke method for apiary support

953efb7

Remove extra space

eba9861

Fix style issue on build method

975c564

Change logic for disabling logging

7e76353

Fix logic for disabling logging

ac4d686

Add a function to log a gRPC status only

b770674

Removed unused method

566c414

Hectorhammett marked this pull request as draft September 25, 2024 21:40

Hectorhammett added 5 commits September 25, 2024 21:45

Fix style for LoggingTrait

8bb61a1

Fix typing

fa851c2

Updated type annotations

600a947

Change logic for logging responses to exclude the info log

3cc71a4

Change logic for logResponse

8699369

Hectorhammett mentioned this pull request Sep 27, 2024

feat: Add documentation for the Logger option inside the options array googleapis/gapic-generator-php#731

Open

Hectorhammett added 2 commits October 8, 2024 19:21

Handle false for the case when json_encode returns false

fb0ac53

Fix serialization bug

56d3881

Add support for logger in

202890d

bshaffer reviewed Oct 22, 2024

View reviewed changes

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: add StdOutLogger and LoggingTrait #578

feat: add StdOutLogger and LoggingTrait #578

Hectorhammett commented Sep 4, 2024 •

edited

Loading

bshaffer Oct 22, 2024

bshaffer Oct 22, 2024

Hectorhammett Oct 23, 2024

bshaffer Oct 22, 2024

bshaffer Oct 22, 2024

Hectorhammett Oct 23, 2024

bshaffer Oct 22, 2024

Hectorhammett Oct 23, 2024

bshaffer Oct 22, 2024

bshaffer Oct 22, 2024

bshaffer Oct 22, 2024

Hectorhammett Oct 23, 2024

bshaffer Oct 22, 2024

bshaffer Oct 22, 2024

	$requestEvent->url = $request->getUri()->__toString();
	$requestEvent->url = (string) $request->getUri();

	* @return null\|array<mixed, mixed>
	* @return null\|array<string, string\|false>

feat: add StdOutLogger and LoggingTrait #578

Are you sure you want to change the base?

feat: add StdOutLogger and LoggingTrait #578

Conversation

Hectorhammett commented Sep 4, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Hectorhammett commented Sep 4, 2024 •

edited

Loading