Fatal from CirrusSearch\Job\LinksUpdate: "Call to a member function getLogVariables() on null"
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Assigned To

Authored By

	Krinkle
	Jul 10 2019, 5:36 PM

Description

Error

Request URL:
Request ID: INSERT_ID

message

Fatal Error:
Call to a member function getLogVariables() on null

trace

#0 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/BuildDocument/RedirectsAndIncomingLinks.php(178): CirrusSearch\ElasticsearchIntermediary->failure(Elastica\Exception\RuntimeException)
#1 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/BuildDocument/RedirectsAndIncomingLinks.php(95): CirrusSearch\BuildDocument\RedirectsAndIncomingLinks->realFinishBatch(array)
#2 /srv/mediawiki/php-1.34.0-wmf.13/includes/Hooks.php(174): CirrusSearch\BuildDocument\RedirectsAndIncomingLinks::finishBatch(array)
#3 /srv/mediawiki/php-1.34.0-wmf.13/includes/Hooks.php(202): Hooks::callHook(string, array, array, NULL)
#4 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/Updater.php(475): Hooks::run(string, array)
#5 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/Updater.php(236): CirrusSearch\Updater->buildDocumentsForPages(array, integer)
#6 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/Updater.php(114): CirrusSearch\Updater->updatePages(array, integer)
#7 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/Job/LinksUpdate.php(51): CirrusSearch\Updater->updateFromTitle(Title)
#8 /srv/mediawiki/php-1.34.0-wmf.13/extensions/CirrusSearch/includes/Job/JobTraits.php(137): CirrusSearch\Job\LinksUpdate->doJob()
#9 /srv/mediawiki/php-1.34.0-wmf.13/extensions/EventBus/includes/JobExecutor.php(64): CirrusSearch\Job\CirrusTitleJob->run()
#10 /srv/mediawiki/rpc/RunSingleJob.php(76): JobExecutor->execute(array)

Impact

(To be determined.)

Presumably some pages are not having their search index updated and thus may be stale (with no known correction or retry).

Notes

From Logstash:

Started yesterday (2019-07-09 14:31 UTC).
Affecting both 1.34-wmf.11 and 1.34-wmf.13.
Only seen from PHP 7.2 processes.

Details

Subject	Repo	Branch	Lines +/-
RedirectsAndIncomingLinks: succeede or fail, but not both	mediawiki/extensions/CirrusSearch	master	+33 -3
Log failing RedirectsAndIncomingLinks searches	mediawiki/extensions/CirrusSearch	master	+19 -0
RedirectsAndIncomingLinks: succeede or fail, but not both	mediawiki/extensions/CirrusSearch	wmf/1.34.0-wmf.13	+33 -3

Customize query in gerrit

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved	PRODUCTION ERROR	EBernhardson	T227691 Fatal from CirrusSearch\Job\LinksUpdate: "Call to a member function getLogVariables() on null"
		Resolved		EBernhardson	T228063 Intermittent connect timeout for CirrusSearch connections

Event Timeline

Krinkle created this task.Jul 10 2019, 5:36 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJul 10 2019, 5:36 PM

Only seen from PHP 7.2 processes.

Ping T219148, @Pchelolo, @jijiki.

Krinkle added subscribers: jijiki, • Pchelolo.Jul 10 2019, 5:37 PM

Given "Affecting both 1.34-wmf.11 and 1.34-wmf.13." can we move forward with the train without an explicit fix for this? Or should we wait?

Krinkle moved this task from Untriaged to Jul2019/1.34.wmf.13+ on the Wikimedia-production-error board.Jul 10 2019, 6:15 PM

The error here will only block a class of secondary numerical data updates, the primary content updates still get pushed into elasticsearch. I've not found the root cause for why this is null in 7.2, but will look into it more. I don't think this needs to block the train unless the log spam is excessive.

These messages are paired with "finishRequest called without staring a request" messages. At a minimum the method is documented as possibly returning null so the call site needs to handle it. More directly we need to figure out why it thinks no request was started.

Change 521948 had a related patch set uploaded (by EBernhardson; owner: EBernhardson):
[mediawiki/extensions/CirrusSearch@master] RedirectsAndIncomingLinks: succeede or fail, but not both

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

gerritbot added a project: Patch-For-Review.Jul 10 2019, 8:22 PM

Change 521948 merged by jenkins-bot:
[mediawiki/extensions/CirrusSearch@master] RedirectsAndIncomingLinks: succeede or fail, but not both

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

Change 521956 had a related patch set uploaded (by Jforrester; owner: EBernhardson):
[mediawiki/extensions/CirrusSearch@wmf/1.34.0-wmf.13] RedirectsAndIncomingLinks: succeede or fail, but not both

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

Change 521960 had a related patch set uploaded (by EBernhardson; owner: EBernhardson):
[mediawiki/extensions/CirrusSearch@master] Log failing RedirectsAndIncomingLinks searches

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

EBernhardson mentioned this in rECIR8c05b3433011: RedirectsAndIncomingLinks: succeede or fail, but not both.Jul 10 2019, 9:52 PM

ReleaseTaggerBot added a project: MW-1.34-notes (1.34.0-wmf.14; 2019-07-16).Jul 10 2019, 10:01 PM

Jdforrester-WMF assigned this task to EBernhardson.Jul 10 2019, 10:47 PM

Change 521956 merged by jenkins-bot:
[mediawiki/extensions/CirrusSearch@wmf/1.34.0-wmf.13] RedirectsAndIncomingLinks: succeede or fail, but not both

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

EBernhardson mentioned this in rECIR1cd9cb07be61: RedirectsAndIncomingLinks: succeede or fail, but not both.Jul 10 2019, 10:56 PM

ReleaseTaggerBot edited projects, added MW-1.34-notes (1.34.0-wmf.13; 2019-07-09); removed MW-1.34-notes (1.34.0-wmf.14; 2019-07-16).Jul 10 2019, 11:00 PM

Mentioned in SAL (#wikimedia-operations) [2019-07-10T23:16:29Z] <jforrester@deploy1001> Synchronized php-1.34.0-wmf.13/extensions/CirrusSearch/includes: T227691 RedirectsAndIncomingLinks: succeede or fail, but not both (duration: 01m 02s)

Deployed.

Change 521960 merged by jenkins-bot:
[mediawiki/extensions/CirrusSearch@master] Log failing RedirectsAndIncomingLinks searches

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

EBernhardson mentioned this in rECIRe1deb4b3dae5: Log failing RedirectsAndIncomingLinks searches.Jul 10 2019, 11:48 PM

ReleaseTaggerBot edited projects, added MW-1.34-notes (1.34.0-wmf.14; 2019-07-16); removed MW-1.34-notes (1.34.0-wmf.13; 2019-07-09).Jul 11 2019, 12:00 AM

Maintenance_bot removed a project: Patch-For-Review.Jul 11 2019, 12:10 AM

Krinkle removed a parent task: T220738: 1.34.0-wmf.13 deployment blockers.Jul 11 2019, 12:34 AM

I've not found the root cause for why this is null in 7.2, but will look into it more. I don't think this needs to block the train unless the log spam is excessive.

Whats happening here is that hhvm uses it's own curl pool implementation, and php 7 uses an external pool via an nginx proxy that runs on the mediawiki servers. This server is giving a low volume of intermittent 504 Gateway Timeout errors. This has a connect timeout of 1s. Doing some testing, i sent 50k requests to https://search.svc.eqiad.wmnet:9243/ from mw1293.eqiad.wmnet. 2 requests tooks longer than 1s, at 1.013s and 3.831s.

It seems there is an underlying network issue to look into here about how it can take a full second for some packets to make it around the DC network.

hashar mentioned this in T228171: InvalidArgumentException: Invalid sort: last_edit_asc=1.Jul 16 2019, 2:58 PM

jijiki closed subtask T228063: Intermittent connect timeout for CirrusSearch connections as Resolved.Jul 18 2019, 10:40 AM

EBernhardson reopened subtask T228063: Intermittent connect timeout for CirrusSearch connections as Open.Jul 30 2019, 4:16 PM

EBernhardson closed subtask T228063: Intermittent connect timeout for CirrusSearch connections as Resolved.

• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:05 PM