Stack trace truncated in production but not emulator when error thrown in nested async function

[trullock]

Related issues

Not sure if this has anything to do with it https://github.com/firebase/firebase-functions/issues/1337

[REQUIRED] Version info

node:

21

firebase-functions:

5.0.1

firebase-tools:

13.13.3

firebase-admin:

12.1.0

[REQUIRED] Test case

See below

[REQUIRED] Steps to reproduce

See below

[REQUIRED] Expected behavior

Stack trace not to be truncated when an error is thrown inside and async function

[REQUIRED] Actual behavior

Stack trace only contains the last stack frame, none of the path of how it got there

Were you able to successfully deploy your functions?

Yes

---

If you have this 2nd Gen function (1st gen not tested):

export const errorHandlingTest1 = onRequest(async (request, response) => {
    try
    {
        let nre = null;
        nre.explode = 'bang'
    }
    catch(e)
    {
        functions.logger.error('Error invoking function', e, {
            query: request.query,
            body: request.body
        })
        response.sendStatus(500);
    }
})

And then you invoke it with this url slug /errorHandlingTest1?foo=bar

On the emulator you get this:

{"query":{"foo":"bar"},"body":{},"severity":"ERROR","message":"
Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at file:///<omitted>/functions/index.js:778:15
    at <omitted>\\functions\\node_modules\\firebase-functions\\lib\\v2\\providers\\https.js:65:29
    at cors (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:188:7)
    at <omitted>\\functions\\node_modules\\cors\\lib\\index.js:224:17
    at originCallback (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:214:15)
    at <omitted>\\functions\\node_modules\\cors\\lib\\index.js:219:13
    at optionsCallback (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:199:9)
    at corsMiddleware (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:204:7)
    at <omitted>\\functions\\node_modules\\firebase-functions\\lib\\v2\\providers\\https.js:64:17"}

And on live you get this:

Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at file:///workspace/index.js:778:15
    at /workspace/node_modules/firebase-functions/lib/common/onInit.js:33:16
    at AsyncLocalStorage.run (node:async_hooks:346:14)
    at /workspace/node_modules/firebase-functions/lib/v2/trace.js:18:37
    at /layers/google.nodejs.functions-framework/functions-framework/node_modules/@google-cloud/functions-framework/build/src/function_wrappers.js:98:17
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11) 

Live omits some of the internal stack frames but thats no issue.

If you make the explosion happen inside another function call:

function explode()
{
    let nre = null;
    nre.explode = 'bang'
}

export const errorHandlingTest2 = onRequest(async (request, response) => {
    try
    {
        explode();
    }
    catch(e)
    {
        error('Error invoking function', e, {
            query: request.query,
            body: request.body
        })
        response.sendStatus(500);
    }
})

and hit /errorHandlingTest2?foo=bar

On the Emulator you get:

{"query":{"foo":"bar"},"body":{},"severity":"ERROR","message":"
Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at explode (file:///<omitted>/functions/index.js:777:14)
    at file:///<omitted>/functions/index.js:784:3
    at <omitted>\\functions\\node_modules\\firebase-functions\\lib\\v2\\providers\\https.js:65:29
    at cors (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:188:7)
    at <omitted>\\functions\\node_modules\\cors\\lib\\index.js:224:17
    at originCallback (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:214:15)
    at <omitted>\\functions\\node_modules\\cors\\lib\\index.js:219:13
    at optionsCallback (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:199:9)
    at corsMiddleware (<omitted>\\functions\\node_modules\\cors\\lib\\index.js:204:7)"}

and on Live you get:

 Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at explode (file:///workspace/index.js:777:14)
    at file:///workspace/index.js:784:3
    at /workspace/node_modules/firebase-functions/lib/common/onInit.js:33:16
    at AsyncLocalStorage.run (node:async_hooks:346:14)
    at /workspace/node_modules/firebase-functions/lib/v2/trace.js:18:37
    at /layers/google.nodejs.functions-framework/functions-framework/node_modules/@google-cloud/functions-framework/build/src/function_wrappers.js:98:17
    at process.processTicksAndRejections (node:internal/process/task_queues:77:11) 

Great, as you'd expect

But then if you have an async function:

async function explode()
{
    await new Promise(r => setTimeout(r, 1));

    let nre = null;
    nre.explode = 'bang'
}

export const errorHandlingTest3 = onRequest(async (request, response) => {
    try
    {
        await explode();
    }
    catch(e)
    {
        functions.logger.error('Error invoking function', e, {
            query: request.query,
            body: request.body
        })
        response.sendStatus(500);
    }
})

and hit /errorHandlingTest3?foo=bar

You get:

Emulator:

{"query":{"foo":"bar"},"body":{},"severity":"ERROR","message":"
Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at explode (file:///<omitted>/functions/index.js:779:14)
    at async file:///<omitted>/functions/index.js:786:3
    at async runFunction (C:\\nvm\\v21.4.0\\node_modules\\firebase-tools\\lib\\emulator\\functionsEmulatorRuntime.js:506:9)
    at async runHTTPS (C:\\nvm\\v21.4.0\\node_modules\\firebase-tools\\lib\\emulator\\functionsEmulatorRuntime.js:531:5)
    at async C:\\nvm\\v21.4.0\\node_modules\\firebase-tools\\lib\\emulator\\functionsEmulatorRuntime.js:694:21"}

Note the two stack frames for index.js, as youd expect BUT on Live you get:

Error invoking function TypeError: Cannot set properties of null (setting 'explode')
    at explode (file:///workspace/index.js:779:14) 

Where's the rest of the stacktrace? This makes debug very difficult.

[google-oss-bot]

I couldn't figure out how to label this issue, so I've labeled it for a human to triage. Hang tight.

[trullock]

Ah, slight update to this.

It only seems to affect the Error Reporting page, e.g. here https://console.cloud.google.com/errors/detail/XXXXXXXXX;locations=global If you click View Logs from a truncated sample and go through to the full log detail, e.g https://console.cloud.google.com/logs/query;query=error_groups.id%3D%22XXXXXXXXXX%22%0AlogName:%22run.googleapis.com%252Fstderr%22%0Aresource.type%3D%22cloud_run_revision%22%0Aresource.labels.revision_name%3D%22errorhandlingtest4-00002-kif%22%0Aresource.labels.location%3D%22europe-west1%22%0Aresource.labels.service_name%3D%22errorhandlingtest4%22%0Aresource.labels.configuration_name%3D%22errorhandlingtest4%22%0Aresource.labels.project_id

the whole stack trace is here.

So thats a workaround at least. Still, theres some issue here, just perhaps not as critical as initally thought. Annoying still