1355800 - 2 minute delay when stopping web server after Android browser tests

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Testing, defect)

Description

[Geoff Brown [:gbrown]]

Test logs for Android mochitests show a 2 minute delay when stopping the web server at the end of a test. Something must be going wrong.

https://public-artifacts.taskcluster.net/KU_94y9BQN-Px2uyQQ_Yjw/0/public/logs/live_backing.log

[task 2017-04-12T04:52:40.538071Z] 04:52:40     INFO -  Stopping web server
[task 2017-04-12T04:54:47.800757Z] 04:54:47     INFO -  Stopping web socket server
[task 2017-04-12T04:54:47.820864Z] 04:54:47     INFO -  Stopping ssltunnel


There is a similar delay at the end of reftests.

https://public-artifacts.taskcluster.net/MK58xD_xQtOcXqnNoKfxIA/0/public/logs/live_backing.log

[task 2017-04-12T05:09:19.244858Z] 05:09:19     INFO -  leakcheck | refcount logging is off, so leaks can't be detected!
[task 2017-04-12T05:11:29.592251Z] 05:11:29     INFO -  04-11 22:07:56.289 I/Gecko   (  766):

Comment 1

[Geoff Brown [:gbrown]]

We timeout on the urlopen() call. The url is "http://10.0.2.2:8854/server/shutdown", which would probably work if called from the emulator!

[task 2017-04-12T03:11:48.074078Z] 03:11:48     INFO -  Traceback (most recent call last):
[task 2017-04-12T03:11:48.075928Z] 03:11:48     INFO -    File "/home/worker/workspace/build/tests/mochitest/runtests.py", line 487, in stop
[task 2017-04-12T03:11:48.076551Z] 03:11:48     INFO -      with urllib2.urlopen(self.shutdownURL) as c:
[task 2017-04-12T03:11:48.076645Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 126, in urlopen
[task 2017-04-12T03:11:48.077322Z] 03:11:48     INFO -      return _opener.open(url, data, timeout)
[task 2017-04-12T03:11:48.077968Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 400, in open
[task 2017-04-12T03:11:48.078067Z] 03:11:48     INFO -      response = self._open(req, data)
[task 2017-04-12T03:11:48.078129Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 418, in _open
[task 2017-04-12T03:11:48.078197Z] 03:11:48     INFO -      '_open', req)
[task 2017-04-12T03:11:48.078256Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 378, in _call_chain
[task 2017-04-12T03:11:48.078298Z] 03:11:48     INFO -      result = func(*args)
[task 2017-04-12T03:11:48.078529Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 1207, in http_open
[task 2017-04-12T03:11:48.078588Z] 03:11:48     INFO -      return self.do_open(httplib.HTTPConnection, req)
[task 2017-04-12T03:11:48.078636Z] 03:11:48     INFO -    File "/usr/lib/python2.7/urllib2.py", line 1177, in do_open
[task 2017-04-12T03:11:48.078821Z] 03:11:48     INFO -      raise URLError(err)
[task 2017-04-12T03:11:48.078912Z] 03:11:48     INFO -  URLError: <urlopen error [Errno 110] Connection timed out>

Comment 2

[Geoff Brown [:gbrown]]

(In reply to Geoff Brown [:gbrown] from comment #1)
> We timeout on the urlopen() call. The url is
> "http://10.0.2.2:8854/server/shutdown", which would probably work if called
> from the emulator!

When run from mach, the local, host, IP is used for the webserver, but even that throws! The response from urlopen() cannot be used with the 'with' statement -- it does not have an __exit__!

Comment 3

[Geoff Brown [:gbrown]]

"10.0.2.2" is passed as the --remote-webserver; that is specified in the android mozharness config. 10.0.2.2 is the emulator's IP address alias for localhost on the host.

Comment 4

[Geoff Brown [:gbrown]]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=acdaab06755ecd2cb4bd2fccf53a85ce5e9f45ca

Comment 5

[Geoff Brown [:gbrown]]

Attachment: stop web server correctly

https://treeherder.mozilla.org/#/jobs?repo=try&revision=b81b511428046a47dc3f8b500f69b6b2a76e9e44

No more delay:

https://public-artifacts.taskcluster.net/J7fl6BjQSnaGIZUfwGrU-A/0/public/logs/live_backing.log

[task 2017-04-12T17:07:09.951971Z] 17:07:09     INFO -  Stopping web server
[task 2017-04-12T17:07:09.958986Z] 17:07:09     INFO -  Stopping web socket server
[task 2017-04-12T17:07:09.979345Z] 17:07:09     INFO -  Stopping ssltunnel
[task 2017-04-12T17:07:09.999793Z] 17:07:09     INFO -  leakcheck | refcount logging is off, so leaks can't be detected!

Comment 6

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8857612 [details] [diff] [review]
stop web server correctly

Review of attachment 8857612 [details] [diff] [review]:
-----------------------------------------------------------------

so much identical code :)

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f101a7b5c135
Improve test web server shutdown to avoid delays; r=jmaher

Comment 8

[Iris Hsiao [:ihsiao]]

https://hg.mozilla.org/mozilla-central/rev/f101a7b5c135

Comment 9

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/8feba0be5de6