Allow for json fields in python logs (google#2052)

The way Error Reporting information was being added to logs was
preventing us from adding additional `json_fields` to our logs.
Changed from inserting Error Reporting information in a Log Record
Factory to a Log Filter.
See:
https://docs.python.org/3/howto/logging-cookbook.html#using-filters-to-impart-contextual-information

Also put the API logged fields back into the json data.

---------

Co-authored-by: Andrew Pollock <[email protected]>

Author: 2 people

gcp/api/server.py

@@ -130,16 +130,18 @@ def QueryAffected(self, request, context: grpc.ServicerContext):
     # Log some information about the query with structured logging
     qtype, ecosystem, versioned = query_info(request.query)
     if ecosystem is not None:
-      # TODO(michaelkedar): work out how to combine json_fields with osv/logs.py
-      import json
       logging.info(
-          'QueryAffected for %s "%s"\n%s', qtype, ecosystem,
-          json.dumps({
-              'details': {
-                  'ecosystem': ecosystem,
-                  'versioned': versioned == 'versioned'
+          'QueryAffected for %s "%s"',
+          qtype,
+          ecosystem,
+          extra={
+              'json_fields': {
+                  'details': {
+                      'ecosystem': ecosystem,
+                      'versioned': versioned == 'versioned'
+                  }
               }
-          }))
+          })
     else:
       logging.info('QueryAffected for %s', qtype)
 
@@ -217,11 +219,12 @@ def QueryAffectedBatch(self, request, context: grpc.ServicerContext):
     # Filter out empty fields
     query_details = {k: v for k, v in query_details.items() if v}
 
-    # TODO(michaelkedar): work out how to combine json_fields with osv/logs.py
-    import json
-    logging.info('QueryAffectedBatch with %d queries\n%s',
-                 len(request.query.queries),
-                 json.dumps({'details': query_details}))
+    logging.info(
+        'QueryAffectedBatch with %d queries',
+        len(request.query.queries),
+        extra={'json_fields': {
+            'details': query_details
+        }})
 
     if len(request.query.queries) > _MAX_BATCH_QUERY:
       context.abort(grpc.StatusCode.INVALID_ARGUMENT, 'Too many queries.')

osv/logs.py

@@ -17,30 +17,29 @@
 from google.cloud import logging as google_logging
 
 
-def setup_gcp_logging(service_name):
-  """Set up GCP logging and error reporting."""
+class _ErrorReportingFilter:
+  """
+  A logging filter that adds necessary JSON fields to error logs so that they
+  can be picked up by Error Reporting.
+  
+  https://cloud.google.com/error-reporting/docs/formatting-error-messages#log-text
+  https://docs.python.org/3/howto/logging-cookbook.html#using-filters-to-impart-contextual-information
+  """
 
-  logging_client = google_logging.Client()
-  logging_client.setup_logging()
+  def __init__(self, service_name: str) -> None:
+    self.service_name = service_name
 
-  old_factory = logging.getLogRecordFactory()
-
-  def record_factory(*args, **kwargs):
-    """Insert jsonPayload fields to all logs."""
-
-    record = old_factory(*args, **kwargs)
+  def filter(self, record: logging.LogRecord) -> bool:
+    """Add the error reporting fields to json_fields."""
     if not hasattr(record, 'json_fields'):
       record.json_fields = {}
 
-    # Add jsonPayload fields to logs that don't contain stack traces to enable
-    # capturing and grouping by error reporting.
-    # https://cloud.google.com/error-reporting/docs/formatting-error-messages#log-text
     if record.levelno >= logging.ERROR and not record.exc_info:
       record.json_fields.update({
           '@type':
               'type.googleapis.com/google.devtools.clouderrorreporting.v1beta1.ReportedErrorEvent',  # pylint: disable=line-too-long
           'serviceContext': {
-              'service': service_name,
+              'service': self.service_name,
           },
           'context': {
               'reportLocation': {
@@ -51,9 +50,16 @@ def record_factory(*args, **kwargs):
           },
       })
 
-    return record
+    return True
+
+
+def setup_gcp_logging(service_name):
+  """Set up GCP logging and error reporting."""
+
+  logging_client = google_logging.Client()
+  logging_client.setup_logging()
 
-  logging.setLogRecordFactory(record_factory)
+  logging.getLogger().addFilter(_ErrorReportingFilter(service_name))
   logging.getLogger().setLevel(logging.INFO)
 
   # Suppress noisy logs in some of our dependencies.