redirectToStdout: httpRequest.latency should be a string and not an object

[jonaaasl]

Hi, not sure if this is an issue with this lib or with the nodejs-logging lib, so I'll start here.

When running the library with redirectToStdout: true in a container on GCE the httpRequest serializes the trace-property as an object:
Example:

  "httpRequest": {
    "requestUrl": "/healthcheck",
    "requestMethod": "GET",
    "userAgent": "GoogleHC/1.0",
    "responseSize": 2,
    "status": 200,
    "latency": {
      "seconds": 0,
      "nanos": 1000000
    }
  },

The stackdriver-logging-agent errors out (error message as reported here: GoogleCloudPlatform/fluent-plugin-google-cloud#433) on the httpRequest, since it expects the latency to be a string: https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/lib/fluent/plugin/out_google_cloud.rb#L1612.

Reference: https://cloud.google.com/logging/docs/reference/v2/rest/v2/LogEntry#httprequest (according to this the JSON-representation of the latency is a string, not an object).

If the latency-property on the request log is missing the stackdriver-logging-agent ingests it ok.

Environment details

• OS: cos-stable-101-17162-40-16 (with gcr.io/stackdriver-agents/stackdriver-logging-agent:1.9.8
  and gem 'fluent-plugin-google-cloud' version '0.12.7')
• Node.js version: v18.15.0
• npm version: 9.5.0
• @google-cloud/logging-bunyan version: 4.2.2

Steps to reproduce

1. Set up an express-app as documented here: https://cloud.google.com/nodejs/docs/reference/logging-bunyan/latest#using-as-an-express-middleware
2. Set the options {redirectToStdout: true} as recommended here: https://cloud.google.com/nodejs/docs/reference/logging-bunyan/latest#alternative-way-to-ingest-logs-in-google-cloud-managed-environments
3. Deploy the app in a COS-container.
4. Call the app with curl so a request-trace is printed to stdout.
5. Tail the stackdriver-logging-agent logs - there will be error-logs in the logs due to the latency not being a string.
6. Inspect the cloud-logging console for the sent messages. The messages containing the latency-property will not be parsed but passed inside the jsonPayload with the trace-property removed to the logging. Messages not containing a trace-property will be parsed properly by the stackdriver-logging-agent.

[losalex]

Thanks @jonaaasl for opening this issue. I believe documentation is a bit confusing, since on the same page it indicates that latency is actually a string in Duration format.
So I believe that the issue needs to be fixed in stackdriver-logging-agent - please let me know if you have any more concerns or questions.

[jonaaasl]

I'll try to clarify: The latency is a string according to the spec in the Duration format (example 3.5s). The stackdriver expects it correctly to be a string, but it's now written to stdout as an object (example "latency":{"seconds":0,"nanos":11000000}}.

From what I can tell the httpRequest is written to stdout here: https://github.com/googleapis/nodejs-logging-bunyan/blob/main/src/middleware/express.ts#L107

And created in the nodejs-logging here: https://github.com/googleapis/nodejs-logging/blob/main/src/utils/http-request.ts#L100

Somewhere between the creation and the writing it needs to be turned into that Duration when writing to stdout.

[losalex]

We cannot use latency as a single string (e.g. 3.5s) in our code since Duration is a protobuf structure expected by Cloud Logging service. We could perhaps add a configuration to support single string Duration, but apparently such fix is not going to be a priority. As I mentioned earlier, I believe that the fix should be done in stackdriver-logging-agent (so it can handle all supported formats properly).