Page MenuHomePhabricator
Create Task
Maniphest T343893

TypeError: Argument 1 passed to MediaWiki\Http\Telemetry::overrideRequestId() must be of the type string, null given
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error
message
[2023-08-09T13:54:02.211953+00:00] exception.ERROR: [2815a361380e59dcb6e4e03c] [no req]   TypeError: Argument 1 passed to MediaWiki\Http\Telemetry::overrideRequestId() must be of the type string, null given, called in /srv/mediawiki/tags/2023-08-09_13:50:27/includes/WebRequest.php on line 354 {"exception":"[object] (TypeError(code: 0): Argument 1 passed to MediaWiki\\Http\\Telemetry::overrideRequestId() must be of the type string, null given, called in /srv/mediawiki/tags/2023-08-09_13:50:27/includes/WebRequest.php on line 354 at /srv/mediawiki/tags/2023-08-09_13:50:27/includes/http/Telemetry.php:96)
trace
#0 /srv/mediawiki/tags/2023-08-09_13:50:27/includes/WebRequest.php(354): MediaWiki\\Http\\Telemetry->overrideRequestId()
#1 /srv/mediawiki/tags/2023-08-09_13:50:27/includes/jobqueue/JobRunner.php(320): WebRequest::overrideRequestId()
#2 /srv/mediawiki/tags/2023-08-09_13:50:27/includes/jobqueue/JobRunner.php(228): JobRunner->executeJob()
#3 /srv/mediawiki/tags/2023-08-09_13:50:27/maintenance/runJobs.php(99): JobRunner->run()
#4 /srv/mediawiki/tags/2023-08-09_13:50:27/maintenance/includes/MaintenanceRunner.php(685): RunJobs->execute()
#5 /srv/mediawiki/tags/2023-08-09_13:50:27/maintenance/run.php(51): MediaWiki\\Maintenance\\MaintenanceRunner->run()
#6 {main}
","exception_url":"[no req]","reqId":"2815a361380e59dcb6e4e03c","caught_by":"mwe_handler"} []
Impact

Not yet sure. Issues with running certain jobs where requestId is missing?

Notes

This patch: 940149: http: Propagate tracestate and traceparent headers expects Telemetry::overrideRequestId (called in JobRunner::executeJob) to be called with a string, but the RunnableJob::getRequestId() (used in JobRunner::executeJob implemented in Job::getRequestId()) may return string|null.

Related task: https://phabricator.wikimedia.org/T320559

Details

MediaWiki Version
master
SubjectRepoBranchLines +/-
Revert "http: fix JobRunner overriding requestId with null"mediawiki/coremaster+6 -38
Revert "http: Propagate `tracestate` and `traceparent` headers"mediawiki/coremaster+33 -306
Revert "TelemetryTest: Use `assertSame()` instead of `assertEquals()`"mediawiki/coremaster+4 -4
Revert "Zuul: [mediawiki/extensions/WikiLambda] Add EventLogging dependency"integration/configmaster+1 -1
http: fix JobRunner overriding requestId with nullmediawiki/coremaster+38 -6
Customize query in gerrit

Related Objects

Event Timeline

abi_ triaged this task as High priority.Aug 9 2023, 2:08 PM
abi_ created this task.
Restricted Application added a project: Wikimedia-production-error. · View Herald TranscriptAug 9 2023, 2:08 PM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
abi_ updated the task description. (Show Details)Aug 9 2023, 2:08 PM
abi_ added a comment.Aug 9 2023, 2:16 PM

To temporarily reduce log spam on translatewiki.net, I added the following code:

diff --git a/includes/jobqueue/Job.php b/includes/jobqueue/Job.php
index 679814c83b2..f7130d13f9d 100644
--- a/includes/jobqueue/Job.php
+++ b/includes/jobqueue/Job.php
@@ -210,7 +210,7 @@ abstract class Job implements RunnableJob {
         * @stable to override
         */
        public function getRequestId() {
-               return $this->params['requestId'] ?? null;
+               return $this->params['requestId'] ?? \MediaWiki\Http\Telemetry::getInstance()->getRequestId();
        }
pmiazga added a comment.Aug 9 2023, 2:50 PM

I'll look into it

pmiazga changed the task status from Open to In Progress.Aug 9 2023, 2:57 PM
pmiazga claimed this task.
pmiazga moved this task from Inbox, needs triage to Current Sprint on the MediaWiki-Platform-Team board.
pmiazga added a comment.Aug 9 2023, 3:01 PM

My understanding is that JobRunner uses overrideRequestId() with a null to reset the RequestId - but then after the reset - getting the id will try to get the ID from headers again, and if not present it will regenerate it.

gerritbot added a comment.Aug 9 2023, 3:22 PM

Change 947374 had a related patch set uploaded (by Pmiazga; author: Pmiazga):

[mediawiki/core@master] http: fix JobRunner overriding requestId with null

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

gerritbot added a project: Patch-For-Review.Aug 9 2023, 3:22 PM
gerritbot added a comment.Aug 9 2023, 4:45 PM

Change 947374 merged by jenkins-bot:

[mediawiki/core@master] http: fix JobRunner overriding requestId with null

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

ReleaseTaggerBot added a project: MW-1.41-notes (1.41.0-wmf.22; 2023-08-15).Aug 9 2023, 5:00 PM
Maintenance_bot removed a project: Patch-For-Review.Aug 9 2023, 5:10 PM
Jdforrester-WMF subscribed.Aug 9 2023, 9:26 PM
Jdforrester-WMF added a comment.Aug 9 2023, 9:30 PM

Is this what's causing EventFactoryTest::testPageMoveEventWithRedirectPageId and EventFactoryTest::testRevisionCreationEventContentChangeExists to fail in CI, too? (Blocking WikiLambda merges, and probably others.)

pmiazga added a comment.Aug 10 2023, 10:45 AM

Could be, I didn't have the EventBus extension locally and didn't test it. But yesterday I started working on EventBus patch too, I'll have it ready today

pmiazga added a comment.Aug 10 2023, 10:46 AM

@Jdforrester-WMF - can you link me to the tests that fail?

Jdforrester-WMF added a comment.Aug 10 2023, 1:27 PM
In T343893#9083112, @pmiazga wrote:

@Jdforrester-WMF - can you link me to the tests that fail?

https://integration.wikimedia.org/ci/job/quibble-vendor-mysql-php74-noselenium-docker/118602/console

thcipriani moved this task from Untriaged to Aug 2023 on the Wikimedia-production-error board.Aug 10 2023, 3:12 PM
gerritbot added a comment.Aug 11 2023, 4:46 PM

Change 948114 had a related patch set uploaded (by Jforrester; author: Jforrester):

[mediawiki/core@master] Revert "http: Propagate `tracestate` and `traceparent` headers"

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

gerritbot added a project: Patch-For-Review.Aug 11 2023, 4:46 PM

Change 948162 had a related patch set uploaded (by Jforrester; author: Jforrester):

[mediawiki/core@master] Revert "http: fix JobRunner overriding requestId with null"

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

gerritbot added a comment.Aug 11 2023, 4:48 PM

Change 948163 had a related patch set uploaded (by Jforrester; author: Jforrester):

[mediawiki/core@master] Revert "TelemetryTest: Use `assertSame()` instead of `assertEquals()`"

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

gerritbot added a comment.Aug 11 2023, 4:59 PM

Change 948115 had a related patch set uploaded (by Jforrester; author: Jforrester):

[integration/config@master] Revert "Zuul: [mediawiki/extensions/WikiLambda] Add EventLogging dependency"

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

gerritbot added a comment.Aug 11 2023, 5:00 PM

Change 948115 merged by jenkins-bot:

[integration/config@master] Revert "Zuul: [mediawiki/extensions/WikiLambda] Add EventLogging dependency"

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

Stashbot added a comment.Aug 11 2023, 5:01 PM

Mentioned in SAL (#wikimedia-releng) [2023-08-11T17:01:24Z] <James_F> Zuul: Revert "[mediawiki/extensions/WikiLambda] Add EventLogging dependency", for T343893

Jdforrester-WMF added a comment.Aug 11 2023, 5:13 PM

As I've disabled the CI dependency on EventLogging (and thus EventBus) for WikiLambda, this is no longer blocking our code merges, but it probably blocks others?

pmiazga added a comment.EditedAug 14 2023, 5:05 PM

It has to be something related to the CI configs, I'll look for someone who could help me reproduce this problem locally. I followed @Jdforrester-WMF advice and I loaded a specific set of extensions

wfLoadExtension('EventBus');
wfLoadExtension('EventLogging');
wfLoadExtension('EventStreamConfig');
wfLoadExtension( 'WikimediaMessages' );
wfLoadExtension( 'WikiLambda' );

I had to add EventStreamConfigs, as without it - some tests were failing.

When I run the tests locally on the latest master for core and EventBus - everything passes

I have no name!@4083bee0d2b2:/var/www/html/w$ composer run --timeout=0 phpunit:entrypoint -- --testsuite extensions --exclude-group Broken,ParserFuzz,Stub,Database,Standalone
> phpunit '-c' 'tests/phpunit/suite.xml' '--testsuite' 'extensions' '--exclude-group' 'Broken,ParserFuzz,Stub,Database,Standalone'
Using PHP 8.1.20
PHPUnit 9.5.28 by Sebastian Bergmann and contributors.

.............................................................   61 / 4038 (  1%)
.............................................................  122 / 4038 (  3%)
.............................................................  183 / 4038 (  4%)
.............................................................  244 / 4038 (  6%)
.............................................................  305 / 4038 (  7%)
.............................................................  366 / 4038 (  9%)
.............................................................  427 / 4038 ( 10%)
.............................................................  488 / 4038 ( 12%)
.............................................................  549 / 4038 ( 13%)
.............................................................  610 / 4038 ( 15%)
.............................................................  671 / 4038 ( 16%)
.............................................................  732 / 4038 ( 18%)
.............................................................  793 / 4038 ( 19%)
.............................................................  854 / 4038 ( 21%)
.............................................................  915 / 4038 ( 22%)
.............................................................  976 / 4038 ( 24%)
............................................................. 1037 / 4038 ( 25%)
............................................................. 1098 / 4038 ( 27%)
............................................................. 1159 / 4038 ( 28%)
............................................................. 1220 / 4038 ( 30%)
............................................................. 1281 / 4038 ( 31%)
............................................................. 1342 / 4038 ( 33%)
............................................................. 1403 / 4038 ( 34%)
............................................................. 1464 / 4038 ( 36%)
............................................................. 1525 / 4038 ( 37%)
............................................................. 1586 / 4038 ( 39%)
............................................................. 1647 / 4038 ( 40%)
............................................................. 1708 / 4038 ( 42%)
............................................................. 1769 / 4038 ( 43%)
............................................................. 1830 / 4038 ( 45%)
............................................................. 1891 / 4038 ( 46%)
............................................................. 1952 / 4038 ( 48%)
............................................................. 2013 / 4038 ( 49%)
............................................................. 2074 / 4038 ( 51%)
............................................................. 2135 / 4038 ( 52%)
............................................................. 2196 / 4038 ( 54%)
............................................................. 2257 / 4038 ( 55%)
............................................................. 2318 / 4038 ( 57%)
............................................................. 2379 / 4038 ( 58%)
............................................................. 2440 / 4038 ( 60%)
............................................................. 2501 / 4038 ( 61%)
............................................................. 2562 / 4038 ( 63%)
............................................................. 2623 / 4038 ( 64%)
............................................................. 2684 / 4038 ( 66%)
............................................................. 2745 / 4038 ( 67%)
............................................................. 2806 / 4038 ( 69%)
............................................................. 2867 / 4038 ( 71%)
............................................................. 2928 / 4038 ( 72%)
............................................................. 2989 / 4038 ( 74%)
............................................................. 3050 / 4038 ( 75%)
............................................................. 3111 / 4038 ( 77%)
............................................................. 3172 / 4038 ( 78%)
............................................................. 3233 / 4038 ( 80%)
............................................................. 3294 / 4038 ( 81%)
............................................................. 3355 / 4038 ( 83%)
............................................................. 3416 / 4038 ( 84%)
............................................................. 3477 / 4038 ( 86%)
............................................................. 3538 / 4038 ( 87%)
............................................................. 3599 / 4038 ( 89%)
............................................................. 3660 / 4038 ( 90%)
............................................................. 3721 / 4038 ( 92%)
............................................................. 3782 / 4038 ( 93%)
............................................................. 3843 / 4038 ( 95%)
................................S............................ 3904 / 4038 ( 96%)
............................................................. 3965 / 4038 ( 98%)
............................................................. 4026 / 4038 ( 99%)
............                                                  4038 / 4038 (100%)

Time: 02:15.204, Memory: 262.50 MB

OK, but incomplete, skipped, or risky tests!
Tests: 4038, Assertions: 12527, Skipped: 1.


You should really speed up these slow tests (>50ms)...
 1. 2385ms to run AutoLoaderStructureTest::testAutoloadOrder
 2. 2207ms to run AutoLoaderStructureTest::testAutoLoadConfig
 3. 1906ms to run ScopeStructureTest::testAutoloadNoFileScope with data set "/var/www/html/w/includes/languages/data/ZhConversion.php"
 4. 1472ms to run MediaWiki\\Tests\\Structure\\SettingsTest::testConfigGeneration with data set "docs/config-schema.yaml"
 5. 1358ms to run MediaWiki\\Tests\\Structure\\SettingsTest::testConfigGeneration with data set "includes/config-schema.php"
 6. 1340ms to run MediaWiki\\Tests\\Structure\\SettingsTest::testConfigGeneration with data set "includes/config-vars.php"
 7. 1299ms to run MediaWiki\\Tests\\Structure\\SettingsTest::testConfigGeneration with data set "includes/MainConfigNames.php"
 8. 793ms to run AbstractSchemaValidationTest::testSchemasPassValidation with data set "maintenance/tables.json"
 9. 576ms to run ScopeStructureTest::testAutoloadNoFileScope with data set "/var/www/html/w/includes/parser/Parser.php"
 10. 461ms to run ScopeStructureTest::testAutoloadNoFileScope with data set "/var/www/html/w/includes/HookContainer/HookRunner.php"
...and there are 355 more above your threshold hidden from view

And I'm not able to reproduce this failed CI locally.

Jdforrester-WMF closed this task as Resolved.Aug 16 2023, 10:08 AM

As discussed directly, this is an existing bug and not the fault of the new code. Sorry for the confusion, and thank you for all your help!

DAlangi_WMF added a comment.Aug 16 2023, 3:56 PM
In T343893#9095783, @Jdforrester-WMF wrote:

As discussed directly, this is an existing bug and not the fault of the new code. Sorry for the confusion, and thank you for all your help!

Okay @Jdforrester-WMF. How about the revert patches created, should they be abandoned or is there something else to tackle with the patches?

pmiazga added a comment.Aug 16 2023, 5:25 PM

I'll abandon those.

gerritbot added a comment.Aug 16 2023, 5:26 PM

Change 948163 abandoned by Pmiazga:

[mediawiki/core@master] Revert "TelemetryTest: Use `assertSame()` instead of `assertEquals()`"

Reason:

Not required any more

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

gerritbot added a comment.Aug 16 2023, 5:27 PM

Change 948114 abandoned by Pmiazga:

[mediawiki/core@master] Revert "http: Propagate `tracestate` and `traceparent` headers"

Reason:

Not required any more

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

gerritbot added a comment.Aug 16 2023, 5:27 PM

Change 948162 abandoned by Pmiazga:

[mediawiki/core@master] Revert "http: fix JobRunner overriding requestId with null"

Reason:

Not required any more.

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

Maintenance_bot removed a project: Patch-For-Review.Aug 16 2023, 5:30 PM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL