1430717 - Intermittent test_cli_arguments.py TestCommandLineArguments.test_startup_timeout causes hangs after Firefox restart on Windows

Status: RESOLVED FIXED

(Testing :: Marionette Client and Harness, defect, P5)

Description

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

As noticed on bug 1391545 comment 67 we have a lot of 1000s timeouts on Windows for the above test.

https://treeherder.mozilla.org/logviewer.html#?repo=mozilla-beta&job_id=154792849&lineNumber=1272

16:50:40     INFO -  TEST-START: test_cli_arguments.py TestCommandLineArguments.test_startup_timeout
16:50:40     INFO -  1515430240619	Marionette	TRACE	3 <- [1,5,null,{"value":null}]
16:50:40     INFO -  1515430240620	Marionette	TRACE	3 -> [0,6,"deleteSession",{}]
16:50:40     INFO -  1515430240621	Marionette	TRACE	3 <- [1,6,null,{}]
16:50:40     INFO -  [GF[GFX1-]: Receive IPC close wit[GX1-h reason]: ReF=ceive IPC close wiX1-]Ath rbnormalShutdown
16:50:40     INFO -  eason=AbnormalShutdown
16:50:40     INFO -  : Receive IPC close with reason=AbnormalShutdown
16:50:40     INFO -  Application command: Z:\task_1515430051\build\application\firefox\firefox.exe -no-remote -marionette -profile c:\users\genericworker\appdata\local\temp\tmpvrnrxb.mozrunner
16:50:40     INFO -  1515430240923	Marionette	DEBUG	Received observer notification "profile-after-change"
16:50:40     INFO -  1515430240964	Marionette	DEBUG	Received observer notification "command-line-startup"
16:50:40     INFO -  1515430240964	Marionette	INFO	Enabled via --marionette
17:07:20     INFO - Automation Error: mozprocess timed out after 1000 seconds running ['Z:\\task_1515430051\\build\\venv\\Scripts\\python', '-u', 'Z:\\task_1515430051\\build\\tests\\marionette\\harness\\marionette_harness\\runtests.py', '--gecko-log=-', '-vv', '--log-raw=Z:\\task_1515430051\\build\\blobber_upload_dir\\marionette_raw.log', '--log-errorsummary=Z:\\task_1515430051\\build\\blobber_upload_dir\\marionette_errorsummary.log', '--log-html=Z:\\task_1515430051\\build\\blobber_upload_dir\\report.html', '--binary=Z:\\task_1515430051\\build\\application\\firefox\\firefox.exe', '--address=localhost:2828', '--symbols-path=https://queue.taskcluster.net/v1/task/ai_xIll0QU2i9Kd8WDhxCw/artifacts/public/build/target.crashreporter-symbols.zip', 'Z:\\task_1515430051\\build\\tests\\marionette\\tests\\testing\\marionette\\harness\\marionette_harness\\tests\\unit-tests.ini']
17:07:21    ERROR - timed out after 1000 seconds of no output

In those cases we do not get a sessionstore-windows-restored observer notification. Maybe this test case helps us to track down this particular problem as filed as bug 1382162.

Comment 1

[Intermittent Failures Robot]

2 failures in 735 pushes (0.003 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-beta: 2

Platform breakdown:
* windows7-32-nightly: 1
* windows7-32-devedition: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1430717&startday=2018-01-29&endday=2018-02-04&tree=all

Comment 2

[Intermittent Failures Robot]

1 failures in 702 pushes (0.001 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 1

Platform breakdown:
* windows7-32: 1

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1430717&startday=2018-02-05&endday=2018-02-11&tree=all

Comment 3

[Intermittent Failures Robot]

10 failures in 814 pushes (0.012 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* autoland: 6
* mozilla-inbound: 3
* mozilla-central: 1

Platform breakdown:
* windows7-32: 10

For more details, see:
https://brasstacks.mozilla.com/orangefactor/?display=Bug&bugid=1430717&startday=2018-03-12&endday=2018-03-18&tree=all

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

I would suggest we temporarily skip this test until I was able to land a fix for bug 1433873. Then we can retry if something has been changed.

Comment 5

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

Attachment: Bug 1430717 - Skip test_cli_arguments.py TestCommandLineArguments.test_startup_timeout.

The test is causing intermittent failures of type "1000s of no output" for
the Mn jobs. It needs to be skipped until at least bug 1433873 has been
fixed.

Review commit: https://reviewboard.mozilla.org/r/229528/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/229528/

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

Comment on attachment 8960799 [details]
Bug 1430717 - Skip test_cli_arguments.py TestCommandLineArguments.test_startup_timeout.

https://reviewboard.mozilla.org/r/229528/#review235274

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/84c7300864d7
Skip test_cli_arguments.py TestCommandLineArguments.test_startup_timeout. r=whimboo

Comment 8

[Tiberius Oros[:tiberius_oros]]

https://hg.mozilla.org/mozilla-central/rev/84c7300864d7

Comment 9

[Intermittent Failures Robot]

2 failures in 822 pushes (0.002 failures/push) were associated with this bug in the last 7 days.    

Repository breakdown:
* mozilla-inbound: 2

Platform breakdown:
* windows7-32: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1430717&startday=2018-03-20&endday=2018-03-26&tree=trunk

Comment 10

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

Lets try to reenable this test:
https://treeherder.mozilla.org/#/jobs?repo=try&revision=46d3c1460a3f2f57c2d535813505e22158715447

Comment 11

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

Attachment: Bug 1430717 - Re-enable test_cli_arguments.py TestCommandLineArguments.test_startup_timeout. r?ato

Comment 12

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/3e89ff5068b7
Re-enable test_cli_arguments.py TestCommandLineArguments.test_startup_timeout. r=ato

Comment 13

[Arthur Iakab [arthur_iakab]]

https://hg.mozilla.org/mozilla-central/rev/3e89ff5068b7

Comment 14

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

So this is still happening but with a very low intermittent rate:

https://treeherder.mozilla.org/logviewer.html#?job_id=207453363&repo=autoland

Sebastian, can we please make sure that all the 1000s timeout failure for Mn jobs are getting classified against this bug instead of bug 1391545? What would we have to change for the summary to make that better classifiable?

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2] (away 10/03 - 10/13)]

This should be fixed now since my patch on bug 1416747 landed.

Comment 16

[BMO Automation]

Moving bug to Testing::Marionette Client and Harness component per bug 1815831.