Skip to content

Callback is not invoked upon serialization failure #275

@losalex

Description

@losalex

As raised in 732, there is a problem with handling invalid payload in client-interceptors.ts:

  1. When latency contains a Duration as string (e.g. "1s"), the following failure occurs: google.logging.type.HttpRequest.latency: object expected
  2. After the failure occurs, provided callback is called only after all retries are exhausted (e.g. error: GoogleError: Exceeded maximum number of retries before any response was received).

Given a fact that the error is permanent and that payload never sent over network due to invalid encoding, the retries should never occur and original encoding error should be sent to callback so caller would see the issue with encoding immediately.
Here is a problematic payload used to reproduce the problem:

{
    "logName": "projects/startup-project-328121/logs/winston_log",
    "entries": [
        {
            "timestamp": {
                "seconds": 1666296002,
                "nanos": 576999902
            },
            "httpRequest": {
                "requestMethod": "GET",
                "requestUrl": "http://some-url.com",
                "status": 200,
                "latency": "1s"
            },
            "insertId": "..........9SD68uY6p5Qc1Z0ytHZMsB",
            "severity": "INFO",
            "jsonPayload": {
                "fields": {
                    "message": {
                        "stringValue": "Fake request"
                    },
                    "metadata": {
                        "structValue": {
                            "fields": {}
                        }
                    }
                }
            }
        },
        {
            "timestamp": {
                "seconds": 1666296002,
                "nanos": 576999902
            },
            "insertId": "..........5SD68uY6p5Qc1Z0ytHZMsB",
            "severity": "INFO",
            "jsonPayload": {
                "fields": {
                    "logging.googleapis.com/diagnostic": {
                        "structValue": {
                            "fields": {
                                "instrumentation_source": {
                                    "listValue": {
                                        "values": [
                                            {
                                                "structValue": {
                                                    "fields": {
                                                        "name": {
                                                            "stringValue": "nodejs"
                                                        },
                                                        "version": {
                                                            "stringValue": "10.1.11"
                                                        }
                                                    }
                                                }
                                            },
                                            {
                                                "structValue": {
                                                    "fields": {
                                                        "name": {
                                                            "stringValue": "nodejs-winston"
                                                        },
                                                        "version": {
                                                            "stringValue": "5.1.6"
                                                        }
                                                    }
                                                }
                                            }
                                        ]
                                    }
                                }
                            }
                        }
                    }
                }
            }
        }
    ],
    "resource": {
        "type": "global"
    },
    "partialSuccess": true
}

The following code snippet is used to repro a problem:

const winston = require('winston');
const { LoggingWinston } = require('@google-cloud/logging-winston');

const logger = winston.createLogger({
  level: 'info',
  format: winston.format.json(),
  transports: [
    new winston.transports.Console(),
    new LoggingWinston({
      projectId: "projectId",
      keyFilename: 'key.json',
      //inspectMetadata: true,
      maxRetries: 1,
      defaultCallback: (error: any, apiResponse: any) => {
        console.debug('defaultCallback called', {
          error,
          apiResponse,
        });
      },
    })
  ]
});

logger.info('Fake request 2', {
  httpRequest: {
    requestMethod: 'GET',
    requestUrl: 'http://some-url.com',
    status: 200,
    latency: "1s", // Latency in wrong format on purpose so that send fails
    // Uncomment following code to make latency working as expected
    // latency: {
    //   seconds: 1,
    //   nanos: 0
    // }
  }
});

setTimeout(() => {
  console.log('done');
}, 
6000);

Metadata

Metadata

Assignees

No one assigned

    Labels

    priority: p2Moderately-important priority. Fix may not be included in next release.type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions