firebase-functions: Functions v2 missing labels with Firebase structured logs

I just migrated my first project from gen1 to gen2 callable functions and the logging is just terrible. It’s not just that the labels are (still) missing but with gen1 function execution time appeared in the “function finished…” built in log message. Also any custom logging done in code is also missing labels. Huge downgrade from gen1 log message structure.

I also just upgraded to gen 2.

When looking at the logs I was surprised that it is no longer possible to filter logs which belong to one invocation, as ‘execution_id’ is missing. This is a crucial mechanism to inspect the logs in order to trace what happened during this particular invocation.

How to do that without the labels? No mention of this topic in the migration guide either.

Yes honestly, this is incredibly frustrating. And time continues to pass and we have 0 news. There is no simple way to see a full log trace. Why was this product released in this state? I mean, no one at Google is using this service and being bothered just like the rest of us? We are paying for a suboptimal service and should not be thinking about downgrading. Please do something

One year, still an issue 😦

Hey folks, Brian here from the Cloud Functions for Firebase team. Sorry to hear that many of you have been frustrated or confused by the logging experience in 2nd gen functions - we appreciate your feedback, and are working to alleviate this pain point in the migration process from 1st gen. That said, I’d like to address the various points people have discussed on this thread:

Labels

2nd gen functions are Cloud Run services under the hood. Running the following query in the Cloud Logs Explorer should display all logs relevant to a specific function:

(resource.type = "cloud_function"
resource.labels.function_name = "foo"
resource.labels.region = "us-central1")
 OR 
(resource.type = "cloud_run_revision"
resource.labels.service_name = "foo"
resource.labels.location = "us-central1")
 severity>=DEFAULT

By default, navigating to the Cloud Logs Explorer on either the Firebase Console or the function details page on the Cloud Console will run this query. Some of the folks in this thread have provided helpful guidance above on adding summary fields to label log entries from a specific function.

Tracing

In the last few months, our team found that a couple of 2nd gen trigger types were not tracking the trace context. We’ve recently reviewed all supported trigger types in 2nd gen to ensure logs from each invocation will be linked together by their common trace ID.

The trace ID can be found in the payload of an expanded log entry (trace: projects/<project_name>/traces/<trace_id>). Adding trace=<trace_id> will run a query for all logs that are tagged with trace_id.

Alternatively, log entries with trace context will show up in the Cloud Console with an icon of a few horizontal lines: Clicking that icon will display a menu, from which you can select “Show entries from this trace” to filter the logs for entires with the same trace ID.

Thanks all for your patience - seeing as logging is now working as intended, I’m going to close this issue out. Please feel free to open a new issue if you are still experiencing problems with logging in 2nd gen.

In v1, there is execution_id. Using this execution id, it is very easy to check the logs. labels.execution_id="id" But in v2, there is no such thing.

@lox The label wasn’t automatically removed since the OP didn’t reply. Sorry about that, remove it and labeled it

What information is needed? I don’t believe this is fixed yet.

Has anyone figured out a workaround to filter by one execution?

@AndreRLima Yup, summary fields can be saved in a saved search.

This is how mine look using a v2 onCall handler:

I have resource.labels.service_name added to my summary fields.

In terms of performance to develop, it did not improve performance. That is my conclusion.

Hey @metadiego. We need more information to resolve this issue but there hasn’t been an update in 7 weekdays. I’m marking the issue as stale and if there are no new updates in the next 3 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

I ended up just writing my own patch for console logging. This might help you @lox:

import { log as logFirebase, debug as debugFirebase, info as infoFirebase, warn as warnFirebase, error as errorFirebase } from 'firebase-functions/logger';

console.log = logFirebase;
console.debug = debugFirebase;
console.info = infoFirebase;
console.warn = warnFirebase;
console.error = errorFirebase;

How does one get at the headers outside of onRequest / onCall @HonahleeWill?

Not gonna be possible as far as I know. The trace is generated per-request, so you will need access to the request headers to read it. You will need to generate a new logging context for each request (also ensure that context isn’t shared by other requests).

Has anyone figured out a workaround to filter by one execution?

We created a custom wrapper for the logging. First for every invocation, a random value is created and used as execution ID. We pass this object as last argument to the log methods.

export function createExtendedLogContext(): ExtendedLogContext {
  // create a random execution id with 10 digits and chars
  const execution_id = Math.random().toString(36).substring(2, 12)

  return {
    'logging.googleapis.com/labels': {
      execution_id,
      function_name: process.env.FUNCTION_NAME || ''
    }
  }
}