Add microsecond precision to quickstart logs (#401)

Author: aabmass

samples/instrumentation-quickstart/app.py

@@ -58,6 +58,7 @@ def multi():
 def single():
     """Handle an http request by sleeping for 100-200 ms, and write the number of seconds slept as the response."""
     duration = uniform(0.1, 0.2)
+    logger.info("handle /single request", extra={"duration": duration})
     time.sleep(duration)
     return f"slept {duration} seconds"
 

samples/instrumentation-quickstart/gcp_logging.py

@@ -13,17 +13,30 @@
 # limitations under the License.
 
 import logging
+from datetime import datetime
+from typing import Optional
 
 from opentelemetry.instrumentation.logging import LoggingInstrumentor
 from pythonjsonlogger import jsonlogger
 
 
+# We override JsonFormatter.formatTime() instead of using the datefmt strftime parameter
+# because it does not support microsecond precision.
+
+
 # [START opentelemetry_instrumentation_setup_logging]
+class JsonFormatter(jsonlogger.JsonFormatter):
+    def formatTime(self, record: logging.LogRecord, datefmt: Optional[str] = None):
+        # Format the timestamp as RFC 3339 with microsecond precision
+        isoformat = datetime.fromtimestamp(record.created).isoformat()
+        return f"{isoformat}Z"
+
+
 def setup_structured_logging() -> None:
     LoggingInstrumentor().instrument()
 
     log_handler = logging.StreamHandler()
-    formatter = jsonlogger.JsonFormatter(
+    formatter = JsonFormatter(
         "%(asctime)s %(levelname)s %(message)s %(otelTraceID)s %(otelSpanID)s %(otelTraceSampled)s",
         rename_fields={
             "levelname": "severity",
@@ -32,7 +45,6 @@ def setup_structured_logging() -> None:
             "otelSpanID": "logging.googleapis.com/spanId",
             "otelTraceSampled": "logging.googleapis.com/trace_sampled",
         },
-        datefmt="%Y-%m-%dT%H:%M:%SZ",
     )
     log_handler.setFormatter(formatter)
     logging.basicConfig(