Page MenuHomePhabricator

PHP Warning: Stats: (action_api_modules_hit_total): Stats: (action_api_modules_hit_total) Cannot associate label keys with label values - Not all initialized labels have an assigned value.
Closed, ResolvedPublicPRODUCTION ERROR

Description

Errors
  • service.version: 1.46.0-wmf.5
  • timestamp: 2025-12-03T09:24:05.167Z
  • labels.phpversion: 8.3.26
  • trace.id: fe83e973-f700-4f93-bb53-22c14eebf809
  • Find trace.id in Logstash

Two issues are occurring fr a single request emanating from CounterMetric and TimingMetric.

labels.normalized_message
[{reqId}] {exception_url}   PHP Warning: Stats: (action_api_modules_hit_total): Stats: (action_api_modules_hit_total) Cannot associate label keys with label values - Not all initialized labels have an assigned value.
FrameLocationCall
from/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/CounterMetric.php(64)
#0[internal function]MediaWiki\Exception\MWExceptionHandler::handleError(int, string, string, int)
#1/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/CounterMetric.php(64)trigger_error(string, int)
#2/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/CounterMetric.php(37)Wikimedia\Stats\Metrics\CounterMetric->incrementBy(float)
#3/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiBase.php(2231)Wikimedia\Stats\Metrics\CounterMetric->increment()
#4/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiQuery.php(733)MediaWiki\Api\ApiBase->recordUnifiedMetrics(float)
#5/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(2053)MediaWiki\Api\ApiQuery->execute()
#6/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(956)MediaWiki\Api\ApiMain->executeAction()
#7/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(927)MediaWiki\Api\ApiMain->executeActionWithErrorHandling()
#8/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiEntryPoint.php(138)MediaWiki\Api\ApiMain->execute()
#9/srv/mediawiki/php-1.46.0-wmf.5/includes/MediaWikiEntryPoint.php(184)MediaWiki\Api\ApiEntryPoint->execute()
#10/srv/mediawiki/php-1.46.0-wmf.5/api.php(30)MediaWiki\MediaWikiEntryPoint->run()
#11/srv/mediawiki/w/api.php(3)require(string)
#12{main}
normalized_message
[{reqId}] {exception_url}   PHP Warning: Stats: (action_api_modules_latency): Stats: (action_api_modules_latency) Cannot associate label keys with label values - Not all initialized labels have an assigned value.
FrameLocationCall
from/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/TimingMetric.php(138)
#0[internal function]MediaWiki\Exception\MWExceptionHandler::handleError(int, string, string, int)
#1/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/TimingMetric.php(138)trigger_error(string, int)
#2/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/TimingMetric.php(84)Wikimedia\Stats\Metrics\TimingMetric->addSample(float)
#3/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiBase.php(2241)Wikimedia\Stats\Metrics\TimingMetric->observeNanoseconds(float)
#4/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiQuery.php(733)MediaWiki\Api\ApiBase->recordUnifiedMetrics(float)
#5/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(2053)MediaWiki\Api\ApiQuery->execute()
#6/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(956)MediaWiki\Api\ApiMain->executeAction()
#7/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(927)MediaWiki\Api\ApiMain->executeActionWithErrorHandling()
#8/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiEntryPoint.php(138)MediaWiki\Api\ApiMain->execute()
#9/srv/mediawiki/php-1.46.0-wmf.5/includes/MediaWikiEntryPoint.php(184)MediaWiki\Api\ApiEntryPoint->execute()
#10/srv/mediawiki/php-1.46.0-wmf.5/api.php(30)MediaWiki\MediaWikiEntryPoint->run()
#11/srv/mediawiki/w/api.php(3)require(string)
#12{main}
Impact

Those two are primarily on ruwikinews and ruwiktionary

Notes

Event Timeline

daniel added subscribers: Mooeypoo, daniel.

@Mooeypoo looks like this is related to the API stats you added recently.

Reedy triaged this task as High priority.Dec 3 2025, 2:52 PM

The error has vanished from ruwikinews at 13:56 UTC:

deprecated_warnings.png (555×231 px, 17 KB)

Without ruwikinews and selecting only one of the two errors:

deprecated_non_ruwikinews.png (530×228 px, 14 KB)

If I look at https://ru.wikinews.org/wiki/Special:RecentChanges , at 13:56 @Ladsgroup has deleted a bunch of pages with the reason: Deleting obsolete stat pages ( https://ru.wikinews.org/w/index.php?title=%D0%92%D0%B8%D0%BA%D0%B8%D0%BD%D0%BE%D0%B2%D0%BE%D1%81%D1%82%D0%B8:%D0%A4%D0%BE%D1%80%D1%83%D0%BC/%D0%9E%D0%B1%D1%89%D0%B8%D0%B9&oldid=16808456#Are_these_pages_needed? )

Which in turns link to T403397: Externallinks in Russian Wikinews is unusually large. I have no idea whether that is related, maybe the deleted pages result in less call to the endpoint generating that deprecation.

This is probably related to my patches https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1197699 and https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1197700 since it calls recordUnifiedMetrics which I moved in that patch.

I think i found the issue, but I can't manage to test this locally so I can't be 100% sure.
I think I made a booboo in my "check that variable isn't empty string" check that was supposed to avoid that ^ error. I'm submitting a patch that should fix it.

(Disclaimer: I am on a sick day, so please forgive brainfog issues with the patch or my communication here 😅 )

Change #1214572 had a related patch set uploaded (by Mooeypoo; author: Mooeypoo):

[mediawiki/core@master] Followup I81a2c4de77: Verify stats label values are not empty

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

Change #1214572 merged by jenkins-bot:

[mediawiki/core@master] Followup I81a2c4de77: Verify stats label values are not empty

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

Change #1214647 had a related patch set uploaded (by Jforrester; author: Mooeypoo):

[mediawiki/core@wmf/1.46.0-wmf.5] Followup I81a2c4de77: Verify stats label values are not empty

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

Change #1214647 merged by jenkins-bot:

[mediawiki/core@wmf/1.46.0-wmf.5] Followup I81a2c4de77: Verify stats label values are not empty

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

Mentioned in SAL (#wikimedia-operations) [2025-12-04T09:20:30Z] <hashar@deploy2002> Started scap sync-world: Backport for [[gerrit:1215078|REST: add explicit cast to sitemapSize calcuation to avoid warning (T411580)]], [[gerrit:1214647|Followup I81a2c4: Verify stats label values are not empty (T411585)]]

Mentioned in SAL (#wikimedia-operations) [2025-12-04T09:23:00Z] <hashar@deploy2002> jforrester, hashar: Backport for [[gerrit:1215078|REST: add explicit cast to sitemapSize calcuation to avoid warning (T411580)]], [[gerrit:1214647|Followup I81a2c4: Verify stats label values are not empty (T411585)]] synced to the testservers (see https://wikitech.wikimedia.org/wiki/Mwdebug). Changes can now be verified there.

Mentioned in SAL (#wikimedia-operations) [2025-12-04T09:30:29Z] <hashar@deploy2002> Finished scap sync-world: Backport for [[gerrit:1215078|REST: add explicit cast to sitemapSize calcuation to avoid warning (T411580)]], [[gerrit:1214647|Followup I81a2c4: Verify stats label values are not empty (T411585)]] (duration: 09m 59s)

As to not loose a couple of remarks that were made on the change and its backport, I am pasting them here:


@BPirkle wrote on https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1214572/comment/63b33e50_08fa7ca0/ :

I'd be slightly happier if we documented/enforced that $detailLabels must be an array of strings, or else checked that $value is a string here (and also in the similar check below) before calling strlen on it.

But I don't see a way that is isn't a string, and the current code before this patch is causing a production warning, so that can be left as a followup improvement.


@CDanis wrote on https://gerrit.wikimedia.org/r/c/mediawiki/core/+/1214647/comment/dabe00f6_5e695d6e/ :

I'm concerned that this unrestricted array (note: $detailLabels) combined with the array_merge() lower down will be a footgun.

https://www.mediawiki.org/wiki/Manual:Stats#Labels

Metrics must exist with the same consistent label keys across all measurements. Labels may not conditionally exist. Use a neutral value like "none" or "unknown" if needed.

The docstring indicates this label set is permissive, allowing additional labels. Doing this will throw an error if a second sample is sent with a different set of label keys. In addition, the quality of the metrics will be degraded if the label sets aren't consistent e.g. some captured samples excluded at query time because the label set wasn't consistent.


And I guess that can be further discussed here on T411585 as follow-up actions (or feel free to file additional task / a change or whatever ;) ).

After deploying the patch there is another issue surfacing, I am adding it on the same task rather than filing one cause that sounds more or less related or at least under the same context. That is only appearing on ruwiki and we got only 160 of them over 90 minutes:

  • service.version: 1.46.0-wmf.5
  • timestamp: 2025-12-04T09:49:15.476Z
  • labels.phpversion: 8.3.26
  • trace.id: 649f19b7-7dac-4f9a-96b3-000593b1de50
  • Find trace.id in Logstash

below is action_api_modules_latency, it also happens for action_api_modules_hit_total

labels.normalized_message
[{reqId}] {exception_url}   PHP Warning: Stats: (action_api_modules_latency) Cannot add labels to a metric containing samples
FrameLocationCall
from/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/MetricTrait.php(89)
#0[internal function]MediaWiki\Exception\MWExceptionHandler::handleError(int, string, string, int)
#1/srv/mediawiki/php-1.46.0-wmf.5/includes/libs/Stats/Metrics/MetricTrait.php(89)trigger_error(string, int)
#2/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiBase.php(2238)Wikimedia\Stats\Metrics\TimingMetric->setLabel(string, string)
#3/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiQuery.php(733)MediaWiki\Api\ApiBase->recordUnifiedMetrics(float)
#4/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(2053)MediaWiki\Api\ApiQuery->execute()
#5/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(956)MediaWiki\Api\ApiMain->executeAction()
#6/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiMain.php(927)MediaWiki\Api\ApiMain->executeActionWithErrorHandling()
#7/srv/mediawiki/php-1.46.0-wmf.5/includes/Api/ApiEntryPoint.php(138)MediaWiki\Api\ApiMain->execute()
#8/srv/mediawiki/php-1.46.0-wmf.5/includes/MediaWikiEntryPoint.php(184)MediaWiki\Api\ApiEntryPoint->execute()
#9/srv/mediawiki/php-1.46.0-wmf.5/api.php(30)MediaWiki\MediaWikiEntryPoint->run()
#10/srv/mediawiki/w/api.php(3)require(string)
#11{main}

This is still logging over 700k messages per hour.

image.png (1,040×300 px, 36 KB)

IMHO that’s borderline UBN. For example, logspam-watch on mwlog1002 isn’t even starting anymore, presumably because there are so many messages to summarize.
image.png (538×62 px, 8 KB)

(Edit: It eventually loaded, but if it only refreshes once every >5 minutes then it’s not super useful for seeing new errors quickly.)

ApiBase::recordUnifiedMetrics()
// Hit metrics
$metricHitStats = $this->getMain()->getStatsFactory()->getCounter( 'action_api_modules_hit_total' )
	->setLabel( 'api_type', 'ACTION_API' );
foreach ( $metricsLabels as $label => $value ) {
	if ( strlen( $value ) > 0 ) {
		$metricHitStats->setLabel( $label, $value );
	}
}
$metricHitStats->increment();

// Latency metrics
$metricLatencyStats = $this->getMain()->getStatsFactory()->getTiming( 'action_api_modules_latency' )
	->setLabel( 'api_type', 'ACTION_API' );
foreach ( $metricsLabels as $label => $value ) {
	if ( strlen( $value ) > 0 ) {
		$metricLatencyStats->setLabel( $label, $value );
	}
}
$metricLatencyStats->observeNanoseconds( $latency );

Doesn’t this code violate the metrics guidelines?

Metrics must exist with the same consistent label keys across all measurements. Labels may not conditionally exist. Use a neutral value like "none" or "unknown" if needed.

This is also blocking deployments (pictured: SpiderPig #1040, unless the deployer is aware of the issue and ignores the canary failures:

image.png (1,862×443 px, 164 KB)

Reedy raised the priority of this task from High to Unbreak Now!.Dec 4 2025, 3:21 PM
Reedy subscribed.

In a 15 minute period...

Screenshot 2025-12-04 at 15.20.27.png (929×172 px, 48 KB)

Yes, you're right that the labels should be set -- this was an oversight!
I have this ticket now to fix it more systemically T411793: Fortify new API metrics method

I've submitted a fix for the above problems: https://gerrit.wikimedia.org/r/1215203 Please help review; I hope this catches the things that were missed in the previous review cycles. Thanks for the help on this!

Thanks @Lucas_Werkmeister_WMDE and @Reedy , it turns out on my copy of MediaWiki New Errors ECS had some extra filters which hiding the spam of logs :(

Thanks @Mooeypoo for the followup patch!

Jdforrester-WMF claimed this task.
Jdforrester-WMF subscribed.

Back-ported and noise is gone.