Various PHP warnings are breaking FormattedRCFeed
Closed, ResolvedPublic
Actions

Description

These seem to all occur together

\nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/cache/MessageCache.php on line 594
\nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/cache/MessageCache.php on line 727

\nWarning: __construct() expects exactly 1 parameter, 0 given in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/rcfeed/FormattedRCFeed.php on line 37
\nCatchable fatal error: Argument 1 passed to FormattedRCFeed::__construct() must be an instance of array, undefined variable given in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/rcfeed/FormattedRCFeed.php on line 37

\nWarning: Destructor threw an object exception: exception 'DBTransactionError' with message 'LBFactory::shutdown: transaction round 'MWCallableUpdate::doUpdate' still running.' in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/libs/rdbms/lbfactory/LBFactory.php:210\nStack trace:\n#0 /srv/mediawiki/tags/2017-02-02_07:24:01/includes/libs/rdbms/lbfactory/LBFactory.php(138): LBFactory->commitMasterChanges()\n#1 /srv/mediawiki/tags/2017-02-02_07:24:01/includes/libs/rdbms/lbfactory/LBFactory.php(124): LBFactory->shutdown()\n#2 /srv/mediawiki/tags/2017-02-02_07:24:01/includes/libs/rdbms/lbfactory/LBFactory.php(571): LBFactory->destroy()\n#3 (): LBFactory->__destruct()\n#4 {main}

Might be related to https://gerrit.wikimedia.org/r/#/c/330833/

Related Objects
Search...

View Standalone Graph

This task is connected to more than 200 other tasks. Only direct parents and subtasks are shown here. Use View Standalone Graph to show more of the graph.

Status	Assigned	Task
		· · ·
Open	None	T41480 Issues affecting translatewiki.net
Resolved	thcipriani	T155526 MW-1.29.0-wmf.11 deployment blockers
Resolved	Krinkle	T156996 Various PHP warnings are breaking FormattedRCFeed
		· · ·

Event Timeline

Nikerabbit created this task.Feb 2 2017, 7:42 AM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 2 2017, 7:42 AM

Nikerabbit added a parent task: T41480: Issues affecting translatewiki.net.Feb 2 2017, 7:44 AM

Nikerabbit mentioned this in T156901: Database updater fails.

Nikerabbit renamed this task from Multiple PHP warnings in master to Multiple PHP warnings in master [FormattedRCFeed].Feb 2 2017, 7:47 AM

I could not correlate this with web requests, so likely coming via JobQueue.

We also got a few hundreds of these:

13.09 -rakkaus:#mediawiki-i18n- (29 lines skipped) \nNotice: JobQueueGroup::__destruct: 2 buffered job(s) of type(s) RecentChangesUpdateJob, EnotifNotifyJob never inserted. in 
          /srv/mediawiki/tags/2017-01-23_17:34:04/includes/jobqueue/JobQueueGroup.php on line 449

11.00 -rakkaus:#mediawiki-i18n- (15 lines skipped) [Thu Feb  2 11:00:46 2017] [hphp] [11982:7f84cc7ff700:5089:000006] [] \nNotice: JobQueueGroup::__destruct: 1 buffered job(s) 
          of type(s) RecentChangesUpdateJob never inserted. in /srv/mediawiki/tags/2017-02-02_07:24:01/includes/jobqueue/JobQueueGroup.php on line 449

which

11.16 <+Nikerabbit> Nemo_bis: according to timestamps, it is related to the same issue, but not there always, hence not in my paste

Nemo_bis added a subscriber: Ottomata.Feb 2 2017, 10:17 AM

I'll also note that this is quite spammy for #mediawiki-i18n, and given the schema change for expiring user groups, I am not sure it is safe to rollback to previously deployed version.

This also broke our IRC relay ($wgRCFeeds['irc'] = array( 'formatter' => 'IRCColourfulRCFeedFormatter', ...) ).

What I ended up doing is reverting 39a6e3dc4d84ed55bdcfefad2fa04dd2bcb867bd locally.

After that only these notices show up (suggesting they are caused by something else)

[Thu Feb  2 11:31:08 2017] [hphp] [11982:7f84fe3ff700:6216:000001] [] \nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_10:27:40/includes/cache/MessageCache.php on line 594
[Thu Feb  2 11:31:08 2017] [hphp] [11982:7f84fe3ff700:6216:000002] [] \nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_10:27:40/includes/cache/MessageCache.php on line 727

In T156996#2992713, @Nikerabbit wrote:

After that only these notices show up (suggesting they are caused by something else)

[Thu Feb  2 11:31:08 2017] [hphp] [11982:7f84fe3ff700:6216:000001] [] \nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_10:27:40/includes/cache/MessageCache.php on line 594
[Thu Feb  2 11:31:08 2017] [hphp] [11982:7f84fe3ff700:6216:000002] [] \nNotice: Undefined index: HASH in /srv/mediawiki/tags/2017-02-02_10:27:40/includes/cache/MessageCache.php on line 727

I filed T157033: Notice: Undefined index: HASH in /srv/mediawiki/php-1.29.0-wmf.10/includes/cache/MessageCache.php on line 594 for that one.

If the RCFeed config refactor causes JobQueue issues, reverting before branch cut sounds good to me. @Krinkle?

Krinkle claimed this task.Feb 2 2017, 8:02 PM

Krinkle added a project: Regression.

Change 335693 had a related patch set uploaded (by Krinkle):
rcfeed: FormattedRCFeed constructor should match parent class

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

gerritbot added a project: Patch-For-Review.Feb 2 2017, 8:04 PM

@Ottomata commit rMW39a6e3dc4d84ed55bdcfefad2fa04dd2bcb867bd did not make the branch cut this week so it's not affecting production yet. However it does need fixing before Tuesday. I've submitted https://gerrit.wikimedia.org/r/#/c/335693/ which should address the FormattedRCFeed warning.

Reedy added a project: MW-1.29-release (WMF-deploy-2017-01-31_(1.29.0-wmf.10)).Feb 2 2017, 8:13 PM

Mentioned in SAL (#wikimedia-operations) [2017-02-02T20:14:21Z] <twentyafterfour> rolling back to wmf.9 due to T156996

Change 335693 merged by jenkins-bot:
rcfeed: FormattedRCFeed constructor should match parent class

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

mmodell added a parent task: T155525: MW-1.29.0-wmf.10 deployment blockers.Feb 2 2017, 9:53 PM

Krinkle closed this task as Resolved.Feb 2 2017, 9:54 PM

Krinkle removed a parent task: T155525: MW-1.29.0-wmf.10 deployment blockers.

ReleaseTaggerBot added projects: MW-1.29-release (WMF-deploy-2017-02-07_(1.29.0-wmf.11)), MW-1.29-release-notes.Feb 2 2017, 10:00 PM

Mentioned in SAL (#wikimedia-operations) [2017-02-02T23:33:58Z] <twentyafterfour@tin> Synchronized php-1.29.0-wmf.10/includes/cache/MessageCache.php: deploy I5b84b1ae4a9c7b710ee452c61d7d9d6076ec9e6a refs T156996 (duration: 00m 45s)

Nikerabbit mentioned this in T157106: IRC relay broken in master.Feb 3 2017, 6:52 AM

In T156996#2992713, @Nikerabbit wrote:

This also broke our IRC relay ($wgRCFeeds['irc'] = array( 'formatter' => 'IRCColourfulRCFeedFormatter', ...) ).

Filed as T157106: IRC relay broken in master

I have to reopen:

[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000001] [] \nNotice: Undefined index: formatter in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/rcfeed/FormattedRCFeed.php on line 56
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000002] [] \nNotice: Undefined index: formatter in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/rcfeed/FormattedRCFeed.php on line 56
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000003] [] \nFatal error: Cls: Expected string or object in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/rcfeed/FormattedRCFeed.php on line 56
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000004] [] \nNotice: JobQueueGroup::__destruct: 1 buffered job(s) of type(s) RecentChangesUpdateJob never inserted. in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/jobqueue/JobQueueGroup.php on line 449
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000005] [] \nNotice: Uncommitted DB writes (transaction from Database::query (User::idFromName)). in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/database/Database.php on line 3445
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000006] [] \nNotice: DB transaction writes or callbacks still pending (RecentChange::save). in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/database/Database.php on line 3451
[Fri Feb  3 08:32:28 2017] [hphp] [28680:7fe5b13ff700:18:000007] [] \nWarning: Destructor threw an object exception: exception 'DBTransactionError' with message 'LBFactory::shutdown: transaction round 'MWCallableUpdate::doUpdate' still running.' in /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/lbfactory/LBFactory.php:210\nStack trace:\n#0 /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/lbfactory/LBFactory.php(138): LBFactory->commitMasterChanges()\n#1 /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/lbfactory/LBFactory.php(124): LBFactory->shutdown()\n#2 /srv/mediawiki/tags/2017-02-03_07:22:50/includes/libs/rdbms/lbfactory/LBFactory.php(571): LBFactory->destroy()\n#3 (): LBFactory->__destruct()\n#4 {main}

Nikerabbit removed a project: Patch-For-Review.Feb 3 2017, 7:33 AM

hashar added a parent task: T155526: MW-1.29.0-wmf.11 deployment blockers.Feb 3 2017, 2:18 PM

Krinkle renamed this task from Multiple PHP warnings in master [FormattedRCFeed] to PHP Warning: construct() expects exactly 1 parameter in FormattedRCFeed.php.Feb 4 2017, 3:18 AM

Krinkle renamed this task from PHP Warning: construct() expects exactly 1 parameter in FormattedRCFeed.php to Various PHP warnings are breaking FormattedRCFeed.

Krinkle closed this task as Resolved.

Krinkle removed projects: MW-1.29-release-notes, MW-1.29-release (WMF-deploy-2017-02-07_(1.29.0-wmf.11)), MW-1.29-release (WMF-deploy-2017-01-31_(1.29.0-wmf.10)).

Krinkle updated the task description. (Show Details)

Krinkle reopened this task as Open.Feb 4 2017, 3:21 AM

Change 335969 had a related patch set uploaded (by Krinkle):
rcfeed: Ensure formatter (and other params) is passed to RCFeedEngine

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

gerritbot added a project: Patch-For-Review.Feb 4 2017, 3:35 AM

@Nikerabbit Can you verify that patch https://gerrit.wikimedia.org/r/335969 resolves it?

It has been running for some minutes now. I have not spotted any issues.

On beta we have includes/rcfeed/FormattedRCFeed.php that raises: PHP Fatal Error: Cls: Expected string or object

{
  "file": "/srv/mediawiki/php-master/includes/rcfeed/FormattedRCFeed.php",
  "line": 56
},
{
  "file": "/srv/mediawiki/php-master/includes/changes/RecentChange.php",
  "line": 421,
  "function": "notify",
  "class": "FormattedRCFeed",
  "type": "->",
  "args": [
    "RecentChange",
    "string"
  ]
},
{
  "file": "/srv/mediawiki/php-master/includes/logging/LogEntry.php",
  "line": 727,
  "function": "notifyRCFeeds",
  "class": "RecentChange",
  "type": "->",
  "args": []
},
{
  "file": "/srv/mediawiki/php-master/includes/deferred/MWCallableUpdate.php",
  "line": 28,
  "function": "Closure$ManualLogEntry::publish",
  "args": []
},
{
  "file": "/srv/mediawiki/php-master/includes/deferred/DeferredUpdates.php",
  "line": 263,
  "function": "doUpdate",
  "class": "MWCallableUpdate",
  "type": "->",
  "args": []
},
{
  "file": "/srv/mediawiki/php-master/includes/deferred/DeferredUpdates.php",
  "line": 225,
  "function": "runUpdate",
  "class": "DeferredUpdates",
  "type": "::",
  "args": [
    "MWCallableUpdate",
    "LBFactoryMulti",
    "integer"
  ]
},
{
  "file": "/srv/mediawiki/php-master/includes/deferred/DeferredUpdates.php",
  "line": 133,
  "function": "execute",
  "class": "DeferredUpdates",
  "type": "::",
  "args": [
    "array",
    "string",
    "integer"
  ]
},
{
  "file": "/srv/mediawiki/php-master/includes/MediaWiki.php",
  "line": 899,
  "function": "doUpdates",
  "class": "DeferredUpdates",
  "type": "::",
  "args": [
    "string"
  ]
},
{
  "file": "/srv/mediawiki/php-master/includes/MediaWiki.php",
  "line": 728,
  "function": "restInPeace",
  "class": "MediaWiki",
  "type": "->",
  "args": [
    "string"
  ]
},
{
  "function": "Closure$MediaWiki::doPostOutputShutdown",
  "args": []
}