Firestore Cloud functions V2 are missing a trace in logs

[milo-]

Firestore Cloud functions V2 are missing traces in logs, which makes debugging very painful.

[REQUIRED] Version info

node: 18

firebase-functions: 4.4.1

firebase-tools: 12.4.3

firebase-admin: 11.9.0

[REQUIRED] Test case

import { logger } from "firebase-functions/v2";
export const foo = onDocumentWritten(
  {
    document: "/foo/{fooId}",
  },
  async (event) => {
    logger.info("This log should have trace. But it does not 😭");
  }
);

[REQUIRED] Steps to reproduce

Create a v2 firestore function and look at the logs in the Google Cloud Logs

[REQUIRED] Expected behavior

There should be a trace, to make debugging easier. It is a massive pain to do right now.

This is how firebase-function tasks show up in the logs. Lovely, a trace. So easy to debug! 😍

[REQUIRED] Actual behavior

This is how v2 firestore logs show up. No trace, so hard to debug 😭

Were you able to successfully deploy your functions?

Yes

[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 seem to follow the issue template. Make sure you provide all the required information.

[milo-]

Looking at the source for other v2 triggers, they wrap all the handlers using wrapTraceContext:
https://github.com/firebase/firebase-functions/blob/master/src/v2/providers/database.ts#L471

The v2 Firestore handler isn't using wrapTraceContext:
https://github.com/firebase/firebase-functions/blob/master/src/v2/providers/firestore.ts#L448

[ciriousjoker]

It might be worth adding that when importing v1 stuff into a v2 function (e.g. the old config(), which no longer works), the error messages produced by the v1 stuff aren't tagged with a trace.

I assume this is working as intended.

[fgatti675]

Hi,
I see this ticket marked as closed but I still don't see the traces like in previous v1 functions.
V2 sample:

V1 sample:

The trace id is extremely useful for finding all the logs to specific invocation. Right now it is pretty painful.
Also note that in V2 there is no tag for the function name.

I suspect there might be something wrong with my setup. This is how I initialize my API:

import { onRequest } from "firebase-functions/v2/https";
import { setGlobalOptions } from "firebase-functions/v2";
import { buildExpressApp } from "./app";

const expressApp = buildExpressApp();

setGlobalOptions({
    timeoutSeconds: 120,
    memory: "512MiB",
    region: "europe-west3"
});

export * from "./functions";

// Expose Express API as a single Cloud Function:
exports.api = onRequest(expressApp);

[abdulaziz-mohammed]

why is this closed?

[blidd-google]

Hi @fgatti675, see my comment here for more details about how to trace logs from the same invocation in 2nd gen. If you are continuing to have issues, please open a new issue with a reproducible sample and we'll investigate as soon as we can.

[fgatti675]

Hi @fgatti675, see my comment here for more details about how to trace logs from the same invocation in 2nd gen. If you are continuing to have issues, please open a new issue with a reproducible sample and we'll investigate as soon as we can.

Thank you! We managed to get the traces working again, we were really missing this.
As a comment, they only work using the logger imported from firebase-functions/logger, it doesn't work using console.log, but much appreciated

[fgatti675]

Traces are gone, not sure since when, with no changes in our side.
You don't understand how frustrating this is.
Really, what is going on at Google?

[Byrontoo]

1. After 2024-09-13 10:29:33.257514 UTC, the traces are lost in the prod environment, but occasionally appears in other environments;
2. The trace is shortened in v2api, without the prefix: /projects/${projectId}
3. resource type: Cloud Run Revision
4. There is an additional field in the label node: execution_id

[adamxi]

@Byrontoo: We were having the same issues. Suddenly our stack traces were shortened after a redeploy, yet no firebase related dependencies had been updated. In fact, through much debugging it seemed that the logging.googleapis.com/trace log entry cannot be set manually AT ALL despite the documentation still indicating otherwise. In production this always gets overwritten.

So it appears that during function deployment, the functions-framework dependency is added to the build, unless already included (which it isn't for our project). In a recent update to the functions-framework library, the LOG_EXECUTION_ID env variable was introduced. Inspecting this on the deployed 2nd gen cloud function from the variables tab, to seems to default to true, despite the documentation stating otherwise. And yes.. after a redeploy with LOG_EXECUTION_ID=false our log trace values were working as before and no longer shortened.

So LOG_EXECUTION_ID=true effectively overwrites logging.googleapis.com/trace and also logging.googleapis.com/spanId it seems. Very frustrating to suddenly have stuff break in production like this.

[jits]

@Byrontoo: We were having the same issues. Suddenly our stack traces were shortened after a redeploy, yet no firebase related dependencies had been updated. In fact, though much debugging it seemed that the logging.googleapis.com/trace log entry cannot be set manually AT ALL despite the documentation still indicating otherwise. In production this always gets overwritten.

So it appears that during function deployment, the functions-framework dependency is added to the build, unless already included (which it isn't for our project). In a recent update to the functions-framework library, the LOG_EXECUTION_ID env variable was introduced. Inspecting this on the deployed 2nd gen cloud function from the variables tab, to seems to default to true, despite the documentation stating otherwise. And yes.. after a redeploy with LOG_EXECUTION_ID=false our log trace values were working as before and no longer shortened.

So LOG_EXECUTION_ID=true effectively overwrites logging.googleapis.com/trace and also logging.googleapis.com/spanId it seems. Very frustrating to suddenly have stuff break in production like this.

This is a really good microcosm of the complexities that are now inherent within the Firebase platform, especially given how it integrates with Google Cloud as a whole. As a developer that has banked significant intellectual and monetary capital on Firebase and Google Cloud, it disheartens me to see these kinds of things crop up on a regular basis (from my monitoring of the various Firebase repos and groups, and personal experience). Another prime example: the inability to have a single list of the permissions needed for a service account to deploy to Firebase, requiring lots of trial and error, and breaking whenever new capabilities or changes are made. At this point, it feels like Firebase and Google Cloud is buckling under it's own weight, and isn't a coherent enough platform. And with resources being cut and then diverted to the latest newfangled gen AI slop machinery I'm not sure anymore what my confidence levels are in Firebase (and Google as a whole) as a platform to build products on top of. Don't get me wrong, I still enjoy using services like Firestore. But I'm more and more concerned about being locked in to a platform with an uncertain and complex future.

[fgatti675]

Since this ticket was closed, I am expressing all my frustrations with this issue in a new one:
#1625

[Byrontoo]

@Byrontoo: We were having the same issues. Suddenly our stack traces were shortened after a redeploy, yet no firebase related dependencies had been updated. In fact, through much debugging it seemed that the logging.googleapis.com/trace log entry cannot be set manually AT ALL despite the documentation still indicating otherwise. In production this always gets overwritten.

So it appears that during function deployment, the functions-framework dependency is added to the build, unless already included (which it isn't for our project). In a recent update to the functions-framework library, the LOG_EXECUTION_ID env variable was introduced. Inspecting this on the deployed 2nd gen cloud function from the variables tab, to seems to default to true, despite the documentation stating otherwise. And yes.. after a redeploy with LOG_EXECUTION_ID=false our log trace values were working as before and no longer shortened.

So LOG_EXECUTION_ID=true effectively overwrites logging.googleapis.com/trace and also logging.googleapis.com/spanId it seems. Very frustrating to suddenly have stuff break in production like this.

Thank you for your reply, but it didn't work when I used npx firebase functions:config:set log.execution_id=false when publishing

[adamxi]

@Byrontoo In our setup we are actually deploying the function along with an env file which is loaded upon startup. Here we set the value of LOG_EXECUTION_ID to true. I believe this has to be loaded before the function export.
After deployment, you should check the variables tab in the function overview to inspect the value of LOG_EXECUTION_ID

[gbourne1]

Same issue and the reset with missing Trace logs

[gillycheesesteak]

I was having the issue, and adding LOG_EXECUTION_ID=false to my env file resolved it, although I'm not sure of the potential knock-on effects of that