Add logging support to Playground

packages/php-wasm/universal/src/lib/base-php.ts

@@ -28,6 +28,7 @@ import {
 	UnhandledRejectionsTarget,
 } from './wasm-error-reporting';
 import { Semaphore, createSpawnHandler, joinPaths } from '@php-wasm/util';
+import { LogSeverity, get_logger } from './logger';
 
 const STRING = 'string';
 const NUMBER = 'number';
@@ -52,6 +53,7 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
 	#eventListeners: Map<string, Set<PHPEventListener>> = new Map();
 	#messageListeners: MessageListener[] = [];
 	requestHandler?: PHPBrowser;
+	logger = get_logger(this);
 
 	/**
 	 * An exclusive lock that prevent multiple requests from running at
@@ -264,21 +266,30 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
 				this.#setPHPCode(' ?>' + request.code);
 			}
 			this.#addServerGlobalEntriesInWasm();
-			const response = await this.#handleRequest();
-			if (request.throwOnError && response.exitCode !== 0) {
-				const output = {
-					stdout: response.text,
-					stderr: response.errors,
-				};
-				console.warn(`PHP.run() output was:`, output);
-				const error = new Error(
-					`PHP.run() failed with exit code ${response.exitCode} and the following output`
-				);
-				// @ts-ignore
-				error.output = output;
-				throw error;
+			try {
+				const response = await this.#handleRequest();
+				if (request.throwOnError && response.exitCode !== 0) {
+					const output = {
+						stdout: response.text,
+						stderr: response.errors,
+					};
+					console.warn(`PHP.run() output was:`, output);
+					const error = new Error(
+						`PHP.run() failed with exit code ${response.exitCode} and the following output`
+					);
+					// @ts-ignore
+					error.output = output;
+					throw error;
+				}
+				return response;
+			} catch (e: any) {
+				this.logger.log({
+					body: e.message,
+					severityNumber: LogSeverity.Error,
+					resource: 'php',
+				});
+				throw e;
 			}
-			return response;
 		} finally {
 			try {
 				if (heapBodyPointer) {
@@ -770,6 +781,7 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
 		// runtime.
 		const oldFS = this[__private__dont__use].FS;
 
+		console.log('PHP runtime exited');
 		// Kill the current runtime
 		try {
 			this.exit();
@@ -799,6 +811,7 @@ export abstract class BasePHP implements IsomorphicLocalPHP {
 	}
 
 	exit(code = 0) {
+		console.log('PHP exit()');
 		this.dispatchEvent({
 			type: 'runtime.beforedestroy',
 		});

packages/php-wasm/universal/src/lib/logger.ts

@@ -0,0 +1,148 @@
+import { BasePHP } from "./base-php";
+import { UniversalPHP } from "./universal-php";
+
+// Log severity levels based on OpenTelemetry https://opentelemetry.io/docs/specs/otel/logs/data-model/#field-severitynumber
+export enum LogSeverity {
+    // A dine grained debugging event. Typically disabled in default configurations.
+    Trace = 1,
+    // A debugging event.
+    Debug = 5,
+    // An informational event. Indicates that an event happened.
+    Info = 9,
+    // A warning event. Not an error but is likely more important than an informational event.
+    Warn = 13,
+    // An error event. Something went wrong.
+    Error = 17,
+    // A fatal error such as application or system crash.
+    Fatal = 21,
+}
+
+// Log format based on OpenTelemetry https://opentelemetry.io/docs/specs/otel/logs/data-model/
+export type Log = {
+    // Time when the event occurred.
+    timestamp?: number;
+    // Time when the event was observed.
+    observedTimestamp?: number;
+    // Request trace id.
+    traceId?: number;
+    // Request span id.
+    spanId?: number; // Not implemented
+    // W3C trace flag.
+    traceFlags?: number;
+    // The severity text (also known as log level).
+    severityText?: string;
+    // Numerical value of the severity.
+    severityNumber: LogSeverity;
+    // The body of the log record.
+    body: string;
+    // Describes the source of the log.
+    resource?: string;
+    // Describes the scope that emitted the log.
+    instrumentationScope?: string; // Not implemented
+    // Additional information about the event.
+    attributes?: Record<string, string>;
+};
+
+const defaultLog: Log = {
+    timestamp: 0,
+    observedTimestamp: 0,
+    traceId: 0,
+    spanId: 0,
+    traceFlags: 0,
+    severityText: LogSeverity[LogSeverity.Info],
+    severityNumber: LogSeverity.Info,
+    body: '',
+    resource: '',
+    instrumentationScope: '',
+    attributes: {},
+};
+
+export class Logger {
+    private php: UniversalPHP | undefined;
+    private logs: Log[] = [];
+
+    constructor(php?: UniversalPHP) {
+        this.php = php;
+        if (this.php) {
+            this.php.addEventListener(
+                'request.end',
+                () => {
+                    this.printWordPressLogs();
+                }
+            )
+            this.php.onMessage(this.processPhpLogMessage.bind(this));
+        }
+        if ( typeof window !== 'undefined' ) {
+            window.onerror = (message, source, lineno, colno) => {
+                this.log({
+                    body: `${message} in ${source} on line ${lineno}:${colno}`,
+                    severityNumber: LogSeverity.Fatal,
+                    resource: 'javascript',
+                });
+            }
+        }
+    }
+
+    private processPhpLogMessage(message: string) {
+        try {
+            const logMessage = JSON.parse(message);
+            if (logMessage.type === 'wordpress-log') {
+                this.log({
+                   ...logMessage,
+                   severityNumber: LogSeverity[logMessage.severityText as keyof typeof LogSeverity],
+                    resource: 'wordpress',
+                });
+            }
+        } catch (error) {
+            // Not a log message
+        }
+    }
+
+    public log(rawLog: Log): void {
+        const now = Date.now();
+        const log = {
+            ...defaultLog,
+            ...rawLog,
+        };
+        log.timestamp = log.timestamp || now;
+        log.observedTimestamp = now;
+        log.severityText = LogSeverity[log.severityNumber];
+
+        this.logs.push(log);
+    }
+
+    public getLogs(): Log[] {
+        return this.logs;
+    }
+
+    private numberOfLogLinesToShow() {
+        //  @TODO Get value from query API
+        return 100;
+    }
+
+    public async printWordPressLogs() {
+        if (!this.php) {
+            return;
+        }
+        const linesToShow = this.numberOfLogLinesToShow();
+        if (linesToShow === 0) {
+            return;
+        }
+        const logPath = `/tmp/debug.log`;
+        if (await this.php.fileExists(logPath)) {
+            const rawLogs =  await this.php.readFileAsText(logPath);
+            const logs = rawLogs.split('\n').slice(-linesToShow).join('\n');
+            console.log(logs);
+        }
+    }
+
+};
+
+let logger: Logger | undefined = undefined;
+
+export function get_logger(php?: UniversalPHP | BasePHP): Logger {
+    if (!logger) {
+        logger = new Logger(php as UniversalPHP);
+    }
+    return logger;
+}

packages/playground/remote/src/lib/playground-mu-plugin/0-playground.php

@@ -1,7 +1,9 @@
 <?php
 
+require(__DIR__ . '/playground-includes/playground_logger.php');
+
 /**
- * This is a temporary workaround to hide the 32bit integer warnings that 
+ * This is a temporary workaround to hide the 32bit integer warnings that
  * appear when using various time related function, such as strtotime and mktime.
  * Examples of the warnings that are displayed:
  * Warning: mktime(): Epoch doesn't fit in a PHP integer in <file>
@@ -29,19 +31,19 @@ function () {
 );
 
 /**
- * Because the in-browser Playground doesn't have access to the internet, 
- * network-dependent features like directories don't work. Normally, you'll 
+ * Because the in-browser Playground doesn't have access to the internet,
+ * network-dependent features like directories don't work. Normally, you'll
  * see a confusing message like "An unexpected error occurred." This mu-plugin
  * makes it more clear that the feature is not yet supported.
- * 
+ *
  * https://github.com/WordPress/wordpress-playground/issues/498
- * 
+ *
  * Added styling to hide the Popular tags section of the Plugins page
  * and the nonfunctional Try Again button (both Plugins and Themes) that's
  * appended when the message is displayed.
- * 
+ *
  * https://github.com/WordPress/wordpress-playground/issues/927
- * 
+ *
  */
 add_action('admin_head', function () {
   echo '<style>
@@ -90,7 +92,7 @@ function networking_disabled() {
  * the sandbox attribute. What they really should be targeting is the
  * playground iframe itself (name="playground"). This mu-plugin rewrites
  * all target="_top" links to target="playground" instead.
- * 
+ *
  * https://github.com/WordPress/wordpress-playground/issues/266
  */
 add_action('admin_print_scripts', function () {
@@ -129,9 +131,9 @@ function networking_disabled() {
  * The default WordPress requests transports have been disabled
  * at this point. However, the Requests class requires at least
  * one working transport or else it throws warnings and acts up.
- * 
+ *
  * This mu-plugin provides that transport. It's one of the two:
- * 
+ *
  * * WP_Http_Fetch – Sends requests using browser's fetch() function.
  *                   Only enabled when PHP was compiled with the VRZNO
  * 					 extension.
@@ -154,10 +156,10 @@ function networking_disabled() {
 	/**
 	 * Disable signature verification as it doesn't seem to work with
 	 * fetch requests:
-	 * 
+	 *
 	 * https://downloads.wordpress.org/plugin/classic-editor.zip returns no signature header.
 	 * https://downloads.wordpress.org/plugin/classic-editor.zip.sig returns 404.
-	 * 
+	 *
 	 * @TODO Investigate why.
 	 */
 	add_filter('wp_signature_hosts', function ($hosts) {
@@ -175,4 +177,4 @@ function networking_disabled() {
 		$transports[] = 'Dummy';
 		return $transports;
 	});
-}
+}

packages/playground/remote/src/lib/playground-mu-plugin/playground-includes/playground_logger.php

@@ -0,0 +1,65 @@
+<?php
+// Configure error logging
+// @TODO use the WordPress directory
+$log_file = '/tmp/debug.log';
+error_reporting(E_ALL);
+define('ERROR_LOG_FILE', $log_file);
+ini_set('error_log', $log_file);
+
+/**
+ * Get OpenTracing severity text from PHP error code
+ *
+ * @param int $code PHP error code
+ * @return int OpenTracing severity text
+ */
+function get_severity_text($code)
+{
+    switch ($code) {
+        case E_ERROR:
+        case E_CORE_ERROR:
+        case E_COMPILE_ERROR:
+        case E_USER_ERROR:
+            return 'Error';
+        case E_WARNING:
+        case E_CORE_WARNING:
+        case E_COMPILE_WARNING:
+        case E_USER_WARNING:
+            return 'Warning';
+        case E_NOTICE:
+        case E_USER_NOTICE:
+            return 'Info';
+        default:
+            return 'Debug';
+    }
+}
+
+/**
+ * Send log message to JS
+ */
+function playground_error_handler($errno, $errstr, $errfile, $errline)
+{
+    post_message_to_js(
+        json_encode([
+            'event' => 'wordpress-log',
+            'timestamp' => time(),
+            'severityText' => get_severity_text($errno),
+            'body' => "$errstr in $errfile on line $errline",
+        ])
+    );
+    return false;
+}
+
+set_error_handler('playground_error_handler', E_ALL);
+
+/**
+ * Collect last error on shutdown
+ */
+function collect_last_error_on_shutdown()
+{
+    $error = error_get_last();
+    if ($error !== null) {
+        playground_error_handler($error['type'], $error['message'], $error['file'], $error['line']);
+    }
+}
+
+register_shutdown_function('collect_last_error_on_shutdown');

packages/playground/remote/src/lib/worker-thread.ts

@@ -37,6 +37,8 @@ import transportFetch from './playground-mu-plugin/playground-includes/wp_http_f
 /** @ts-ignore */
 import transportDummy from './playground-mu-plugin/playground-includes/wp_http_dummy.php?raw';
 /** @ts-ignore */
+import playgroundLogger from './playground-mu-plugin/playground-includes/playground_logger.php?raw';
+/** @ts-ignore */
 import playgroundMuPlugin from './playground-mu-plugin/0-playground.php?raw';
 import { joinPaths, randomString } from '@php-wasm/util';
 
@@ -275,6 +277,7 @@ try {
 		'0-playground.php': playgroundMuPlugin,
 		'playground-includes/wp_http_dummy.php': transportDummy,
 		'playground-includes/wp_http_fetch.php': transportFetch,
+		'playground-includes/playground_logger.php': playgroundLogger,
 	});
 
 	if (virtualOpfsDir) {