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
5 changes: 4 additions & 1 deletion packages/php-wasm/logger/src/index.ts
Original file line number Diff line number Diff line change
@@ -1 +1,4 @@
export * from './logger';
// PHP.wasm requires WordPress Playground's Node polyfills.
import '@php-wasm/node-polyfills';

export * from './lib/logger';
Original file line number Diff line number Diff line change
@@ -1,14 +1,27 @@
import { UniversalPHP } from '@php-wasm/universal/src/lib/universal-php';
import {
PHPRequestErrorEvent,
UniversalPHP,
} from '@php-wasm/universal/src/lib/universal-php';
/**
* Log severity levels.
*/
export type LogSeverity = 'debug' | 'info' | 'warn' | 'error' | 'fatal';
export type LogSeverity = 'Debug' | 'Info' | 'Warn' | 'Error' | 'Fatal';

/**
* Log prefix.
*/
export type LogPrefix = 'Playground' | 'PHP-WASM';

/**
* A logger for Playground.
*/
export class Logger {
private readonly LOG_PREFIX = 'Playground';
export class Logger extends EventTarget {
public readonly fatalErrorEvent = 'playground-fatal-error';

/**
* Log messages
*/
private logs: string[] = [];

/**
* Whether the window events are connected.
Expand All @@ -26,6 +39,7 @@ export class Logger {
private errorLogPath = '/wordpress/wp-content/debug.log';

constructor(errorLogPath?: string) {
super();
if (errorLogPath) {
this.errorLogPath = errorLogPath;
}
Expand All @@ -52,7 +66,7 @@ export class Logger {
private logWindowError(event: ErrorEvent) {
this.log(
`${event.message} in ${event.filename} on line ${event.lineno}:${event.colno}`,
'fatal'
'Error'
);
}

Expand All @@ -62,7 +76,7 @@ export class Logger {
* @param PromiseRejectionEvent event
*/
private logUnhandledRejection(event: PromiseRejectionEvent) {
this.log(`${event.reason.stack}`, 'fatal');
this.log(`${event.reason.stack}`, 'Error');
}

/**
Expand Down Expand Up @@ -101,6 +115,23 @@ export class Logger {
this.lastPHPLogLength = log.length;
}
});
playground.addEventListener('request.error', (event) => {
event = event as PHPRequestErrorEvent;
if (event.error) {
this.log(
`${event.error.message} ${event.error.stack}`,
'Fatal',
'PHP-WASM'
);
this.dispatchEvent(
new CustomEvent(this.fatalErrorEvent, {
detail: {
logs: this.getLogs(),
},
})
);
}
});
}

/**
Expand Down Expand Up @@ -134,22 +165,36 @@ export class Logger {
* Format log message and severity and log it.
* @param string message
* @param LogSeverity severity
* @param string prefix
*/
public formatMessage(message: string, severity: LogSeverity): string {
public formatMessage(
message: string,
severity: LogSeverity,
prefix: string
): string {
const now = this.formatLogDate(new Date());
return `[${now}] ${this.LOG_PREFIX} ${severity}: ${message}`;
return `[${now}] ${prefix} ${severity}: ${message}`;
}

/**
* Log message with severity and timestamp.
* @param string message
* @param LogSeverity severity
* @param string prefix
*/
public log(message: string, severity?: LogSeverity): void {
public log(
message: string,
severity?: LogSeverity,
prefix?: LogPrefix
): void {
if (severity === undefined) {
severity = 'info';
severity = 'Info';
}
const log = this.formatMessage(message, severity);
const log = this.formatMessage(
message,
severity,
prefix ?? 'Playground'
);
this.logRaw(log);
}

Expand All @@ -158,8 +203,17 @@ export class Logger {
* @param string log
*/
public logRaw(log: string): void {
this.logs.push(log);
console.debug(log);
}

/**
* Get all logs.
* @returns string[]
*/
public getLogs(): string[] {
return this.logs;
}
}

/**
Expand All @@ -186,3 +240,18 @@ export function collectPhpLogs(
) {
loggerInstance.addPlaygroundRequestEndListener(playground);
}

/**
* Add a listener for the fatal Playground errors.
* These errors include Playground errors like Asyncify errors. PHP errors won't trigger this event.
* The callback function will receive an Event object with logs in the detail property.
*
* @param loggerInstance The logger instance
* @param callback The callback function
*/
export function addFatalErrorListener(
loggerInstance: Logger,
callback: EventListenerOrEventListenerObject
) {
loggerInstance.addEventListener(loggerInstance.fatalErrorEvent, callback);
}
23 changes: 23 additions & 0 deletions packages/php-wasm/logger/src/test/logger.spec.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,23 @@
import { NodePHP } from '@php-wasm/node';
import { LatestSupportedPHPVersion } from '@php-wasm/universal';
import { logger, addFatalErrorListener, collectPhpLogs } from '../lib/logger';

describe('Logger', () => {
let php: NodePHP;
beforeEach(async () => {
php = await NodePHP.load(LatestSupportedPHPVersion);
});
it('Event listener should work', () => {
const listener = vi.fn();
collectPhpLogs(logger, php);
addFatalErrorListener(logger, listener);
php.dispatchEvent({
type: 'request.error',
error: new Error('test'),
});
expect(listener).toBeCalledTimes(1);

const logs = logger.getLogs();
expect(logs.length).toBe(1);
});
});
6 changes: 6 additions & 0 deletions packages/php-wasm/universal/src/lib/base-php.ts
Original file line number Diff line number Diff line change
Expand Up @@ -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.

type: 'request.error',
error: e as Error,
});
throw e;
} finally {
try {
if (heapBodyPointer) {
Expand Down
9 changes: 9 additions & 0 deletions packages/php-wasm/universal/src/lib/universal-php.ts
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,14 @@ export interface PHPRequestEndEvent {
type: 'request.end';
}

/**
* Represents an error event related to the PHP request.
*/
export interface PHPRequestErrorEvent {
type: 'request.error';
error: Error;
}

/**
* Represents a PHP runtime initialization event.
*/
Expand All @@ -29,6 +37,7 @@ export interface PHPRuntimeBeforeDestroyEvent {
*/
export type PHPEvent =
| PHPRequestEndEvent
| PHPRequestErrorEvent
| PHPRuntimeInitializedEvent
| PHPRuntimeBeforeDestroyEvent;

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,7 @@
declare const self: ServiceWorkerGlobalScope;

import { awaitReply, getNextRequestId } from './messaging';
import {
getURLScope,
isURLScoped,
removeURLScope,
setURLScope,
} from '@php-wasm/scopes';
import { getURLScope, isURLScoped, setURLScope } from '@php-wasm/scopes';

/**
* Run this function in the service worker to install the required event
Expand Down Expand Up @@ -45,12 +40,6 @@ export function initializeServiceWorker(config: ServiceWorkerConfiguration) {
return;
}
}

console.debug(
`[ServiceWorker] Serving request: ${getRelativePart(
removeURLScope(url)
)}`
);
bgrgicak marked this conversation as resolved.
Show resolved Hide resolved
const responsePromise = handleRequest(event);
if (responsePromise) {
event.respondWith(responsePromise);
Expand Down Expand Up @@ -122,22 +111,12 @@ export async function convertFetchEventToPHPRequest(event: FetchEvent) {
`The URL ${url.toString()} is not scoped. This should not happen.`
);
}
console.debug(
'[ServiceWorker] Forwarding a request to the Worker Thread',
{
message,
}
);
const requestId = await broadcastMessageExpectReply(message, scope);
phpResponse = await awaitReply(self, requestId);

// X-frame-options gets in a way when PHP is
// being displayed in an iframe.
delete phpResponse.headers['x-frame-options'];

console.debug('[ServiceWorker] Response received from the main app', {
phpResponse,
});
} catch (e) {
console.error(e, { url: url.toString() });
throw e;
Expand Down Expand Up @@ -247,7 +226,3 @@ export function getRequestHeaders(request: Request) {
});
return headers;
}

function getRelativePart(url: URL): string {
return url.toString().substring(url.origin.length);
}
1 change: 0 additions & 1 deletion packages/php-wasm/web/src/lib/register-service-worker.ts
Original file line number Diff line number Diff line change
Expand Up @@ -48,7 +48,6 @@ export async function registerServiceWorker<
navigator.serviceWorker.addEventListener(
'message',
async function onMessage(event) {
console.debug('[window][sw] Message from ServiceWorker', event);
/**
* Ignore events meant for other PHP instances to
* avoid handling the same event twice.
Expand Down
8 changes: 3 additions & 5 deletions packages/playground/website/src/main.tsx
Original file line number Diff line number Diff line change
Expand Up @@ -22,12 +22,14 @@ import { acquireOAuthTokenIfNeeded } from './github/acquire-oauth-token-if-neede
import { GithubImportModal } from './github/github-import-form';
import { GithubExportMenuItem } from './components/toolbar-buttons/github-export-menu-item';
import { GithubExportModal } from './github/github-export-form';
import { useEffect, useState } from 'react';
import { useState } from 'react';
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)


const query = new URL(document.location.href).searchParams;
const blueprint = await resolveBlueprint();

Expand Down Expand Up @@ -83,10 +85,6 @@ function Main() {
Partial<ExportFormValues>
>({});

useEffect(() => {
collectWindowErrors(logger);
}, []);

return (
<PlaygroundContext.Provider value={{ storage }}>
<PlaygroundViewport
Expand Down
Loading