googleapis / nodejs-logging-winston

Node.js client integration between Stackdriver Logging and Winston.
https://cloud.google.com/logging/
Apache License 2.0
105 stars 50 forks source link

inconsistent `logName` behaviour with `redirectToStdout` #744

Closed leoschweizer closed 1 year ago

leoschweizer commented 1 year ago

When using the redirectToStdout option (on Google Cloud Functions), the created jsonPayload log field has a logName field which contains a string with the winston_log log name, but improperly interpolated Google project id. The log also contains a root level logName which is set to "cloud functions".

So either this should properly result in winston_log being the log name or the log name field in the jsonPayload should not be present at all? In any case the uninterpolated {{projectId}} in the output looks wrong.

Environment details

Steps to reproduce

import * as winston from 'winston'
import { LoggingWinston } from '@google-cloud/logging-winston'

const loggingTransport = new LoggingWinston({
    redirectToStdout: true,
    useMessageField: false,
})

const logger = winston.createLogger({
    level: 'debug',
    transports: [loggingTransport],
})

logger.info('execute', { ...metaData })

results in the following output:

Screenshot 2022-09-28 at 13 15 33
losalex commented 1 year ago

Thanks @leoschweizer for reaching out! When running in serverless environments like Cloud Functions (CF), the logName field is always overriden by the environment when stdout-based output is used. See more explanation in Structured logging in Google Cloud blog under How to write logs section. I filed an issue with CF team to provide an ability to override the logName, so for now we embedding this into jsonPayload field so it could be searched at least. Regarding missing projectId - I believe you could set desired project ID explicitly like in example below:

const loggingWinston = new LoggingWinston({
  projectId: 'my-project-id-goes-here',
  redirectToStdout: true,
  useMessageField: false,
});

Please let me know if you have any more questions.

leoschweizer commented 1 year ago

Hi @losalex ,

thanks for the explanation. The two logNames being present just didn't appear to be intentional, but now I understand that it is.

Regarding the projectId, I can confirm that this is fixed by setting it explicitly. However I want to note that this is also a bit unexpected. I'm using a lot of GCP client libraries and this never has to be done if the code is anyways running in the exact same project. And this is btw true including this very library, as long as you are not setting redirectToStdout to true. So just my 2ct but would be nice if this weren't needed 😉

losalex commented 1 year ago

Thank you @leoschweizer - indeed, the inconsistency here should be fixed, will take a look on it. Thanks!

macrozone commented 1 year ago

i also fell into this, log_name appears twice and adds noise to the log, even worse, its the only thing you see if you don't expand the logs:

Bildschirm­foto 2023-02-28 um 14 57 55

@losalex @leoschweizer This needs to be reopened, I think.

setting projectId explicitly is surely the wrong solution here: we run it in google cloud environments, so the projectId is always known and if users need to specify it, it will be wrong sooner or later.

I even think its better to create structured logs ourself, instead of using this library here, since it adds a lot of magic that is not required for running under google services