thumb.php last change was on May 24 :/

https://github.com/wikimedia/mediawiki/commits/master/thumb.php

We should probably use WebResponse which can log where the headers were sent.

Possibly T224491: PHP 7 corruption during deployment (was: PHP 7 fatals on mw1262) related?

Change 514732 had a related patch set uploaded (by Gergő Tisza; owner: Gergő Tisza):
[mediawiki/core@master] Log headers sent errors more usefully in thumb.php

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

Change 514732 merged by jenkins-bot:
[mediawiki/core@master] Log headers sent errors more usefully in thumb.php

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

Change 516495 had a related patch set uploaded (by Krinkle; owner: Gergő Tisza):
[mediawiki/core@wmf/1.34.0-wmf.8] Log headers sent errors more usefully in thumb.php

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

Change 516495 merged by jenkins-bot:
[mediawiki/core@wmf/1.34.0-wmf.8] Log headers sent errors more usefully in thumb.php

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

Mentioned in SAL (#wikimedia-operations) [2019-06-12T18:15:55Z] <krinkle@deploy1001> Synchronized php-1.34.0-wmf.8/thumb.php: T225197 / rMW06b631fae560 (duration: 00m 47s)

New information from this error from the above debug instrumentation:

PHP Warning: Cannot modify header information - headers already sent by (output started at /srv/mediawiki/php-1.34.0-wmf.15/includes/libs/http/MultiHttpClient.php:416)

#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(646): header(string)
#2 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(330): wfThumbError(integer, string, NULL, array)
#3 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(38): wfStreamThumb(array)

PHP Warning: Cannot modify header information - headers already sent by (output started at /srv/mediawiki/php-1.34.0-wmf.15/includes/libs/http/MultiHttpClient.php:416)

#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(683): header(string)
#2 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(330): wfThumbError(integer, string, NULL, array)
#3 /srv/mediawiki/php-1.34.0-wmf.15/thumb.php(38): wfStreamThumb(array)

So looks like MultiHttpClient might be at fault?

This seems to be a secondary error, triggered while trying to report another error. As far as I can tell from looking at the code for five minutes, this seems to be happening:

• In line 321 of thumb.php, we call $status = $img->getRepo()->streamFileWithStatus( $thumbPath, $headers ) which tries to send the file, and starts generating output, but hits an error at some point.
• $status->isOK() returns false in line 324, so wfThumbError() is called in 329.
• wfThumbError() tries to set a header in line 645, which triggers "PHP Warning: Cannot modify header information"

Seems to me like wfThumbError() should not tried to send HTML output if output was already sent.
Also, we should probably log the original error somewhere, somehow. As far as I can tell, that doesn't happen at all.

Change 562592 had a related patch set uploaded (by Daniel Kinzler; owner: Daniel Kinzler):
[mediawiki/core@master] thumb.php: don't try to send errors after data has been sent.

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

Change 562592 merged by jenkins-bot:
[mediawiki/core@master] thumb.php: don't try to send errors after data has been sent.

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

@daniel Remember to enable the thumb channel in production, or, given this is probably temporary instrumentation, perhaps use AdhocDebug instead (and cherry-pick to wmf, leave unmerged in master).

In T225197#5804063, @Krinkle wrote:

@daniel Remember to enable the thumb channel in production, or, given this is probably temporary instrumentation, perhaps use AdhocDebug instead (and cherry-pick to wmf, leave unmerged in master).

The new code reports errors exactly in the same way that is already done if an error occurs before streaming starts. The channel isn't new, and it's not temporary. I'd expect that channel to already be enabled?...

Those two lines using thumb are the only two in the codebase that use that channel. The previous one being introduced in 2015 and never enabled in prod from what I can see. There is however a more common thumbnail channel enabled in prod.

What is the long term purpose of this check? It seems to me not like a runtime error but a logical error in the code. Which, once we find the root cause, can be fixed and then removed. The contract of this function is to produce an http response. Something else making an HTTP response and letting execution continue until here is a bug. I don't think we intend to add similar checks everywhere in the codebase where an HTTP header or some content is output? If not, why is this one special? Note that PHP already covers our basis for the general ability to detect such mistakes from creeping back in (we'd know about it).

In T225197#5806883, @Krinkle wrote:

Those two lines using thumb are the only two in the codebase that use that channel. The previous one being introduced in 2015 and never enabled in prod from what I can see. There is however a more common thumbnail channel enabled in prod.

Good point, perhaps we should use that channel instead.

What is the long term purpose of this check? It seems to me not like a runtime error but a logical error in the code. Which, once we find the root cause, can be fixed and then removed. The contract of this function is to produce an http response. Something else making an HTTP response and letting execution continue until here is a bug. I don't think we intend to add similar checks everywhere in the codebase where an HTTP header or some content is output? If not, why is this one special? Note that PHP already covers our basis for the general ability to detect such mistakes from creeping back in (we'd know about it).

The root cause of the "Cannot modify header information - headers already sent" warning is found and fixed by this patch: it happens when an error occurs during streaming. The old code would try to set a status header, but that would fail because the stream already started. The new code logs the original error instead.

The code that has already started to send a response is indeed known: it's line 326:

$status = $img->getRepo()->streamFileWithStatus( $thumbPath, $headers );

this generates a HTTP response, and returns a Status if something goes wrong. We were previously mishandling the case of something going wrong after output had already started.

Change 565152 had a related patch set uploaded (by Daniel Kinzler; owner: Daniel Kinzler):
[mediawiki/core@master] thumb.php: Use 'thumbnail' channel to report errors

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

Change 565152 merged by jenkins-bot:
[mediawiki/core@master] thumb.php: Use 'thumbnail' channel to report errors

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