Logging Error object has a difficult to read output

[shalomhalbert]

Related issues

[REQUIRED] Version info

node: 10.22.0

firebase-functions: 3.11.0

firebase-tools: 8.9.0

firebase-admin: 8.13.0

[REQUIRED] Test case

const firebaseFunctions = require('firebase-functions');
try {
     throw new Error('Message from the thrown error.');
 } catch (err) {
     firebaseFunctions.logger.error('Logged message', err);
 }

[REQUIRED] Steps to reproduce

Run the test case. For example:

const firebaseFunctions = require('firebase-functions');

it('Test', () => {
  try {
       throw new Error('Message from the thrown error.');
   } catch (err) {
       firebaseFunctions.logger.error('Logged message', err);
   }
});

[REQUIRED] Expected behavior

Something like:

{
   "severity":"ERROR",
   "message":"Logged message"
   "stack":"Error: Message from the thrown error.\n   <insert stack>"
}

[REQUIRED] Actual behavior

{
   "severity":"ERROR",
   "message":"Logged message Error: Message from the thrown error.\n   <insert stack>"
}

Were you able to successfully deploy your functions?

Yes, it deploys fine. This is about logging errors in a way that is easier to read.

The actual output isn't ideal because the the logged message ("Logged message ") is concatenated with the Error object's message ("Message from the thrown error.") and stack. It's clear this happens because Error isn't a simple object, which means the logger won't interpret it as a "jsonPayload". However, this makes reading errors more difficult. Is there a way to log errors so that the output is more like the following?

This is just the tip of the iceberg, because I'd like to create custom error classes that extends the Error class, but those print just as poorly.

[google-oss-bot]

I found a few problems with this issue:

• I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.
• This issue does not have all the information required by the template. Looks like you forgot to fill out some sections. Please update the issue with more information.

[jankalthoefer]

I have the same problem for objects I pass to the logger. So e.g. if I log the following:

import { logger } from 'firebase-functions';

const nestedObject = 
{
    layer: '1',
    next: {
        layer: '2',
        next: {
                layer: '3',   
        }
    }
};

logger.log('Simple Object:', nestedObject);

The output I get is: {"layer":"1","next":{"layer":"2","next":{"layer":"3","next":{"layer":"4"}}},"severity":"INFO","message":"Simple Object:"}

For more complex objects the output is almost unreadable.

[taeold]

Thanks for reporting the issue @shalbert94 and @jankalthoefer.

A workaround would be to wrap the error stack inside a simple object:

const functions = require('firebase-functions');
try {
     throw new Error('Message from the thrown error.');
 } catch (err) {
     functions.logger.error('Logged message', { stack: err.stack });
 }

I suspect that this isn't a satisfying answer.

FWIW, you can always use a custom logger that better fits your use case. functions.logger module exists to make logs entries emitted from Cloud Functions look good in Google's Cloud Logging, but you are absolutely freed to choose any other logging library (no guarantee that it will work w/ Cloud Logging though).

[shalomhalbert]

For anyone who'd like a potentially more complete solution, the following module is what I've come up with.

const firebaseFunctions = require('firebase-functions');

const errorToMetadata = (err) => {
    return {
        metadata: {
            ...err,
            message: err.message,
            stack: err.stack
        }
    };
};

const formatMetadata = (payload) => {
    if (payload instanceof Error) {
        return errorToMetadata(payload);
    }

    const payloadType = typeof payload;
    if (payloadType === 'object') {
        return { metadata: { ...payload } };
    }

    return { metadata: payload };
};

const info = (message, data) => {
    const formattedMetadata = formatMetadata(data);

    firebaseFunctions.logger.info(message, formattedMetadata);
};

const error = (message, data) => {
    const formattedMetadata = formatMetadata(data);

    firebaseFunctions.logger.error(message, formattedMetadata);
};

exports.info = info;
exports.error = error;

Explanation:

• formatMetadata is used for formatting all data that's passed in to ensure it is logged as a jsonPayload that is relatively easy to read.
• if (payload instanceof Error) is required because Error's message and stack properties are not enumerable. That means { ...payload } would not add those two to the cloned object.
• firebaseFunctions.logger's documentation clearly states

  If the last argument provided is a plain object, it is added to the jsonPayload in the Cloud Logging entry.

Because of the API's implementation, ES6 classes are not converted to a jsonPayload, unlike plain objects. That's where

const payloadType = typeof payload;
if (payloadType === 'object')

comes in. I couldn't find a good approach for identifying ES6 classes, as opposed to plain objects, so instead, it made sense to just clone enumerable properties of every object.

Opinions:

1. firebaseFunctions.logger.error should cleanly log an Error.
2. An ES6 class should be an acceptable jsonPayload

Edit: Replaced one solution with another I think is better

[taeold]

@shalbert94 Thanks for making the suggestions. I think that makes for a good FR. I don't think we can prioritize the work ATM, but feel free to check in with us if you have some time to contribute.

[j-frost]

I thought I was taking crazy pills. Thanks for the workaround @shalbert94 . In my case, errors would just go missing and show up as empty objects - but only sometimes. Took me quite a number of hours to find this issue.