Page MenuHomePhabricator

/etc/php/php7-fatal-error.php uses unsafe ob_start
Closed, ResolvedPublic

Description

From Logstash, found from the new Parsoid server:

Error
PHP Fatal Error: ob_start(): Cannot use output buffering in output buffering display handlers

#0 [internal function]: MWExceptionHandler::handleFatalError()
#1 {main}
[XbiGXApAICsAAIDkzSEAAAAN] /w/rest.php … … …   PHP Fatal Error from line 57 of /etc/php/php7-fatal-error.php: ob_start(): Cannot use output buffering in output buffering display handlers

_type	parsoid-php
type	parsoid-php
program	mediawiki
mwversion	1.35.0-wmf.3
fatal_error.file	/etc/php/php7-fatal-error.php
fatal_exception.line	57
Source

php7-fatal-error.php

ob_start();
debug_print_backtrace( DEBUG_BACKTRACE_IGNORE_ARGS, 500 );
$trace = ob_get_clean();

Details

Related Gerrit Patches:

Event Timeline

Krinkle created this task.Oct 29 2019, 7:09 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptOct 29 2019, 7:09 PM

It looks like this is caused by at least three different levels of failure.

  1. Some kind of fatal error happens inside MediaWiki PHP, possibly related to Parsoid.
  2. The fatal is either "too fatal" for the PHP set_error_handler callback to be allowed to handle, or MW tried and also failed.
  3. We reach the PHP engine internals where our php-wmerrors extension kicks in to replace the current script with our custom php7-fatal-error handler as last resort to render and log the error.
  4. This last resort also fails, due to unsafe use of ob_start.
  5. This failure is a slightly less severe fatal than the one that led us here, and so the PHP engine still invokes the regular error and shutdown handles, thus kicking it back into MediaWiki core's MWExceptionHandler::handleFatalError callback.
Krinkle moved this task from Limbo to Watching on the Performance-Team (Radar) board.
Krinkle updated the task description. (Show Details)
Anomie added a subscriber: Anomie.Oct 29 2019, 8:01 PM
  1. Some kind of fatal error happens inside MediaWiki PHP, possibly related to Parsoid.

My guess would be that this error happens inside an output buffering display handler.

  1. This last resort also fails, due to unsafe use of ob_start.

That's what presumably makes this one unsafe, where it normally isn't.

@Krinkle Do you have a sense of the severity for this?

After checking php7.2-fpm.log, it looks like #1 is typically an "Allowed memory size of 692060160 bytes exhausted" error. The associated stack traces are all over the code; I don't see obvious evidence for my supposition in T236832#5617220 that it's inside a display handler itself.

Change 553439 had a related patch set uploaded (by Krinkle; owner: Krinkle):
[operations/puppet@production] mediawiki: Avoid unsafe ob_start insnide php7-fatal-error.php

https://gerrit.wikimedia.org/r/553439

Change 553439 merged by Alexandros Kosiaris:
[operations/puppet@production] mediawiki: Avoid unsafe ob_start inside php7-fatal-error.php

https://gerrit.wikimedia.org/r/553439

Looks like we're still getting this from time to time on wtp hosts:

	2019-12-09T02:50:10	wtp1044	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
	2019-12-09T02:50:10	wtp1044	ERR	Unknown: Cannot use output buffering in output buffering display handlers
	2019-12-08T21:25:47	wtp1033	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
	2019-12-08T21:25:47	wtp1033	ERR	Unknown: Cannot use output buffering in output buffering display handlers
	2019-12-08T21:01:59	wtp1041	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
	2019-12-08T21:01:59	wtp1041	ERR	Unknown: Cannot use output buffering in output buffering display handlers
	2019-12-08T19:37:13	wtp1047	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
	2019-12-08T19:37:13	wtp1047	ERR	Unknown: Cannot use output buffering in output buffering display handlers
	2019-12-08T10:39:14	wtp1043	ERR	Unknown: Cannot use output buffering in output buffering display handlers
	2019-12-08T10:39:14	wtp1043	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
	2019-12-08T05:15:53	wtp1040	ERR	PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0

I thought maybe the puppet change didn't propagate to the wtp servers, but that's not the case I realise now.

@fgiunchedi That's the same class of issue, but other than being a violation of the same constraint in PHP, I see no indication that it is caused by php7-fatal-error.php.

It has a different stack trace than the one reported in this task. Or rather, these have no stack trace.

Task description
PHP Fatal Error: ob_start(): Cannot use output buffering in output buffering display handlers
from line 57 of /etc/php/php7-fatal-error.php:
Currently Logstash entries forCannot use output bufferingfrom wpt* servers
PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0

exception.file	"Unknown:0"
exception.message	"Unknown: Cannot use output buffering in output buffering display handlers"
exception.trace	""

Note that all fatal errors from MediaWiki and Parsoid-php in production are caught by and reported through "php7-fatal-error.php". The issue in this task however was an output buffer bug existing in the php7-fatal-error.php script itself. Very confusing, I know :)

Krinkle closed this task as Resolved.Dec 12 2019, 12:58 AM
Krinkle claimed this task.
Krinkle removed a project: Patch-For-Review.

I thought maybe the puppet change didn't propagate to the wtp servers, but that's not the case I realise now.
@fgiunchedi That's the same class of issue, but other than being a violation of the same constraint in PHP, I see no indication that it is caused by php7-fatal-error.php.
It has a different stack trace than the one reported in this task. Or rather, these have no stack trace.

Task description
PHP Fatal Error: ob_start(): Cannot use output buffering in output buffering display handlers
from line 57 of /etc/php/php7-fatal-error.php:
Currently Logstash entries forCannot use output bufferingfrom wpt* servers
PHP Fatal error:  Unknown: Cannot use output buffering in output buffering display handlers in Unknown on line 0
exception.file	"Unknown:0"
exception.message	"Unknown: Cannot use output buffering in output buffering display handlers"
exception.trace	""

Note that all fatal errors from MediaWiki and Parsoid-php in production are caught by and reported through "php7-fatal-error.php". The issue in this task however was an output buffer bug existing in the php7-fatal-error.php script itself. Very confusing, I know :)

hah! Confusing indeed, thanks for the explanation and resolving this task :)