Bunyan logger problems about applicationinsights-node.js HOT 9 OPEN

Regarding the issue with "flattened" traces. Can you share your call to the Bunyan logger creating that record? The logs you're comparing between 2.X and 3.0.1 don't appear to be the same, so I'm trying to understand what the original structures look like so I can better understand what behavior you're expecting.

Regarding your second issue with errors, I'm not able to reproduce your issue with not seeing Bunyan error logging. The Telemetry type should be trace if it's coming from Bunyan, but with a severity level of "Error". An example trace from my testing:
.

If you're not able to find these error logs, please share what your Bunyan error log calls in your code look like. I'm happy to test them and take a look. Thanks!

from applicationinsights-node.js.

@JacksonWeber Sure!

Here is where we create the logger...

import * as Logger from 'bunyan';

...

let logStreams = [];

if (process.env.enable_log_file === 'true') {
    logStreams.push({
        type: 'rotating-file',
        period: '1d',
        count: 10,
        path: `evolved${process.pid}.log`,
        level: process.env.log_level
    });
}

logStreams.push({
    stream: process.stderr,
    level: process.env.log_level
});

this.log = Logger.createLogger(<Logger.LoggerOptions>{
    name: 'EVolvED',
    streams: logStreams
});

Here is an example of an "info" level call...

this.log.info(
    `Retrieved ${options.length} CPOE order text options for site ${req.params.siteId} with configuration ${req.params.type}`
);

Here is an example of an "error" level call...

this.log.error(
    err,
    `Error finding encounter ${req.params.encounterId} or site ${req.params.siteId} to get encounter with export criteria`
);

from applicationinsights-node.js.

@skhilliard Thank you for following up. Regarding the changes in Bunyan trace logging, I understand the changes you're referring to now. As a part of our move to OpenTelemetry we also moved away from our previous diagnostic-channel usage to an OpenTelemetry offering for tracking Bunyan, which explains why some fields are not identical here. Does this new data formatting break implementations on your end?

I also tested your error implementation, and I'm still seeing the logs being produced from these logging calls. The contained error object is not serialized correctly (this has just been fixed in the exporter and will roll out with the next release), but I'm not seeing issues with generation from the SDK. Are you seeing no traces with severityLevel: 3?

from applicationinsights-node.js.

@JacksonWeber We do have some alerts and other queries that count on the structure of the messages field, so it'd be ideal if it was the same rather than "flattened" as a string.

I do have some traces with severity level of 3 but only when I'm not passing in an error object. E.g. this.log.error('this is an error') vs. this.log.error(err, 'The err here is an Error object')

from applicationinsights-node.js.

@skhilliard I don't know that the message field is really "flattened" so much as it just reports the Bunyan's message field as the message attribute in Azure Monitor. For example, if I log a stringified object as Bunyan's message, I get:

so it should still be possible to log any necessary data in objects as a part of your message field.

I've tested further and haven't been able to find any type of object/data I can pass to the log.error() to cause it to not create an output in the traces table. Do you have an example of an error you're using there so I can test with the exact same data?

from applicationinsights-node.js.

@JacksonWeber Thanks for delving into this! For my testing of the error condition, I just intentionally threw an error using an Error object like this:

let error = new Error('fakeError')
this.log.error(error, 'This is a fake error');

Kelly

from applicationinsights-node.js.

@JacksonWeber Any updates for this? Thanks!

from applicationinsights-node.js.

@skhilliard Apologies for the delay. I tested your above error with the following code:

let error = new Error('fakeError')

async function setupRoutes() {
    app.get('/', async (req, res) => {
        try {
            bunyanLog.error(
                error,
                `Error finding encounter`
            );
        } catch (error) {
            console.error(error);
        }
        res.send("Hello World!");
    });
}

setupRoutes().then(() => {
    app.listen(PORT);
    console.log(`Listening on http://localhost:${PORT}`);
});

And I get a resultant trace that looks like this:

Are you ensuring that the test you're using gives ample time to the SDK to export the error logs? If you want to make sure, you can await flush() on the default telemetry client.
I'm also using ApplicationInsights 3.1.0 for the above example.

from applicationinsights-node.js.

@JacksonWeber Yeah....I am sure we were giving enough time for the logs to export. What version of bunyan are you using? We are using...

    "bunyan": "^1.8.15",
    "bunyan-middleware": "^1.0.2",

from applicationinsights-node.js.