Protobuf encoding error seems to close/terminate log stream

[yelworc]

When logging a message with some object in the payload data that cannot be serialized to protobuf, a Node.js warning is logged on the console, and no further messages are written to the Cloud Logging stream. A while later, the default callback handler is called with the following error: Error: Total timeout of API google.logging.v2.LoggingServiceV2 exceeded 60000 milliseconds before any response was received.

The prior warning looks roughly like this (with node --trace-warnings; abbreviated because the actual payload is quite big):

(node:4047859) Warning: Cannot encode protobuf.js object: {"timestamp":{"seconds":1683557843,"nanos":710999965},"severity":"INFO","insertId":"..........exorJH2vpCEe.5iuCtwcxj","jsonPayload":{…}}: TypeError: Cannot read properties of undefined (reading 'nullValue')
    at warn (node_modules/google-gax/build/src/warnings.js:37:17)
    at BundleDescriptor.getByteLength [as byteLengthFunction] (node_modules/google-gax/build/src/gax.js:517:33)
    at node_modules/google-gax/build/src/bundlingCalls/bundleExecutor.js:83:46
    at Array.forEach (<anonymous>)
    at BundleExecutor.schedule (node_modules/google-gax/build/src/bundlingCalls/bundleExecutor.js:82:22)
    at node_modules/google-gax/build/src/bundlingCalls/bundleApiCaller.js:43:26
    at OngoingCallPromise.call (node_modules/google-gax/build/src/call.js:67:27)
    at BundleApiCaller.call (node_modules/google-gax/build/src/bundlingCalls/bundleApiCaller.js:42:16)
    at node_modules/google-gax/build/src/createApiCall.js:84:30

So, obviously I should avoid throwing non-trivial objects into log messages, but is the behavior of the library correct/expected in this case? Specifically:

• Should it really close the stream after one such error occurs?
• Is there a way to catch/handle the warning programmatically? (in production, I wouldn't normally notice warnings printed to the console)

Intuitively, I would say the lib should probably drop individual problematic messages (and report the serialization problem via the callback handler), rather than stop working entirely. At the very least, the current error message is misleading, since it suggests some sort of networking issue.

If this is a more general issue with nodejs-logging, let me know, and I'll close this one and reopen the issue over there.

Environment details

• OS: Heroku (yeah, not an OS, but close enough :laughing:)
• Node.js version: v18.12.1
• npm version: 8.19.2
• @google-cloud/logging-bunyan version: 4.2.2

Steps to reproduce

The specific object that causes an error when serializing to protobuf is a Moment.js instance, i.e. something like this should reproduce the problem:

const moment = require('moment');
// …
logger.info({ now: moment() }, 'hello');

[cindy-peng]

Hi @yelworc , I tried to repro the issue but no luck. Which version of Moment.js package were you using? Also, I am wondering were you able to add default callback in the logger for error handling? https://github.com/googleapis/nodejs-logging-bunyan#error-handling-with-a-default-callback

[yelworc]

@cindy-peng thanks for looking into this!

I'm afraid I cannot reproduce this anymore, either; not even after rolling back to the code state around the time of reporting (the moment.js version was and still is 2.29.4). Maybe I misdiagnosed the cause 🤔

Either way, feel free to close the issue – I'll reopen if I come across it again.

[cindy-peng]

Sounds good. Thanks @yelworc! I am closing this for now but feel free to reopen it if this happens again. 😊