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

Add fatal errror listener #1095

Merged
merged 16 commits into from
Mar 19, 2024
Merged

Add fatal errror listener #1095

merged 16 commits into from
Mar 19, 2024

Conversation

bgrgicak
Copy link
Collaborator

@bgrgicak bgrgicak commented Mar 8, 2024

What is this PR doing?

It allows developers to listen for fatal Playground errors and collect logs.

What problem is it solving?

This will allow Playground to collect fatal errors from user sessions in the future.
It will also allow developers who use startPlaygroundWeb to listen for errors and create custom workflows.

How is the problem addressed?

All logs are now collected inside the logger including PHP request errors.
When a PHP request error happens the logger dispatches a custom event that developers can listen.

Testing Instructions

addFatalErrorListener(logger, (e) => {
	console.log('Playground logs', (e as CustomEvent).detail.logs);
});
  • Reload Playground and confirm that the even has triggered with log data by checking the browser console for Playground logs

@bgrgicak bgrgicak self-assigned this Mar 8, 2024
@bgrgicak bgrgicak requested a review from adamziel March 8, 2024 13:05
@@ -292,6 +292,12 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
throw error;
}
return response;
} catch (e) {
this.dispatchEvent({
Copy link
Collaborator

@adamziel adamziel Mar 11, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cool! Note this might either signify a fatal error in PHP, if request.throwOnError is true, or a more serious issue like, e.g., Asyncify exception.

Copy link
Collaborator

@adamziel adamziel Mar 11, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be useful to also emit response information when available? Also, I wonder whether we should remove throwOnError and always act as if it was set to true – that's probably out of scope for this PR.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note this might either signify a fatal error in PHP, if request.throwOnError is true, or a more serious issue like, e.g., Asyncify exception.

Thanks! Both are valid cases for returning the event, but it would be good to distinguish between them.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, I wonder whether we should remove throwOnError and always act as if it was set to true – that's probably out of scope for this PR.

Let's take a look at this separately. I'm trying to avoid changing current logs in this project to stay focused.
But there is definitely room for improvement in how we throw and display errors.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be useful to also emit response information when available?

Do you mean emit the response when the request is successful?
I don't know how I would do it for failed requests. There is #getResponseHeaders for getting the headers, but I'm not sure how useful that is.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

PHP exceptions won't trigger this. Only internal errors like Asyncify.
For some reason, I thought they would, but after testing it, it doesn't.
You get a WordPress error screen and can read the log in the browser console/debug.log.

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@bgrgicak actually, this will be triggered by PHP exceptions if this method is called with throwOnError, see the line 292. Let's fix that.

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm unable to recreate this. Do you have an example?

I tried throwing an error in 0-playground.php and introducing syntax errors. Both just returned a 500, but didn't trigger the event.
Screenshot from 2024-03-22 10-50-35

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

	php.addEventListener('request.error', (e) => {
		console.log("Request error");
	});
	php.run({
		throwOnError: true,
		code: `<?php
		syntax_error
		`,
	});

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks! I added a flag that will prevent the modal from triggering.

There is still value in catching these errors in some cases. For example if a developer uses Playground to demo their product and wants to know when it breaks on Playground.

Playground.WordPress.net won't show the modal, but a developer might decide to log the message somewhere to improve their demo experience.

import { ExportFormValues } from './github/github-export-form/form';
import { joinPaths } from '@php-wasm/util';
import { PlaygroundContext } from './playground-context';
import { collectWindowErrors, logger } from '@php-wasm/logger';

collectWindowErrors(logger);
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Related discussion #1035 (comment)

packages/php-wasm/logger/src/logger.ts Outdated Show resolved Hide resolved
@@ -292,6 +292,12 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
throw error;
}
return response;
} catch (e) {
this.dispatchEvent({
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note this might either signify a fatal error in PHP, if request.throwOnError is true, or a more serious issue like, e.g., Asyncify exception.

Thanks! Both are valid cases for returning the event, but it would be good to distinguish between them.

@@ -292,6 +292,12 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
throw error;
}
return response;
} catch (e) {
this.dispatchEvent({
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Also, I wonder whether we should remove throwOnError and always act as if it was set to true – that's probably out of scope for this PR.

Let's take a look at this separately. I'm trying to avoid changing current logs in this project to stay focused.
But there is definitely room for improvement in how we throw and display errors.

@@ -292,6 +292,12 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
throw error;
}
return response;
} catch (e) {
this.dispatchEvent({
Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Would it be useful to also emit response information when available?

Do you mean emit the response when the request is successful?
I don't know how I would do it for failed requests. There is #getResponseHeaders for getting the headers, but I'm not sure how useful that is.

@bgrgicak bgrgicak requested a review from adamziel March 12, 2024 09:50
@adamziel
Copy link
Collaborator

Let's add at least one unit test just as a smoke test to confirm dispatching CustomEvent works.

@adamziel adamziel added [Type] Enhancement New feature or request [Type] Reliability Playground uptime, reliability, not crashing labels Mar 12, 2024
@bgrgicak bgrgicak force-pushed the add/logger-crash-event branch from 9762186 to 93e28c0 Compare March 12, 2024 12:47
@bgrgicak
Copy link
Collaborator Author

Let's add at least one unit test just as a smoke test to confirm dispatching CustomEvent works.

Done a9aa605

@bgrgicak bgrgicak requested a review from adamziel March 13, 2024 11:00
@@ -186,3 +240,15 @@ export function collectPhpLogs(
) {
loggerInstance.addPlaygroundRequestEndListener(playground);
}

/**
* Add a listener for the fatal error event.
Copy link
Collaborator

@adamziel adamziel Mar 13, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let's explain what's a fatal error – is it related to WordPress? PHP.wasm? The current JavaScript app? How is it different from window errors?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I clarified that this includes only Playground errors and not PHP errors. 91a5e72

I also mentioned that logs are available in the event.

Copy link
Collaborator

@adamziel adamziel left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks great so I'm going to approve! My only remaining note is around clarity – let's explain exactly what kind of information developers may expect when they listen for fatal errors.

@bgrgicak
Copy link
Collaborator Author

I just ran npm run test locally and all tests passed.

@adamziel
Copy link
Collaborator

Saving the CI test failures stack traces for posterity – would a rebase solve those? Or is this a new issue?

 ❯ src/test/php.spec.ts  (937 tests | 9 failed) 302575ms
   ❯ src/test/php.spec.ts > PHP 8.3 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 8.2 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 8.1 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 8.0 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 7.4 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 7.3 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 7.2 > onMessage > should return null when JS message handler throws an error
     → memory access out of bounds
   ❯ src/test/php.spec.ts > PHP 7.1 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
   ❯ src/test/php.spec.ts > PHP 7.0 > onMessage > should return null when JS message handler throws an error
     → table index is out of bounds
 ✓ src/test/php-networking.spec.ts  (9 tests) 2065ms

⎯⎯⎯⎯⎯⎯⎯ Failed Tests 9 ⎯⎯⎯⎯⎯⎯⎯

 FAIL  src/test/php.spec.ts > PHP 8.3 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 8.2 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 8.1 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 8.0 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 7.4 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 7.3 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 7.1 > onMessage > should return null when JS message handler throws an error
 FAIL  src/test/php.spec.ts > PHP 7.0 > onMessage > should return null when JS message handler throws an error
Error: table index is out of bounds
 ❯ _NodePHP.#handleRequest ../universal/src/lib/base-php.ts:653:21
    651|     'betterMessage' in err ? err.betterMessage : err.message
    652|    ) as string;
    653|    const rethrown = new Error(message);
       |                     ^
    654|    rethrown.cause = err;
    655|    console.error(rethrown);
 ❯ _NodePHP.run ../universal/src/lib/base-php.ts:278:21
 ❯ src/test/php.spec.ts:1560:16

Caused by: Error: Rethrown
 ❯ UnhandledRejectionsTarget.errorListener ../universal/src/lib/base-php.ts:610:23
 ❯ UnhandledRejectionsTarget.callTheUserObjectsOperation ../../../node_modules/jsdom/lib/jsdom/living/generated/EventListener.js:26:30
 ❯ innerInvokeEventListeners ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:350:25
 ❯ invokeEventListeners ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:286:3
 ❯ EventTargetImpl._dispatch ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:233:9
 ❯ EventTargetImpl.dispatchEvent ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:104:17
 ❯ UnhandledRejectionsTarget.dispatchEvent ../../../node_modules/jsdom/lib/jsdom/living/generated/EventTarget.js:241:34
 ❯ runtime.asm.<computed> ../universal/src/lib/wasm-error-reporting.ts:60:14
 ❯ invoke_vii public/php_8_3.js:7563:3
 ❯ zend_eval_stringl ../../../wasm:/wasm/02b5f34a:1:2193029

⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
Serialized Error: {
  "betterMessage": "table index is out of bounds",
}
Caused by: RuntimeError: table index is out of bounds
 ❯ execute_ex ../../../wasm:/wasm/02b5f34a:1:6648744
 ❯ zend_execute ../../../wasm:/wasm/02b5f34a:1:2191872
 ❯ dynCall_vii ../../../wasm:/wasm/02b5f34a:1:6687099
 ❯ ret.<computed> public/php_8_3.js:6713:24
 ❯ runtime.asm.<computed> ../universal/src/lib/wasm-error-reporting.ts:45:13
 ❯ invoke_vii public/php_8_3.js:7563:3
 ❯ zend_eval_stringl ../../../wasm:/wasm/02b5f34a:1:2193029
 ❯ zend_eval_string ../../../wasm:/wasm/02b5f34a:1:5513831
 ❯ dynCall_iiii ../../../wasm:/wasm/02b5f34a:1:6688780
 ❯ ret.<computed> public/php_8_3.js:6713:24

Caused by: Error: 
 ❯ Object.Asyncify.handleSleep public/php_8_3.js:7806:49
 ❯ _js_module_onMessage public/php_8_3.js:5882:19
 ❯ zif_post_message_to_js ../../../wasm:/wasm/02b5f34a:1:5036287
 ❯ ZEND_DO_ICALL_SPEC_RETVAL_USED_HANDLER ../../../wasm:/wasm/02b5f34a:1:7078703
 ❯ execute_ex ../../../wasm:/wasm/02b5f34a:1:6648744
 ❯ zend_execute ../../../wasm:/wasm/02b5f34a:1:2191872
 ❯ dynCall_vii ../../../wasm:/wasm/02b5f34a:1:6687099
 ❯ ret.<computed> public/php_8_3.js:6713:24
 ❯ runtime.asm.<computed> ../universal/src/lib/wasm-error-reporting.ts:45:13
 ❯ invoke_vii public/php_8_3.js:7563:3

⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯[1/9]⎯

 FAIL  src/test/php.spec.ts > PHP 7.2 > onMessage > should return null when JS message handler throws an error
Error: memory access out of bounds
 ❯ _NodePHP.#handleRequest ../universal/src/lib/base-php.ts:653:21
    651|     'betterMessage' in err ? err.betterMessage : err.message
    652|    ) as string;
    653|    const rethrown = new Error(message);
       |                     ^
    654|    rethrown.cause = err;
    655|    console.error(rethrown);
 ❯ _NodePHP.run ../universal/src/lib/base-php.ts:278:21
 ❯ src/test/php.spec.ts:1560:16

Caused by: Error: Rethrown
 ❯ UnhandledRejectionsTarget.errorListener ../universal/src/lib/base-php.ts:610:23
 ❯ UnhandledRejectionsTarget.callTheUserObjectsOperation ../../../node_modules/jsdom/lib/jsdom/living/generated/EventListener.js:26:30
 ❯ innerInvokeEventListeners ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:350:25
 ❯ invokeEventListeners ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:286:3
 ❯ EventTargetImpl._dispatch ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:233:9
 ❯ EventTargetImpl.dispatchEvent ../../../node_modules/jsdom/lib/jsdom/living/events/EventTarget-impl.js:104:17
 ❯ UnhandledRejectionsTarget.dispatchEvent ../../../node_modules/jsdom/lib/jsdom/living/generated/EventTarget.js:241:34
 ❯ runtime.asm.<computed> ../universal/src/lib/wasm-error-reporting.ts:60:14
 ❯ invoke_vii public/php_7_2.js:7363:3
 ❯ zend_eval_stringl ../../../wasm:/wasm/02daf362:1:1335004

⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
Serialized Error: {
  "betterMessage": "memory access out of bounds",
}
Caused by: RuntimeError: memory access out of bounds
 ❯ zend_detach_symbol_table ../../../wasm:/wasm/02daf362:1:2857423
 ❯ zend_leave_helper_SPEC ../../../wasm:/wasm/02daf362:1:487753
 ❯ ZEND_RETURN_SPEC_CONST_HANDLER ../../../wasm:/wasm/02daf362:1:6774961
 ❯ byn$fpcast-emu$ZEND_RETURN_SPEC_CONST_HANDLER ../../../wasm:/wasm/02daf362:1:6631097
 ❯ execute_ex ../../../wasm:/wasm/02daf362:1:6334252
 ❯ byn$fpcast-emu$execute_ex ../../../wasm:/wasm/02daf362:1:6614434
 ❯ zend_execute ../../../wasm:/wasm/02daf362:1:2116228
 ❯ byn$fpcast-emu$zend_execute ../../../wasm:/wasm/02daf362:1:6550874
 ❯ dynCall_vii ../../../wasm:/wasm/02daf362:1:6375909
 ❯ ret.<computed> public/php_7_2.js:6547:24

Caused by: Error: 
 ❯ Object.Asyncify.handleSleep public/php_7_2.js:7617:49
 ❯ _js_module_onMessage public/php_7_2.js:5730:19
 ❯ zif_post_message_to_js ../../../wasm:/wasm/02daf362:1:4735348
 ❯ byn$fpcast-emu$zif_post_message_to_js ../../../wasm:/wasm/02daf362:1:6527601
 ❯ ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_USED_HANDLER ../../../wasm:/wasm/02daf362:1:6969516
 ❯ byn$fpcast-emu$ZEND_DO_FCALL_BY_NAME_SPEC_RETVAL_USED_HANDLER ../../../wasm:/wasm/02daf362:1:6639713
 ❯ execute_ex ../../../wasm:/wasm/02daf362:1:6334252
 ❯ byn$fpcast-emu$execute_ex ../../../wasm:/wasm/02daf362:1:6614434
 ❯ zend_execute ../../../wasm:/wasm/02daf362:1:2116228
 ❯ byn$fpcast-emu$zend_execute ../../../wasm:/wasm/02daf362:1:6550874

@bgrgicak
Copy link
Collaborator Author

@adamziel this unit test is also failing for me on trunk. Would it be ok to merge this PR as is and fix the test in another PR?
Or maybe better to disable the test temporarily.

I wouldn't rush the merge, but this feature is blocking adoption.

@bgrgicak
Copy link
Collaborator Author

Issue for the failing unit test #1112

@bgrgicak bgrgicak merged commit 55a94bb into trunk Mar 19, 2024
5 checks passed
@bgrgicak bgrgicak deleted the add/logger-crash-event branch March 19, 2024 11:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
[Type] Enhancement New feature or request [Type] Reliability Playground uptime, reliability, not crashing
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants