Page MenuHomePhabricator

onMwLoadEnd test failing regularly blocking mergings across repositories
Closed, ResolvedPublicBUG REPORT

Description

This test appears to be flakey. It's become a common occurrence in unrelated changes for example https://gerrit.wikimedia.org/r/c/mediawiki/core/+/753757/ and https://gerrit.wikimedia.org/r/c/mediawiki/skins/Vector/+/753990.

✖ 1 test failed
04:29:04 
04:29:04 FAILED TESTS:
04:29:04   ext.navigationTiming
04:29:04     ✖ onMwLoadEnd - controlled
04:29:04       Chrome Headless 90.0.4430.212 (Linux x86_64)
04:29:04     resolved after fail+ok
04:29:04     Expected: [
04:29:04       "call"
04:29:04     ]
04:29:04     Actual: []
04:29:04         at Object.<anonymous> (http://localhost:9876/load.php?modules=mediawiki.interface.helpers.styles%7Cmediawiki.jqueryMsg%2Clanguage%2CmessagePoster%2Cpulsatingdot%2Cqunit-testrunner%2Crouter%2Cstorage%2Ctemplate%2Ctoc%2Cui%2Cuser%2Cutil%2Cviewport%2CvisibleTimeout%2Cwidgets%7Cmediawiki.language.months%2Cnames%2CspecialCharacters%2Ctestdata%7Cmediawiki.libs.guiders%2Cjpegmeta%2Cpluralruleparser%7Cmediawiki.page.gallery.styles%7Cmediawiki.page.ready%7Cmediawiki.page.watch.ajax%7Cmediawiki.rcfilters.filters.ui%7Cmediawiki.skinning.content.parsoid%7Cmediawiki.special.recentchanges%7Cmediawiki.template.handlebars%2Cmustache%7Cmediawiki.ui.button%2Cicon%7Cmediawiki.widgets.AbandonEditDialog%2CCategoryMultiselectWidget%2CDateInputWidget%2CMediaSearch%2CTable%2CUserInputWidget%2Cstyles%7Cmediawiki.widgets.DateInputWidget.styles%7Cmobile.ooui.icons%7Cmobile.pagelist.styles%7Cmobile.pagesummary.styles%7Cmobile.placeholder.images%7Cmobile.startup%7Cmobile.startup.images%7Cmoment%2Coojs%2Coojs-router%2Coojs-ui%2Coojs-ui-core%2Coojs-ui-toolbars%2Coojs-ui-widgets%2Coojs-ui-windows%2Cpapaparse%2Crangefix%2Csinonjs%2Cspark-md5%7Cmw.config.values.wbDataTypes%2CwbRefTabsEnabled%2CwbRepo%2CwbSiteDetails%7Cmw.cx.SiteMapper%2Cdm%2Cinit%2Cui%2Cutil%7Cmw.cx.dm.Translation%7Cmw.cx.tools.TranslationTool%7Cmw.cx.ui.Infobar%7Coojs-ui-core.icons%2Cstyles%7Coojs-ui-toolbars.icons%7Coojs-ui-widgets.icons%7Coojs-ui-windows.icons%7Coojs-ui.styles.icons-accessibility%2Cicons-alerts%2Cicons-content%2Cicons-editing-advanced%2Cicons-editing-citation%2Cicons-editing-core%2Cicons-editing-list%2Cicons-editing-styling%2Cicons-interactions%2Cicons-layout%2Cicons-media%2Cicons-moderation%2Cicons-movement%2Cicons-user%2Cicons-wikimedia%2Cindicators%7Cskins.minerva.messageBox.styles%7Csocket.io%7Ctest.Cite%2CContentTranslation%2CEcho%2CEventLogging%2CFlow%2CGraph%2CGrowthExperiments%2CGuidedTour%2CMediaWiki%2CMinervaNeue%2CNavigationTiming%2CTemplateData%2CThanks%2CTranslate%2CUniversalLanguageSelector%2CVisualEditor%2CWikiEditor%2CWikibaseClient&version=hywdh:2201:225)
04:29:04         at runTest (node_modules/qunit/qunit/qunit.js:2272:35)
04:29:04         at Test.run (node_modules/qunit/qunit/qunit.js:2255:9)
04:29:04         at node_modules/qunit/qunit/qunit.js:2492:16
04:29:04         at processTaskQueue (node_modules/qunit/qunit/qunit.js:1863:26)
04:29:04         at node_modules/qunit/qunit/qunit.js:1867:13
04:29:04

Event Timeline

Restricted Application added subscribers: Masumrezarock100, Aklapper. · View Herald Transcript

I thought we fixed this last week: T298732: Flaky test: "ext.navigationTiming: onMwLoadEnd - controlled". I'll try to reproduce it again to investigate. Please do keep reporting once or twice if you still encounter it.

Change 756099 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] ext.navigationTiming: Don't call main() in test context

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

Krinkle triaged this task as High priority.

Change 756099 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] ext.navigationTiming: Don't call main() in test context

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

matmarex added a subscriber: matmarex.

Hopefully fixed for real this time.

It is still flaky. Just failed here: https://gerrit.wikimedia.org/r/c/mediawiki/extensions/VisualEditor/+/757443

https://integration.wikimedia.org/ci/job/wmf-quibble-vendor-mysql-php72-docker/87847/console

14:55:52 FAILED TESTS:
14:55:52   ext.navigationTiming
14:55:52     ✖ onMwLoadEnd - controlled
14:55:52       Chrome Headless 90.0.4430.212 (Linux x86_64)
14:55:52     resolved after fail+ok
14:55:52     Expected: [
14:55:52       "call"
14:55:52     ]
14:55:52     Actual: []
14:55:52         at Object.<anonymous> (http://localhost:9876/load.php?modules=mediawiki.experiments%2Cinspect%2CjqueryMsg%2Clanguage%2CmessagePoster%2Cpulsatingdot%2Cqunit-testrunner%2Crouter%2Cstorage%2Ctemplate%2Ctoc%2Cui%2Cuser%2Cutil%2Cviewport%2CvisibleTimeout%2Cwidgets%7Cmediawiki.interface.helpers.styles%7Cmediawiki.language.months%2Cnames%2CspecialCharacters%2Ctestdata%7Cmediawiki.libs.guiders%2Cjpegmeta%2Cpluralruleparser%7Cmediawiki.page.gallery.styles%7Cmediawiki.page.ready%7Cmediawiki.page.watch.ajax%7Cmediawiki.rcfilters.filters.ui%7Cmediawiki.skinning.content.parsoid%7Cmediawiki.special.recentchanges%7Cmediawiki.template.handlebars%2Cmustache%7Cmediawiki.ui.button%2Cicon%7Cmediawiki.widgets.AbandonEditDialog%2CCategoryMultiselectWidget%2CDateInputWidget%2CMediaSearch%2CTable%2CUserInputWidget%2Cstyles%7Cmediawiki.widgets.DateInputWidget.styles%7Cmobile.ooui.icons%7Cmobile.pagelist.styles%7Cmobile.pagesummary.styles%7Cmobile.placeholder.images%7Cmobile.startup%7Cmobile.startup.images%7Cmoment%2Coojs%2Coojs-router%2Coojs-ui%2Coojs-ui-core%2Coojs-ui-toolbars%2Coojs-ui-widgets%2Coojs-ui-windows%2Cpapaparse%2Crangefix%2Csinonjs%2Cspark-md5%7Cmw.config.values.wbDataTypes%2CwbRefTabsEnabled%2CwbRepo%2CwbSiteDetails%7Cmw.cx.SiteMapper%2Cdm%2Cinit%2Cui%2Cutil%7Cmw.cx.dm.Translation%7Cmw.cx.tools.TranslationTool%7Cmw.cx.ui.Infobar%7Coojs-ui-core.icons%2Cstyles%7Coojs-ui-toolbars.icons%7Coojs-ui-widgets.icons%7Coojs-ui-windows.icons%7Coojs-ui.styles.icons-accessibility%2Cicons-alerts%2Cicons-content%2Cicons-editing-advanced%2Cicons-editing-citation%2Cicons-editing-core%2Cicons-editing-list%2Cicons-editing-styling%2Cicons-interactions%2Cicons-layout%2Cicons-media%2Cicons-moderation%2Cicons-movement%2Cicons-user%2Cicons-wikimedia%2Cindicators%7Cskins.minerva.messageBox.styles%7Csocket.io%7Ctest.Cite%2CContentTranslation%2CEcho%2CEventLogging%2CFlow%2CGraph%2CGrowthExperiments%2CGuidedTour%2CMath%2CMediaWiki%2CMinervaNeue%2CNavigationTiming%2CTemplateData%2CThanks%2CTranslate%2CUniversalLanguageSelector%2CVisualEditor&version=1x2s6:2206:475)
14:55:52         at runTest (node_modules/qunit/qunit/qunit.js:2272:35)
14:55:52         at Test.run (node_modules/qunit/qunit/qunit.js:2255:9)
14:55:52         at node_modules/qunit/qunit/qunit.js:2492:16
14:55:52         at processTaskQueue (node_modules/qunit/qunit/qunit.js:1863:26)
14:55:52         at node_modules/qunit/qunit/qunit.js:1867:13

Change 757538 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/VisualEditor@master] [DNM] Jenkins demo commit

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

I have not been able to reproduce this locally at any point last week or this week.

A few outstanding simplifications and code removals have landed today in NavigationTiming. I am now unable to reproduce it on the above VE patch in CI, nor on the dozens of patches in other repos I just reviewed. Maybe those removals got rid of the racey code.

Next time I hear about this, I will first disable (QUnit.skip) the test in question. Others, feel free to do so without my input if you encounter it first.

Change 757789 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] Disable flaky test

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

Change 757789 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] Disable flaky test

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

Krinkle lowered the priority of this task from High to Medium.Feb 7 2022, 7:44 PM

Change 765284 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] ext.navigationTiming: Use early return for isRegularNavigation

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

Change 765285 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] tests: Improve stability and visibility of emitCpuBenchmark() test

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

Change 765333 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] tests: Avoid loadCallback() in tests and re-enable onMwLoadEnd test

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

Change 765284 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] ext.navigationTiming: Use early return for isRegularNavigation

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

Change 765285 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] tests: Improve stability and visibility of emitCpuBenchmark() test

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

Change 765333 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] tests: Avoid loadCallback() in tests and re-enable onMwLoadEnd test

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

Umherirrender added a subscriber: Umherirrender.

Still flaky

https://gerrit.wikimedia.org/r/c/mediawiki/extensions/GrowthExperiments/+/763755
https://integration.wikimedia.org/ci/job/wmf-quibble-vendor-mysql-php72-docker/90847/console

20:53:27 FAILED TESTS:
20:53:27   ext.navigationTiming
20:53:27     ✖ onMwLoadEnd - controlled
20:53:27       Chrome Headless 90.0.4430.212 (Linux x86_64)
20:53:27     resolved after fail+ok
20:53:27     Expected: [
20:53:27       "call"
20:53:27     ]
20:53:27     Actual: []
20:53:27         at Object.<anonymous> (http://localhost:9876/load.php?modules=mediawiki.experiments%2Cinspect%2CjqueryMsg%2Clanguage%2CmessagePoster%2Cpulsatingdot%2Cqunit-testrunner%2Crouter%2Cstorage%2Ctemplate%2Ctoc%2Cui%2Cuser%2Cutil%2Cviewport%2CvisibleTimeout%2Cwidgets%7Cmediawiki.interface.helpers.styles%7Cmediawiki.language.months%2Cnames%2CspecialCharacters%2Ctestdata%7Cmediawiki.libs.guiders%2Cjpegmeta%2Cpluralruleparser%7Cmediawiki.page.gallery.styles%7Cmediawiki.page.ready%7Cmediawiki.page.watch.ajax%7Cmediawiki.rcfilters.filters.ui%7Cmediawiki.skinning.content.parsoid%7Cmediawiki.special.recentchanges%7Cmediawiki.template.handlebars%2Cmustache%7Cmediawiki.ui.button%2Cicon%7Cmediawiki.widgets.AbandonEditDialog%2CCategoryMultiselectWidget%2CDateInputWidget%2CMediaSearch%2CTable%2CUserInputWidget%2Cstyles%7Cmediawiki.widgets.DateInputWidget.styles%7Cmobile.ooui.icons%7Cmobile.pagelist.styles%7Cmobile.pagesummary.styles%7Cmobile.placeholder.images%7Cmobile.startup%7Cmobile.startup.images%7Cmoment%2Coojs%2Coojs-router%2Coojs-ui%2Coojs-ui-core%2Coojs-ui-toolbars%2Coojs-ui-widgets%2Coojs-ui-windows%2Cpapaparse%2Crangefix%2Csinonjs%2Cspark-md5%7Cmw.config.values.wbDataTypes%2CwbRefTabsEnabled%2CwbRepo%2CwbSiteDetails%7Cmw.cx.SiteMapper%2Cdm%2Cinit%2Cui%2Cutil%7Cmw.cx.dm.Translation%7Cmw.cx.tools.TranslationTool%7Cmw.cx.ui.Infobar%7Coojs-ui-core.icons%2Cstyles%7Coojs-ui-toolbars.icons%7Coojs-ui-widgets.icons%7Coojs-ui-windows.icons%7Coojs-ui.styles.icons-accessibility%2Cicons-alerts%2Cicons-content%2Cicons-editing-advanced%2Cicons-editing-citation%2Cicons-editing-core%2Cicons-editing-list%2Cicons-editing-styling%2Cicons-interactions%2Cicons-layout%2Cicons-media%2Cicons-moderation%2Cicons-movement%2Cicons-user%2Cicons-wikimedia%2Cindicators%7Cskins.minerva.messageBox.styles%7Csocket.io%7Ctest.Cite%2CContentTranslation%2CEcho%2CEventLogging%2CFlow%2CGraph%2CGrowthExperiments%2CGuidedTour%2CMath%2CMediaWiki%2CMinervaNeue%2CNavigationTiming%2CTemplateData%2CThanks%2CTranslate%2CUniversalLanguageSelector%2CVisualEditor&version=9vvsy:2245:70)
20:53:27         at runTest (node_modules/qunit/qunit/qunit.js:2496:35)
20:53:27         at Test.run (node_modules/qunit/qunit/qunit.js:2479:9)
20:53:27         at node_modules/qunit/qunit/qunit.js:2770:16
20:53:27         at processTaskQueue (node_modules/qunit/qunit/qunit.js:2051:26)
20:53:27         at node_modules/qunit/qunit/qunit.js:2055:13

Again for https://gerrit.wikimedia.org/r/c/mediawiki/core/+/767224

✔ 1659 tests completed
19:11:49 ℹ 11 tests skipped
19:11:49 ✖ 1 test failed
19:11:49 
19:11:49 FAILED TESTS:
19:11:49   ext.navigationTiming
19:11:49     ✖ onMwLoadEnd - controlled
19:11:49       Chrome Headless 90.0.4430.212 (Linux x86_64)
19:11:49     resolved after fail+ok
19:11:49     Expected: [
19:11:49       "call"
19:11:49     ]
19:11:49     Actual: []
19:11:49         at Object.<anonymous> ( ...

Change 767493 had a related patch set uploaded (by Krinkle; author: Krinkle):

[integration/config@master] zuul: Install MobileFrontend when testing Echo

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

Change 767255 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/Echo@master] tests: Fix QUnit warnings and resolve complex test_NotificationBadge

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

Change 767493 merged by jenkins-bot:

[integration/config@master] zuul: Install MobileFrontend when testing Echo

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

Change 767255 merged by jenkins-bot:

[mediawiki/extensions/Echo@master] tests: Fix QUnit warnings and resolve complex test_NotificationBadge

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

Reedy raised the priority of this task from Medium to High.Mar 5 2022, 4:55 PM

Change 768230 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/NavigationTiming@master] tests: Replace flaky mock with the real thing in onMwLoadEnd() test

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

Change 768230 merged by jenkins-bot:

[mediawiki/extensions/NavigationTiming@master] tests: Replace flaky mock with the real thing in onMwLoadEnd() test

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