Page MenuHomePhabricator

PHP warning on some Echo email sending attempts due to mismatching PEAR file versions
Closed, ResolvedPublic

Description

Error

Request ID: XFc2KQpAICIAALvG8PsAAAAO

message
Warning: count(): Parameter must be an array or an object that implements Countable in /usr/share/php/Mail/mimePart.php on line 314
(10.2.2.1)
Warning: count(): Parameter must be an array or an object that implements Countable in /usr/share/php/Mail/mimePart.php on line 314
(10.2.2.1)
trace
#0 /usr/share/php/Mail/mimePart.php(314): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /usr/share/php/Mail/mimePart.php(328): Mail_mimePart->encode()
#2 /srv/mediawiki/php-1.33.0-wmf.14/vendor/pear/mail_mime/Mail/mime.php(1052): Mail_mimePart->encode(string, boolean)
#3 /srv/mediawiki/php-1.33.0-wmf.14/includes/mail/UserMailer.php(345): Mail_mime->get()
#4 /srv/mediawiki/php-1.33.0-wmf.14/includes/mail/UserMailer.php(190): UserMailer::sendInternal(array, MailAddress, string, array, array)
#5 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/Notifier.php(105): UserMailer::send(array, MailAddress, string, array, array)
#6 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/controller/NotificationController.php(362): EchoNotifier::notifyWithEmail(User, EchoEvent)
#7 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/controller/NotificationController.php(114): EchoNotificationController::doNotification(EchoEvent, User, string)
#8 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/model/Event.php(168): EchoNotificationController::notify(EchoEvent, boolean)
#9 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/control/MWOAuthConsumerSubmitControl.php(522): EchoEvent::create(array)
#10 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/control/MWOAuthConsumerSubmitControl.php(420): MediaWiki\Extensions\OAuth\MWOAuthConsumerSubmitControl->notify(MediaWiki\Extensions\OAuth\MWOAuthConsumer, User, string, string)
#11 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/control/MWOAuthSubmitControl.php(76): MediaWiki\Extensions\OAuth\MWOAuthConsumerSubmitControl->processAction(string)
#12 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/frontend/specialpages/SpecialMWOAuthManageConsumers.php(328): MediaWiki\Extensions\OAuth\MWOAuthSubmitControl->submit()
#13 /srv/mediawiki/php-1.33.0-wmf.14/includes/htmlform/HTMLForm.php(660): MediaWiki\Extensions\OAuth\SpecialMWOAuthManageConsumers->MediaWiki\Extensions\OAuth\{closure}(array, OOUIHTMLForm)
#14 /srv/mediawiki/php-1.33.0-wmf.14/includes/htmlform/HTMLForm.php(552): HTMLForm->trySubmit()
#15 /srv/mediawiki/php-1.33.0-wmf.14/includes/htmlform/HTMLForm.php(567): HTMLForm->tryAuthorizedSubmit()
#16 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/frontend/specialpages/SpecialMWOAuthManageConsumers.php(337): HTMLForm->show()
#17 /srv/mediawiki/php-1.33.0-wmf.14/extensions/OAuth/frontend/specialpages/SpecialMWOAuthManageConsumers.php(96): MediaWiki\Extensions\OAuth\SpecialMWOAuthManageConsumers->handleConsumerForm(string)
#18 /srv/mediawiki/php-1.33.0-wmf.14/includes/specialpage/SpecialPage.php(569): MediaWiki\Extensions\OAuth\SpecialMWOAuthManageConsumers->execute(string)
#19 /srv/mediawiki/php-1.33.0-wmf.14/includes/specialpage/SpecialPageFactory.php(558): SpecialPage->run(string)
#20 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(288): MediaWiki\Special\SpecialPageFactory->executePath(Title, RequestContext)
#21 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(862): MediaWiki->performRequest()
#22 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(517): MediaWiki->main()
#23 /srv/mediawiki/php-1.33.0-wmf.14/index.php(42): MediaWiki->run()
#24 /srv/mediawiki/w/index.php(3): require(string)
#25 {main}

Impact

Just two warnings displayed with successful result.

Notes

Not sure if this is Wikimedia-General-or-Unknown or other wikimedia-specific problem, so skipped that.

Event Timeline

revi created this task.Sun, Feb 3, 6:48 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptSun, Feb 3, 6:48 PM
Tgr added a subscriber: Tgr.Sun, Feb 3, 8:43 PM

Have you enabled the PHP7 beta feature?

Tgr renamed this task from PHP warning when disabling an OAuth aaplication to PHP warning when disabling an OAuth application.Sun, Feb 3, 8:44 PM
revi added a comment.Sun, Feb 3, 8:45 PM

Have you enabled the PHP7 beta feature?

Yes, forgot to mention that. Didn't test without PHP7 off.

The full error is

ErrorException /usr/share/php/Mail/mimePart.php:314
PHP Warning: count(): Parameter must be an array or an object that implements Countable
#0 /usr/share/php/Mail/mimePart.php(314): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /usr/share/php/Mail/mimePart.php(328): Mail_mimePart->encode()
#2 /srv/mediawiki/php-1.33.0-wmf.14/vendor/pear/mail_mime/Mail/mime.php(1052): Mail_mimePart->encode(string, boolean)
#3 /srv/mediawiki/php-1.33.0-wmf.14/includes/mail/UserMailer.php(345): Mail_mime->get()
#4 /srv/mediawiki/php-1.33.0-wmf.14/includes/mail/UserMailer.php(190): UserMailer::sendInternal(array, MailAddress, string, array, array)
#5 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/Notifier.php(105): UserMailer::send(array, MailAddress, string, array, array)
#6 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/controller/NotificationController.php(362): EchoNotifier::notifyWithEmail(User, EchoEvent)
#7 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/controller/NotificationController.php(114): EchoNotificationController::doNotification(EchoEvent, User, string)
#8 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/model/Event.php(168): EchoNotificationController::notify(EchoEvent, boolean)
#9 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/DiscussionParser.php(94): EchoEvent::create(array)
#10 /srv/mediawiki/php-1.33.0-wmf.14/extensions/Echo/includes/EchoHooks.php(543): EchoDiscussionParser::generateEventsForRevision(Revision, boolean)
#11 /srv/mediawiki/php-1.33.0-wmf.14/includes/deferred/MWCallableUpdate.php(34): EchoHooks::{closure}()
#12 /srv/mediawiki/php-1.33.0-wmf.14/includes/deferred/DeferredUpdates.php(270): MWCallableUpdate->doUpdate()
#13 /srv/mediawiki/php-1.33.0-wmf.14/includes/deferred/DeferredUpdates.php(216): DeferredUpdates::runUpdate(MWCallableUpdate, Wikimedia\Rdbms\LBFactoryMulti, string, integer)
#14 /srv/mediawiki/php-1.33.0-wmf.14/includes/deferred/DeferredUpdates.php(140): DeferredUpdates::execute(array, string, integer)
#15 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(904): DeferredUpdates::doUpdates(string)
#16 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(728): MediaWiki->restInPeace(string, boolean)
#17 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(751): MediaWiki->{closure}()
#18 /srv/mediawiki/php-1.33.0-wmf.14/includes/MediaWiki.php(550): MediaWiki->doPostOutputShutdown(string)
#19 /srv/mediawiki/php-1.33.0-wmf.14/index.php(42): MediaWiki->run()
#20 /srv/mediawiki/w/index.php(3): require(string)
#21 {main}

(two identical errors per request). Happening about ten times per hour (dashboard). The URLs this happens on vary a lot; seems like a generic Echo error. (Plus an error handling error as those warnings should not be displayed to the user, and in any case MediaWiki should check for error conditions instead of letting PHP error out.) Can't reproduce myself though (but I also can't make Echo send me an email so maybe I just didn't find the right testcase.)

Restricted Application added a project: Growth-Team. · View Herald TranscriptSun, Feb 3, 9:14 PM
Tgr added a comment.Sun, Feb 3, 9:33 PM

I enabled PHP7 on beta, and @-mentioned a test user. The email goes out, there is no error (I tried both HTML and plain text errors). Also, the error volume is way too low for all Echo notifications to be affected.
OTOH OAuth Echo events only happen on some metawiki special pages, and this is happening on all wikis and all kinds of pages (edits, pageviews, API actions...) so not limited to a single type of Echo notification.

Looking at Mail_mimePart, no idea how this error could happen. It's triggered on count($this->subparts), but subparts is initialized on declaration as an array and never changed, so it should not ever be not an array.

Anomie added a subscriber: Anomie.EditedMon, Feb 4, 2:48 PM

Looking at Mail_mimePart, no idea how this error could happen. It's triggered on count($this->subparts), but subparts is initialized on declaration as an array and never changed, so it should not ever be not an array.

In pear/mail_mime version 1.10.2, which we pull in via composer, yes. But the trace shows it's using the version installed from Debian's stretch package instead (at /usr/share/php/Mail/mimePart.php), which is version 1.10.0 and does not initialize the field on declaration meaning it's initialized to null.

Krinkle updated the task description. (Show Details)Mon, Feb 4, 11:20 PM
Krinkle added a subscriber: Krinkle.
From task description:

Request ID: (none displayed).

message
Warning: count(): Parameter must be an array or an object that implements Countable in /usr/share/php/Mail/mimePart.php on line 314

We normally see errors of one of two kinds:

  • Fatal: seen by users, reported from browser with request ID.
  • Non-fatal: not seen by users, reported from Logstash only - with request ID.

Either way, there is always a request ID. Yet, what seems to have occurred here is that a PHP Warning was logged directly into the HTML output stream as part of a regular response. This must never happen. Presumably, this is due to the display_errors INI settings from PHP7 being set incorrectly. For more about that, see T211488.

Krinkle updated the task description. (Show Details)Mon, Feb 4, 11:38 PM

I've added a stack trace for an instance of this warning most closely matching the original report (meta.wikimedia.org Special:OAuthManageConsumers). There were only two on that day, and they have the same trace.

Tgr added a comment.Mon, Feb 4, 11:46 PM

In pear/mail_mime version 1.10.2, which we pull in via composer, yes. But the trace shows it's using the version installed from Debian's stretch package instead (at /usr/share/php/Mail/mimePart.php), which is version 1.10.0 and does not initialize the field on declaration meaning it's initialized to null.

Good catch! Apparently mimePart.php is loaded from the Debian package and mime.php is loaded from the mediawiki/vendor repo. Those are both files from the Mail_Mime PEAR/Composer package. That explains the error then.

Tgr added a comment.Mon, Feb 4, 11:57 PM

T195364: Remove pear/mail packages from WMF MW app servers will fix this specific bug, but things randomly getting loaded from unused PEAR packages seems problematic beyond that. Apparently MediaWiki loads Mail_mime via class autoloader, which resolves to mediawiki/vendor; that file starts with require_once 'PEAR.php'; require_once 'Mail/mimePart.php';. The include path is /srv/mediawiki/php-<version>:/usr/local/lib/php:/usr/share/php so the system version of the files is loaded.

How is that even supposed to work with Composer but without PEAR? Seems like a bug but after the recent exploit they just pulled down their site and left it at that so I can't check. Might be time to switch to a better maintained mail component.

Tgr renamed this task from PHP warning when disabling an OAuth application to PHP warning on some Echo email sending attempts due to mismatching PEAR file versions.Mon, Feb 4, 11:59 PM
Tgr removed projects: Growth-Team, Notifications.

Change 488070 had a related patch set uploaded (by Anomie; owner: Anomie):
[operations/mediawiki-config@master] Preserve Composer's include paths

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

Anomie added a comment.EditedTue, Feb 5, 3:06 PM

How is that even supposed to work with Composer but without PEAR?

To close the loop, that's answered in the description of T215224. TL;DR: Composer's include-path property, and pear/pear-core-minimal.

Change 488070 merged by jenkins-bot:
[operations/mediawiki-config@master] Preserve Composer's include paths

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

Mentioned in SAL (#wikimedia-operations) [2019-02-06T00:16:52Z] <niharika29@deploy1001> Synchronized wmf-config/CommonSettings.php: Preserve Composer's include paths - T215126, T215224 (duration: 01m 40s)

Tgr closed this task as Resolved.EditedWed, Feb 6, 4:14 AM
Tgr assigned this task to Anomie.
Tgr removed a project: Patch-For-Review.

The production error has been fixed; errors drop off at UTC midnight as expected. Between T211488: Audit and sync INI settings as needed between HHVM and PHP 7 and T195364: Remove pear/mail packages from WMF MW app servers I don't think there's any other followup left.