Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Trace Context for GoogleCloudLoggingFormatter #1877

Open
wants to merge 1 commit into
base: main
Choose a base branch
from

Conversation

iamacarpet
Copy link

Add Cloud Trace context to log entries formatted with GoogleCloudLoggingFormatter.

This allows log entries to be grouped with the HTTP request that generated them in GCP's Log Explorer:

Screenshot 2024-03-28 7 20 16 PM

@sl0wik @sonnysasaka - two big users of PHP on GCP, RFC please.

@iamacarpet iamacarpet force-pushed the feature/gcp-trace-id branch from 8134a04 to 5efa13b Compare April 2, 2024 10:28
@sonnysasaka
Copy link

Not sure if we need this support directly at monolog level, but I've been able to use https://github.com/googleapis/google-cloud-php-logging, which is a PSR logger which is supported as a "Handler" by monolog, e.g. in this laravel snippet:

<?php
namespace App\Logging;

use Google\Cloud\Logging\LoggingClient;
use Monolog\Logger;
use Monolog\Handler\PsrHandler;

class CreateGcpLogger
{
    /**
     * Create a custom Monolog instance.
     *
     * @param  array<string>  $config
     * @return \Monolog\Logger
     */
    public function __invoke(array $config)
    {
        $loggingClient = new LoggingClient([
            'projectId' => env('GOOGLE_PROJECT_ID'),
        ]);

        $logger = $loggingClient->psrLogger('app', [
            'batchEnabled' => true,
        ]);

        return new Logger('gcp', [new PsrHandler($logger)]);
    }
}

And this already includes the trace id to each log entry: https://github.com/googleapis/google-cloud-php-core/blob/686ffd0bb1328cd2ee963c4444e2ab4b111ba3ba/src/Report/GAEMetadataProvider.php#L39

This works out of the box for app engine. For cloud run you might want to look at CloudRunMetadataProvider: https://github.com/googleapis/google-cloud-php-core/blob/686ffd0bb1328cd2ee963c4444e2ab4b111ba3ba/src/Report/CloudRunMetadataProvider.php

So this could be an alternative, if monolog prefers to stay agnostic towards formatting and let other modules define their own format to be used by monolog.

@iamacarpet
Copy link
Author

Thanks @sonnysasaka ,

This came about from a conversation with @sl0wik who said his Firevel project was using this:

LOG_CHANNEL: stderr
LOG_STDERR_FORMATTER: Monolog\Formatter\GoogleCloudLoggingFormatter

in the environmental configuration for Laravel on App Engine Standard.

This method of logging more closely matches what is desirable in a containerised environment (logging via stdout/stderr) and works on PHP 7.4+ thanks to the PHP-FPM configuration option:

decorate_workers_output = no

Although I was concerned he & his users were missing out on logs being tagged together against the request that generated them, which our developers consistently say is their favourite developer friendly feature of GCP.

I believe that Google\Cloud\Logging\LoggingClient works by submitting to the Logs API endpoint directly, sped up by the Batch Daemon, which is only available on App Engine Flexible.

Using the stderr logging method along with this formatter allows for something that works across App Engine Standard, App Engine Flexible, Cloud Run, GKE and (potentially) GCE, without any latency associated with calling the Logs API directly.

Personally, we have our own log formatter as part of our GaeSupportLaravel package, however, adding the required stuff into here (since exists anyway) will hopefully bring this functionality to more people.

@sonnysasaka
Copy link

Thanks for providing more context. With that, I think it makes sense for the google cloud formatter to live in monolog repo itself. I don't have a particular concern with the code except one small suggestion inline in the patch.

}

if (class_exists('\Google\Cloud\Core\Compute\Metadata')) {
return (new \Google\Cloud\Core\Compute\Metadata())->getProjectId();

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

also, it looks like the implementation of Google\Cloud\Core\Compute\Metadata::getProjectId() does not do caching, so maybe it's better to retrieve the project id just once at the constructor of this GoogleCloudLoggingFormatter as not to incur HTTP round trip every time there is a new log entry to format.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

You'll hopefully see further up, we set the static property $this->traceID and once set, we always return that static value.

The project ID is only retrieved to construct that value the single time it is constructed, so hopefully this is already accounted for.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Caching $this->traceID may be fine if it's guaranteed that GoogleCloudLoggingFormatter is always created new for each request. I think this is the case with PHP app with nginx + php-fpm but may not be the case with other kind of deployment (like with Laravel Octane where objects are created just once when the app starts and reused across multiple requests).

I am not familiar enough with monolog + octane to confidently say whether Octane reuses the formatter object across different requests, but to be safe I would not cache the trace id but only the project id.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah it's probably safer not to cache, as retrieving the trace id doesn't seem that expensive.

Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

And I would definitely not cache this as a static property. Cache on an instance property then a new instance would at least refetch from a clean state. Static property will definitely cause issues in some envs.

@iamacarpet iamacarpet force-pushed the feature/gcp-trace-id branch from 5efa13b to a0b5b3c Compare April 3, 2024 16:42
@iamacarpet iamacarpet force-pushed the feature/gcp-trace-id branch from a0b5b3c to 05ae45f Compare April 3, 2024 16:44
@@ -32,9 +36,49 @@ protected function normalizeRecord(LogRecord $record): array
$normalized['severity'] = $normalized['level_name'];
$normalized['time'] = $record->datetime->format(DateTimeInterface::RFC3339_EXTENDED);

// Tag with Trace ID for request attribution
$normalized['logging.googleapis.com/trace'] = $this->getTraceID();
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should this really be set at all if getTraceID returns null?

return $_SERVER['GOOGLE_CLOUD_PROJECT'];
}

if (class_exists('\Google\Cloud\Core\Compute\Metadata')) {
Copy link
Owner

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggested change
if (class_exists('\Google\Cloud\Core\Compute\Metadata')) {
if (class_exists('Google\Cloud\Core\Compute\Metadata')) {

@Seldaek Seldaek added this to the 3.x milestone Apr 12, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants