Skip to content
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import { generateBackupFilename } from '@studio/common/lib/generate-backup-filen
import { createExportErrorPayload, ExportEvents } from '@studio/common/lib/import-export-events';
import {
LEGACY_MU_PLUGIN_FILENAMES,
STUDIO_ERROR_LOG_FILENAME,
STUDIO_LOADER_MU_PLUGIN_FILENAME,
} from '@studio/common/lib/mu-plugins';
import { parseJsonFromPhpOutput } from '@studio/common/lib/php-output-parser';
Expand Down Expand Up @@ -45,6 +46,7 @@ export class DefaultExporter extends ImportExportEventEmitter implements Exporte
'wp-content/database',
'wp-content/db.php',
'wp-content/debug.log',
`wp-content/${ STUDIO_ERROR_LOG_FILENAME }`,
...prefixedLegacyMuPluginNames,
`wp-content/mu-plugins/${ STUDIO_LOADER_MU_PLUGIN_FILENAME }`,
];
Expand Down
24 changes: 24 additions & 0 deletions apps/cli/lib/read-file-tail.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,24 @@
import { open } from 'fs/promises';

export async function readFileTail( filePath: string, maxBytes: number ): Promise< string > {
const file = await open( filePath, 'r' );
try {
const { size } = await file.stat();
const length = Math.min( size, maxBytes );
if ( length === 0 ) {
return '';
}
const { buffer } = await file.read( {
buffer: Buffer.alloc( length ),
position: size - length,
} );
let tail = buffer.toString( 'utf8' );
if ( length < size ) {
// Drop the first, likely partial, line of a truncated read.
tail = tail.slice( tail.indexOf( '\n' ) + 1 );
}
return tail.trim();
} finally {
await file.close();
}
}
39 changes: 39 additions & 0 deletions apps/cli/lib/tests/read-file-tail.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,39 @@
import { mkdtemp, writeFile } from 'fs/promises';
import { tmpdir } from 'os';
import { join } from 'path';
import { readFileTail } from 'cli/lib/read-file-tail';

describe( 'readFileTail', () => {
let dir: string;

beforeEach( async () => {
dir = await mkdtemp( join( tmpdir(), 'studio-test-tail-' ) );
} );

it( 'should return the whole file when smaller than maxBytes', async () => {
const filePath = join( dir, 'small.log' );
await writeFile( filePath, 'line one\nline two\n' );

expect( await readFileTail( filePath, 1024 ) ).toBe( 'line one\nline two' );
} );

it( 'should return the trailing bytes and drop the partial first line when truncated', async () => {
const filePath = join( dir, 'large.log' );
await writeFile( filePath, 'first line is long\nsecond line\nthird line\n' );

expect( await readFileTail( filePath, 'second line\nthird line\n'.length ) ).toBe(
'third line'
);
} );

it( 'should return an empty string for an empty file', async () => {
const filePath = join( dir, 'empty.log' );
await writeFile( filePath, '' );

expect( await readFileTail( filePath, 1024 ) ).toBe( '' );
} );

it( 'should reject for a missing file', async () => {
await expect( readFileTail( join( dir, 'missing.log' ), 1024 ) ).rejects.toThrow();
} );
} );
70 changes: 70 additions & 0 deletions apps/cli/lib/tests/wordpress-server-manager.test.ts
Original file line number Diff line number Diff line change
@@ -1,4 +1,8 @@
import { EventEmitter } from 'events';
import fs from 'fs';
import os from 'os';
import path from 'path';
import { STUDIO_ERROR_LOG_FILENAME } from '@studio/common/lib/mu-plugins';
import { SITE_RUNTIME_NATIVE_PHP, SITE_RUNTIME_PLAYGROUND } from '@studio/common/lib/site-runtime';
import { vi } from 'vitest';
import { SiteData } from 'cli/lib/cli-config/core';
Expand Down Expand Up @@ -264,6 +268,72 @@ describe( 'WordPress Server Manager', () => {
/early crash/
);
} );

it( 'should append PHP errors captured during the start attempt to the failure', async () => {
const sitePath = await fs.promises.mkdtemp( path.join( os.tmpdir(), 'studio-test-site-' ) );
await fs.promises.mkdir( path.join( sitePath, 'wp-content' ), { recursive: true } );
const logPath = path.join( sitePath, 'wp-content', STUDIO_ERROR_LOG_FILENAME );

setTimeout( () => {
fs.writeFileSync( logPath, 'PHP Fatal error: Uncaught Error: Failed opening required' );
mockBus.emit( 'process-event', {
process: {
name: mockProcessDescription.name,
pm_id: mockProcessDescription.pmId,
},
event: 'exit',
} );
}, 10 );

await expect(
startWordPressServer( { ...mockSiteData, path: sitePath }, mockLogger )
).rejects.toThrow( /Recent PHP errors[\s\S]*PHP Fatal error/ );
} );

it( 'should not append stale PHP errors from a previous run', async () => {
const sitePath = await fs.promises.mkdtemp( path.join( os.tmpdir(), 'studio-test-site-' ) );
await fs.promises.mkdir( path.join( sitePath, 'wp-content' ), { recursive: true } );
// Sites with the debug-log setting on read from debug.log, which Studio
// does not clear on start, so stale entries must be filtered by mtime.
const logPath = path.join( sitePath, 'wp-content', 'debug.log' );
fs.writeFileSync( logPath, 'PHP Fatal error: from a previous run' );
const past = new Date( Date.now() - 60_000 );
fs.utimesSync( logPath, past, past );

setTimeout( () => {
mockBus.emit( 'process-event', {
process: {
name: mockProcessDescription.name,
pm_id: mockProcessDescription.pmId,
},
event: 'exit',
} );
}, 10 );

const error: Error = await startWordPressServer(
{ ...mockSiteData, path: sitePath, enableDebugLog: true },
mockLogger
).then(
() => {
throw new Error( 'expected startWordPressServer to reject' );
},
( e ) => e
);
expect( error.message ).toContain( 'exited before becoming ready' );
expect( error.message ).not.toContain( 'Recent PHP errors' );
} );

it( 'should clear the studio error log from a previous run before starting', async () => {
setupIpcMocks();
const sitePath = await fs.promises.mkdtemp( path.join( os.tmpdir(), 'studio-test-site-' ) );
await fs.promises.mkdir( path.join( sitePath, 'wp-content' ), { recursive: true } );
const logPath = path.join( sitePath, 'wp-content', STUDIO_ERROR_LOG_FILENAME );
fs.writeFileSync( logPath, 'PHP Fatal error: from a previous run' );

await startWordPressServer( { ...mockSiteData, path: sitePath }, mockLogger );

expect( fs.existsSync( logPath ) ).toBe( false );
} );
} );

describe( 'sendWpCliCommand', () => {
Expand Down
55 changes: 55 additions & 0 deletions apps/cli/lib/wordpress-server-manager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import {
PLAYGROUND_CLI_INACTIVITY_TIMEOUT,
PLAYGROUND_CLI_MAX_TIMEOUT,
} from '@studio/common/constants';
import { STUDIO_ERROR_LOG_FILENAME } from '@studio/common/lib/mu-plugins';
import { resolveNativePhpVersion } from '@studio/common/lib/php-binary-metadata';
import {
SITE_RUNTIME_NATIVE_PHP,
Expand All @@ -31,6 +32,7 @@ import {
} from 'cli/lib/daemon-client';
import { ensurePhpBinaryAvailable } from 'cli/lib/dependency-management/php-binary';
import { getSiteRuntime } from 'cli/lib/feature-flags';
import { readFileTail } from 'cli/lib/read-file-tail';
import { ProcessDescription } from 'cli/lib/types/process-manager-ipc';
import { ServerConfig, ManagerMessagePayload } from 'cli/lib/types/wordpress-server-ipc';
import { Logger } from 'cli/logger';
Expand Down Expand Up @@ -231,6 +233,9 @@ export async function startWordPressServer(
const processName = getProcessName( site.id );
const serverConfig = buildServerConfig( site, runtime, options );

const startedAt = Date.now();
await clearStudioErrorLog( site );

const readyOrExit = await subscribeForReadyOrExit( processName );
try {
const processDesc = await startProcess( processName, wordPressServerChildPath, { runtime } );
Expand All @@ -246,11 +251,61 @@ export async function startWordPressServer(
);

return withSiteRuntime( processDesc );
} catch ( error ) {
throw await withCapturedPhpErrors( error, site, startedAt );
} finally {
readyOrExit.dispose();
}
}

async function clearStudioErrorLog( site: SiteData ): Promise< void > {
const logPath = path.join( site.path, 'wp-content', STUDIO_ERROR_LOG_FILENAME );
await fs.promises.rm( logPath, { force: true } ).catch( () => undefined );
}

const PHP_ERROR_TAIL_MAX_BYTES = 4096;

/**
* Appends the PHP errors recorded during this start attempt to a startup
* failure, so users see why WordPress died (e.g. a plugin fatal) instead of
* just "process exited unexpectedly" (STU-1757).
*/
async function withCapturedPhpErrors(
error: unknown,
site: SiteData,
startedAt: number
): Promise< unknown > {
if (
! ( error instanceof Error ) ||
error.name === 'AbortError' ||
error.message === 'Operation aborted'
) {
return error;
}

// With the debug-log setting on, WordPress records errors to debug.log
// instead of the Studio-managed log.
const logFilename = site.enableDebugLog ? 'debug.log' : STUDIO_ERROR_LOG_FILENAME;
const logPath = path.join( site.path, 'wp-content', logFilename );

try {
const stats = await fs.promises.stat( logPath );
// Only surface errors written during this start attempt; debug.log can
// hold stale entries from previous runs.
if ( stats.mtimeMs < startedAt ) {
return error;
}
const tail = await readFileTail( logPath, PHP_ERROR_TAIL_MAX_BYTES );
if ( tail ) {
error.message += `\nRecent PHP errors (${ logPath }):\n${ tail }`;
}
} catch {
// No PHP error log to surface.
}

return error;
}

function buildChildExitedError( processName: string, stderrTail?: string ): Error {
let message = `Server child process "${ processName }" exited before becoming ready.`;
if ( stderrTail?.trim() ) {
Expand Down
13 changes: 12 additions & 1 deletion apps/cli/playground-server-child.ts
Original file line number Diff line number Diff line change
Expand Up @@ -17,7 +17,11 @@ import { DEFAULT_PHP_VERSION } from '@studio/common/constants';
import { isWordPressDirectory } from '@studio/common/lib/fs-utils';
import { IS_JSPI_AVAILABLE } from '@studio/common/lib/jspi';
import { DEFAULT_LOCALE } from '@studio/common/lib/locale';
import { cleanupLegacyMuPlugins, getMuPlugins } from '@studio/common/lib/mu-plugins';
import {
cleanupLegacyMuPlugins,
getMuPlugins,
STUDIO_ERROR_LOG_FILENAME,
} from '@studio/common/lib/mu-plugins';
import { formatPlaygroundCliMessage } from '@studio/common/lib/playground-cli-messages';
import { sequential } from '@studio/common/lib/sequential';
import { isWordPressDevVersion } from '@studio/common/lib/wordpress-version-utils';
Expand Down Expand Up @@ -250,6 +254,13 @@ async function getBaseRunCLIArgs(

const [ studioMuPluginsHostPath, loaderMuPluginHostPath ] = await getMuPlugins( {
isWpAutoUpdating: config.isWpAutoUpdating,
// With the debug-log setting off nothing records PHP errors, leaving
// startup failures undiagnosable (STU-1757). Capture them to a
// Studio-managed log; `startWordPressServer` reads it back when the
// start fails.
...( config.enableDebugLog
? {}
: { errorLogPath: `/wordpress/wp-content/${ STUDIO_ERROR_LOG_FILENAME }` } ),
} );

if ( ! useExactMountLayout ) {
Expand Down
9 changes: 8 additions & 1 deletion apps/cli/process-manager-daemon.ts
Original file line number Diff line number Diff line change
Expand Up @@ -251,7 +251,14 @@ export class ProcessManagerDaemon {

this.managedProcesses.set( pmId, managedProcess );

this.pipeOutputWithTimestamp( child.stdout, stdoutStream );
this.pipeOutputWithTimestamp( child.stdout, stdoutStream, ( line ) => {
// Playground CLI prints boot failures to stdout (with the noisy
// crash-page HTML on the following lines); keep the error line in
// the exit tail so start failures carry a reason.
if ( line.startsWith( 'Error:' ) ) {
this.recordStderrLine( managedProcess, line );
}
} );
this.pipeOutputWithTimestamp( child.stderr, stderrStream, ( line ) => {
this.recordStderrLine( managedProcess, line );
} );
Expand Down
45 changes: 45 additions & 0 deletions apps/cli/tests/daemon.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -179,6 +179,51 @@ describe( 'ProcessManagerDaemon', () => {
expect( payload.stderrTail ).toContain( 'at Module._compile' );
} );

it( 'includes stdout error lines in the exit event payload, skipping other stdout output', async () => {
const child = new MockChildProcess();
spawnMock.mockReturnValue( child );
const { ProcessManagerDaemon } = await import( '../process-manager-daemon' );

const daemon = new ProcessManagerDaemon();
const daemonInternal = daemon as unknown as {
handleRequest: ( request: unknown ) => Promise< unknown >;
broadcastEvent: ( event: unknown ) => Promise< void >;
};
const broadcastSpy = vi
.spyOn( daemonInternal, 'broadcastEvent' )
.mockResolvedValue( undefined );

await daemonInternal.handleRequest( {
type: 'start-process',
requestId: '1',
processName: testProcessName,
scriptPath: '/tmp/test-child.js',
env: {},
args: [],
} );

// Playground CLI prints boot failures to stdout, followed by the crash-page HTML.
child.stdout.write( 'WordPress Playground CLI\n' );
child.stdout.write( 'Error: PHP.run() failed with exit code 255.\n' );
child.stdout.write( '<!DOCTYPE html>\n' );
// Let readline consume the lines before triggering exit.
await new Promise( ( resolve ) => setTimeout( resolve, 25 ) );

child.emit( 'exit', 1 );
await new Promise( ( resolve ) => setTimeout( resolve, 25 ) );

const exitCall = broadcastSpy.mock.calls.find( ( [ event ] ) => {
const payload = ( event as { type: string; payload: { event: string } } ).payload;
return payload.event === 'exit';
} );

expect( exitCall ).toBeDefined();
const payload = ( exitCall![ 0 ] as { payload: { stderrTail?: string } } ).payload;
expect( payload.stderrTail ).toContain( 'Error: PHP.run() failed with exit code 255.' );
expect( payload.stderrTail ).not.toContain( 'DOCTYPE' );
expect( payload.stderrTail ).not.toContain( 'WordPress Playground CLI' );
} );

it( 'reuses duplicate starts, forwards messages, and resolves missing stops', async () => {
const child = new MockChildProcess();
spawnMock.mockReturnValue( child );
Expand Down
31 changes: 31 additions & 0 deletions tools/common/lib/mu-plugins.ts
Original file line number Diff line number Diff line change
Expand Up @@ -14,11 +14,18 @@ export interface MuPlugin {
content: string;
}

// Written inside the site's wp-content directory by the 0-error-capture
// mu-plugin; read back by the CLI when `site start` fails.
export const STUDIO_ERROR_LOG_FILENAME = 'studio-error.log';

export type MuPluginRuntime = 'playground' | 'native-php';

export interface MuPluginOptions {
isWpAutoUpdating?: boolean;
runtime?: MuPluginRuntime;
// PHP errors are captured to this path (as seen by PHP, e.g. a VFS path
// for the Playground runtime) even when WP debug logging is off.
errorLogPath?: string;
}

/**
Expand Down Expand Up @@ -165,6 +172,30 @@ function getStandardMuPlugins( options: MuPluginOptions ): MuPlugin[] {
`,
} );

// Capture PHP errors while the user's debug-log setting is off, so site
// start failures (e.g. a plugin fatal during WordPress load) remain
// diagnosable. The path is baked in at write time because blueprint
// constants are not yet applied during the first boot request — exactly
// the one that fails (STU-1757). Playground's platform mu-plugins disable
// log_errors when WP_DEBUG_LOG is falsy and load after the Studio ones,
// so re-assert from a late muplugins_loaded hook in addition to setting
// immediately (the hook still fires within the current do_action pass).
if ( options.errorLogPath ) {
muPlugins.push( {
filename: '0-error-capture.php',
content: `<?php
$studio_enable_error_capture = function () {
ini_set( 'log_errors', '1' );
ini_set( 'error_log', '${ escapePhpSingleQuotedString( options.errorLogPath ) }' );
};
$studio_enable_error_capture();
if ( function_exists( 'add_action' ) ) {
add_action( 'muplugins_loaded', $studio_enable_error_capture, PHP_INT_MAX );
}
`,
} );
}

// HTTPS detection for reverse proxy
muPlugins.push( {
filename: '0-https-for-reverse-proxy.php',
Expand Down
Loading
Loading