Page MenuHomePhabricator

PHP Notice: Undefined index: queries
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error

MediaWiki version: 1.36.0-wmf.20

message
PHP Notice: Undefined index: queries

Impact

Unknown

Notes

About five or six similar errors (different undefined indices) accompanied this one in the same request(s) across different days.

Details

Request ID
X9DyDwpAICoAAK6FjawAAAEH
Request URL
https://www.wikidata.org/wiki/Special:EntityData/Q148.rdf
Stack Trace
exception.trace
#0 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/TransactionProfiler.php(375): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/TransactionProfiler.php(247): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated(string, Wikimedia\Rdbms\GeneralizedSql, integer)
#2 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(1412): Wikimedia\Rdbms\TransactionProfiler->recordQueryCompletion(Wikimedia\Rdbms\GeneralizedSql, double, boolean, integer)
#3 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(1294): Wikimedia\Rdbms\Database->executeQueryAttempt(string, string, boolean, string, integer)
#4 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(1223): Wikimedia\Rdbms\Database->executeQuery(string, string, integer)
#5 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(4812): Wikimedia\Rdbms\Database->query(string, string, integer)
#6 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(706): Wikimedia\Rdbms\Database->ping(NULL)
#7 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(4636): Wikimedia\Rdbms\Database->pingAndCalculateLastTrxApplyTime()
#8 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/database/Database.php(928): Wikimedia\Rdbms\Database->rollback(string, string)
#9 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1573): Wikimedia\Rdbms\Database->close(string, integer)
#10 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(2154): Wikimedia\Rdbms\LoadBalancer->Wikimedia\Rdbms\{closure}(Wikimedia\Rdbms\DatabaseMysqli)
#11 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1574): Wikimedia\Rdbms\LoadBalancer->forEachOpenConnection(Closure)
#12 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1560): Wikimedia\Rdbms\LoadBalancer->closeAll(string, integer)
#13 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/lbfactory/LBFactory.php(244): Wikimedia\Rdbms\LoadBalancer->disable(string, integer)
#14 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/lbfactory/LBFactoryMulti.php(222): Wikimedia\Rdbms\LBFactory->Wikimedia\Rdbms\{closure}(Wikimedia\Rdbms\LoadBalancer, string, array)
#15 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/lbfactory/LBFactory.php(246): Wikimedia\Rdbms\LBFactoryMulti->forEachLB(Closure, array)
#16 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/lbfactory/LBFactory.php(176): Wikimedia\Rdbms\LBFactory->forEachLBCallMethod(string, array)
#17 /srv/mediawiki/php-1.36.0-wmf.20/includes/libs/rdbms/lbfactory/LBFactory.php(811): Wikimedia\Rdbms\LBFactory->destroy()
#18 [internal function]: Wikimedia\Rdbms\LBFactory->__destruct()
#19 {main}

Event Timeline

It is failing on $this->expectBy[$expect], because the array access to $this->expect[$expect] is also done before the function is called and safe.

expectBy is only set in one function (setExpectation) when the value in expect is changed.

From the first look it looks sane and expectBy should be set (not in case of INF, but than the report is not reached)

class TransactionProfiler implements LoggerAwareInterface {
...
	public function setExpectation( $event, $value, $fname ) {
		$this->expect[$event] = isset( $this->expect[$event] )
			? min( $this->expect[$event], $value )
			: $value;
		if ( $this->expect[$event] == $value ) {
			$this->expectBy[$event] = $fname;
		}
	}
...
	public function recordQueryCompletion( $query, $sTime, $isWrite = false, $n = 0 ) {
...
		if ( $this->hits['queries']++ >= $this->expect['queries'] ) {
			$this->reportExpectationViolated( 'queries', $query, $this->hits['queries'] );
		}
...
	protected function reportExpectationViolated( $expect, $query, $actual ) {
		if ( $this->silenced ) {
			return;
		}

		$this->logger->warning(
			"Expectation ({measure} <= {max}) by {by} not met (actual: {actual}):\n{query}\n",
			[
				'measure' => $expect,
				'max' => $this->expect[$expect],
				'by' => $this->expectBy[$expect],
				'actual' => $actual,
				'query' => self::queryString( $query ),
				'exception' => new RuntimeException()
			]
		);
	}
...

Change 666508 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] rdbms: avoid undefined "expectBy" notices in TransactionProfiler

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

Change 666508 merged by jenkins-bot:
[mediawiki/core@master] rdbms: avoid undefined "expectBy" notices in TransactionProfiler

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

Change 672555 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] rdbms: avoid undefined "expectBy" notices in TransactionProfiler (II)

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

Change 672587 had a related patch set uploaded (by Krinkle; owner: Aaron Schulz):
[mediawiki/core@wmf/1.36.0-wmf.35] rdbms: avoid undefined "expectBy" notices in TransactionProfiler (II)

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

Change 672555 merged by jenkins-bot:
[mediawiki/core@master] rdbms: avoid undefined "expectBy" notices in TransactionProfiler (II)

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

Change 672587 merged by jenkins-bot:
[mediawiki/core@wmf/1.36.0-wmf.35] rdbms: avoid undefined "expectBy" notices in TransactionProfiler (II)

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