context.log({ object: 42}) does not stringify object before logging

[sedot42]

Hi! I really like Azure Functions for Node.js, but recently encountered an issue that causes imo unnecessary work. Please excuse me if this is the wrong repo to file this issue.

Repro steps

module.exports = async function (context) {
    context.log({foo: "bar", 1: 42});
    context.done();
}

Expected behavior

Logging an object should write a stringified JSON to the logs, because otherwise parsing this information in e.g. Application Insights requires transforming the log message to proper JSON.

It should look like this in the console:

[2022-05-24T13:37:52.421Z] {"1":42,"foo":"bar"}

And the message property in ApplicationInsights should be '{"1":42,"foo":"bar"}'

Actual behavior

Console log: [2022-05-24T13:35:48.326Z] { '1': 42, foo: 'bar' }

message property in ApplicationInsights: "{ '1': 42, foo: 'bar' }"

Known workarounds

There are two workarounds:

1. Send proper JSON to ApplicationInsights by logging objects via JSON.stringify().
2. Transform the logged string with something like KQL replace_regex(replace_regex(message, @"'", @'"'), @'([\w]+):', @'"\1":')

While you can argue that developers should do 1., I argue that it is more intuitive to JSON.stringify() objects by default, thus not letting devs step into this trap.

[ejizba]

It looks like we use util.format to turn the arguments into a string, which is the same behavior you would see using console.log (with or without Azure Functions). My gut says to leave this as-is to maintain consistency and because ultimately I don't see a clear right or wrong answer.

That being said, we recently added a feature called invocation hooks, which should make it easier to pick your preference and adjust the behavior for your whole app in one go. Specifically, you could do something like this:

import { registerHook } from '@azure/functions-core';

registerHook('preInvocation', (context) => {
    function stringifyArgs(...args: any[]): any[] {
        return args.map((a) => (typeof a === 'object' ? JSON.stringify(a) : a));
    }

    const oldLogger = context.invocationContext.log;
    context.invocationContext.log = Object.assign((...args: any[]) => oldLogger(...stringifyArgs(...args)), {
        error: (...args: any[]) => oldLogger.error(...stringifyArgs(...args)),
        warn: (...args: any[]) => oldLogger.warn(...stringifyArgs(...args)),
        info: (...args: any[]) => oldLogger.info(...stringifyArgs(...args)),
        verbose: (...args: any[]) => oldLogger.verbose(...stringifyArgs(...args)),
    });
});

If you want more details let me know, because this feature is still rolling out in Azure and we have not published a types package for "@azure/functions-core" yet.

[sedot42]

Interesting. I see the main downside of changing the default behaviour in potentially breaking implementations that rely on parsing this malformed JSON. Thanks for your suggestion on how to change this behaviour with invocation hooks. I consider using this in the future. Have a good day!

[ejizba]

Discussed with the team and we're going to close this as won't fix because we're consistent with the default console.log behavior in Node.js. Thanks for the suggestion, though!