Skip to content

Functions Framework v3.4.0 breaks logging in Firebase projects #617

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Closed
lox opened this issue Jul 7, 2024 · 9 comments · Fixed by #620
Closed

Functions Framework v3.4.0 breaks logging in Firebase projects #617

lox opened this issue Jul 7, 2024 · 9 comments · Fixed by #620

Comments

@lox
Copy link

lox commented Jul 7, 2024

See firebase/firebase-functions#1580

Full reproduction at https://github.com/patientnotes/gcp-case-52054407

@jrmfg jrmfg closed this as completed in #620 Jul 9, 2024
jrmfg added a commit that referenced this issue Jul 9, 2024
`firebase-functions/logger` writes structured logs to stdout and stderr by default, and makes these pretty with ANSI color codes.

When functions-framework intercepts these messages to assign execution IDs, it handles them incorrectly in two ways.

First, when the log emitted on stdout or stderr is already a structured log, we override (ignore) the severity set by the logger. This commit avoids changing severity if it's already set.

Second, when parsing the message and attempting to determine if it's already a json object/structured log, it doesn't handle ANSI escape codes (https://en.wikipedia.org/wiki/ANSI_escape_code) used to control color, so parsing these will fail. This means that severity handling falls back to just looking at whether the message came from stdout or stderr, so debug-level and warn-level logs aren't handled correctly. This commit strips all ANSI escape codes that control terminal color. This is a minor bummer because it's a whole lot less pretty, but color-coding and smarter color coding generally seems less important than correct log-level handling.

Fixes #617.
@jrmfg jrmfg reopened this Jul 9, 2024
@jrmfg
Copy link
Contributor

jrmfg commented Jul 9, 2024

Thanks - fixed in #620 - we still need to do a release so I'll leave this open for now.

@jrmfg
Copy link
Contributor

jrmfg commented Jul 9, 2024

Tested, this works great. Going to cut the release.

@jrmfg
Copy link
Contributor

jrmfg commented Jul 9, 2024

Fixed in 3.4.1.

@jrmfg jrmfg closed this as completed Jul 9, 2024
@jesus-velasco-inditex
Copy link

jesus-velasco-inditex commented Jul 18, 2024

Good morning,

We are sill experiencing this issue in cloud functions framework (NODE) version 3.4.1. We are not using firebase, only GCP with the code below

We leave here the example that we are testing:
1
2
3

const functions = require('@google-cloud/functions-framework');

functions.http('main', (req, res) => {
  console.warn("I should be a warning in the logs")
  res.send(`Hello ${req.query.name || req.body.name || 'World'}!`);
});

Any suggestion/update?

Best regards.

@jrmfg
Copy link
Contributor

jrmfg commented Jul 18, 2024

To handle log levels correctly in log explorer, use structured logging (or the firebase logging library); all the nodejs console logging facilities are just writing a colored message to either stdout or stderr, so there's little we can do to tag logs with these APIs with the correct log level

We've never handled console.warn in cloud logging/structured logs. Before 3.4.0, this showed as a log at "default" level.
After 3.4.0, this shows as an error, which is not really correct either. Neither have ever shown console.warn as a warning.

We could consider changing this to show default log levels for unstructured logs as before 3.4.0 if this is breaking you. Would you prefer that?

@jrmfg jrmfg reopened this Jul 18, 2024
@jrmfg
Copy link
Contributor

jrmfg commented Jul 18, 2024

We could also try to be clever and use the ANSI color codes at the start of the string to try to figure out if it's a warn or error, and add structured logging accordingly. might be cool, but also isn't backwards compatible.

@jesus-velasco-inditex
Copy link

jesus-velasco-inditex commented Jul 19, 2024

First of all, thanks @jrmfg for your answer, we will change to structured logs if it is not supported warn in unstructured logs .

Well, we change to structured logging using Google Library, but is there a way to put a message and extra information without put the message in a sublevel as a simple string do it?

5
4

@jrmfg
Copy link
Contributor

jrmfg commented Jul 19, 2024

but is there a way to put a message and extra information without put the message in a sublevel as a simple string do it?

I'm not sure what you mean - the code you provided looks good, what problem are you having with it?

@jrmfg
Copy link
Contributor

jrmfg commented Jul 22, 2024

rolled back the stderr change in #625; it should land in 3.4.2.

@jrmfg jrmfg closed this as completed Jul 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants