test_key_revocation_integration.TestKeyRevocation fails on windows with Python 2.7

[joshuagl]

Please fill in the fields below to submit an issue or feature request. The
more information that is provided, the better.

Description of issue or feature request:

The full error log can be viewed on AppVeyor, I have pasted the section containing errors below:

....................E
Stderr:
DEBUG:tuf.client.updater:Adding roles delegated from u'targets'.
DEBUG:tuf.client.updater:Adding delegated role: role1.
INFO:tuf.download:Downloading: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json'
DEBUG:tuf.download:url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
DEBUG:tuf.download:session index: http+localhost
DEBUG:tuf.download:Reusing session for http+localhost
ERROR:tuf.download:Could not download URL: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json'
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\download.py", line 264, in _download_file
    response.raise_for_status()
  File "C:\Python27\lib\site-packages\requests\models.py", line 940, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
HTTPError: 404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
ERROR:tuf.client.updater:Update failed from http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json.
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1507, in _get_metadata_file
    upperbound_filelength)
  File "c:\projects\tuf\tuf\download.py", line 150, in unsafe_download
    return _download_file(url, required_length, STRICT_REQUIRED_LENGTH=False)
  File "c:\projects\tuf\tuf\download.py", line 264, in _download_file
    response.raise_for_status()
  File "C:\Python27\lib\site-packages\requests\models.py", line 940, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
HTTPError: 404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
ERROR:tuf.client.updater:Failed to update u'2.root.json' from all mirrors: {u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json': HTTPError(u'404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json',)}
ERROR:root:HTTP error for root version 2
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1150, in _update_root_metadata
    version=next_version)
  File "c:\projects\tuf\tuf\client\updater.py", line 1786, in _update_metadata
    upperbound_filelength, version)
  File "c:\projects\tuf\tuf\client\updater.py", line 1602, in _get_metadata_file
    raise tuf.exceptions.NoWorkingMirrorError(file_mirror_errors)
NoWorkingMirrorError: No working mirror was found:
  u'localhost:43996': HTTPError(u'404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json',)
INFO:tuf.download:Downloading: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json'
DEBUG:tuf.download:url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json
DEBUG:tuf.download:session index: http+localhost
DEBUG:tuf.download:Reusing session for http+localhost
ERROR:tuf.download:Could not download URL: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json'
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\download.py", line 261, in _download_file
    url, stream=True, timeout=tuf.settings.SOCKET_TIMEOUT)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "C:\Python27\lib\site-packages\requests\adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
ReadTimeout: HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)
ERROR:tuf.client.updater:Update failed from http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json.
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1507, in _get_metadata_file
    upperbound_filelength)
  File "c:\projects\tuf\tuf\download.py", line 150, in unsafe_download
    return _download_file(url, required_length, STRICT_REQUIRED_LENGTH=False)
  File "c:\projects\tuf\tuf\download.py", line 261, in _download_file
    url, stream=True, timeout=tuf.settings.SOCKET_TIMEOUT)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "C:\Python27\lib\site-packages\requests\adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
ReadTimeout: HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)
ERROR:tuf.client.updater:Failed to update u'timestamp.json' from all mirrors: {u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json': ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)",),)}
E............................x.......................................................................................................................................................
======================================================================
ERROR: test_timestamp_key_revocation (test_key_revocation_integration.TestKeyRevocation)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "C:\projects\tuf\tests\test_key_revocation_integration.py", line 189, in test_timestamp_key_revocation
    self.repository_updater.refresh()
  File "c:\projects\tuf\tuf\client\updater.py", line 1094, in refresh
    self._update_metadata('timestamp', DEFAULT_TIMESTAMP_UPPERLENGTH)
  File "c:\projects\tuf\tuf\client\updater.py", line 1786, in _update_metadata
    upperbound_filelength, version)
  File "c:\projects\tuf\tuf\client\updater.py", line 1602, in _get_metadata_file
    raise tuf.exceptions.NoWorkingMirrorError(file_mirror_errors)
NoWorkingMirrorError: No working mirror was found:
  u'localhost:43996': ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)",),)
Stderr:
DEBUG:tuf.client.updater:Adding roles delegated from u'targets'.
DEBUG:tuf.client.updater:Adding delegated role: role1.
INFO:tuf.download:Downloading: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json'
DEBUG:tuf.download:url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
DEBUG:tuf.download:session index: http+localhost
DEBUG:tuf.download:Reusing session for http+localhost
ERROR:tuf.download:Could not download URL: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json'
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\download.py", line 264, in _download_file
    response.raise_for_status()
  File "C:\Python27\lib\site-packages\requests\models.py", line 940, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
HTTPError: 404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
ERROR:tuf.client.updater:Update failed from http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json.
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1507, in _get_metadata_file
    upperbound_filelength)
  File "c:\projects\tuf\tuf\download.py", line 150, in unsafe_download
    return _download_file(url, required_length, STRICT_REQUIRED_LENGTH=False)
  File "c:\projects\tuf\tuf\download.py", line 264, in _download_file
    response.raise_for_status()
  File "C:\Python27\lib\site-packages\requests\models.py", line 940, in raise_for_status
    raise HTTPError(http_error_msg, response=self)
HTTPError: 404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json
ERROR:tuf.client.updater:Failed to update u'2.root.json' from all mirrors: {u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json': HTTPError(u'404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json',)}
ERROR:root:HTTP error for root version 2
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1150, in _update_root_metadata
    version=next_version)
  File "c:\projects\tuf\tuf\client\updater.py", line 1786, in _update_metadata
    upperbound_filelength, version)
  File "c:\projects\tuf\tuf\client\updater.py", line 1602, in _get_metadata_file
    raise tuf.exceptions.NoWorkingMirrorError(file_mirror_errors)
NoWorkingMirrorError: No working mirror was found:
  u'localhost:43996': HTTPError(u'404 Client Error: File not found for url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/2.root.json',)
INFO:tuf.download:Downloading: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json'
DEBUG:tuf.download:url: http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json
DEBUG:tuf.download:session index: http+localhost
DEBUG:tuf.download:Reusing session for http+localhost
ERROR:tuf.download:Could not download URL: u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json'
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\download.py", line 261, in _download_file
    url, stream=True, timeout=tuf.settings.SOCKET_TIMEOUT)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "C:\Python27\lib\site-packages\requests\adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
ReadTimeout: HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)
ERROR:tuf.client.updater:Update failed from http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json.
Traceback (most recent call last):
  File "c:\projects\tuf\tuf\client\updater.py", line 1507, in _get_metadata_file
    upperbound_filelength)
  File "c:\projects\tuf\tuf\download.py", line 150, in unsafe_download
    return _download_file(url, required_length, STRICT_REQUIRED_LENGTH=False)
  File "c:\projects\tuf\tuf\download.py", line 261, in _download_file
    url, stream=True, timeout=tuf.settings.SOCKET_TIMEOUT)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 546, in get
    return self.request('GET', url, **kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 533, in request
    resp = self.send(prep, **send_kwargs)
  File "C:\Python27\lib\site-packages\requests\sessions.py", line 646, in send
    r = adapter.send(request, **kwargs)
  File "C:\Python27\lib\site-packages\requests\adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
ReadTimeout: HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)
ERROR:tuf.client.updater:Failed to update u'timestamp.json' from all mirrors: {u'http://localhost:43996/tmp_hppez/TestKeyRevocation_vtpw4q/repository/metadata/timestamp.json': ReadTimeout(ReadTimeoutError("HTTPConnectionPool(host='localhost', port=43996): Read timed out. (read timeout=4)",),)}

Current behavior:

test_key_revocation_integration.TestKeyRevocation test fails on Windows with Python 2.7

Expected behavior:

All tests pass on all supported Python/OS combinations

[joshuagl]

I've already set up a VM to replicate this issue, so I'll work on it.

[lukpueh]

I created #940 for this issue. But yours is more informative. Let's make sure to close both when we have a fix. :)

[joshuagl]

Ugh, sorry. I should have paid more attention before filing the issue. Will be sure to tag both issues as fixed when I submit a PR.

[lukpueh]

Absolutely no need to apologize. Helping find a fix will be very much appreciated. As hinted at in #940, we are not dead set on AppVeyor, we just want something to test Windows builds on.

[lukpueh]

PSA: AppVeyor workers are accessible via RDP. This was quite useful for debugging an unrelated appveyor issue, which I couldn't replicate on a local windows vm.

[joshuagl]

This was resolved by #985