firebase-functions icon indicating copy to clipboard operation
firebase-functions copied to clipboard

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

Open trullock opened this issue 1 year ago • 3 comments

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.

trullock avatar Sep 05 '24 12:09 trullock