Skip to content
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

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

Open
trullock opened this issue Sep 5, 2024 · 2 comments

Comments

@trullock
Copy link

trullock commented Sep 5, 2024

Related issues

Not sure if this has anything to do with it #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
Copy link
Collaborator

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

@trullock
Copy link
Author

trullock commented Sep 5, 2024

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

@github-staff github-staff deleted a comment from trullock Sep 5, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

3 participants
@trullock @google-oss-bot and others