Upload to blob fails with timeout error much sooner than timeout expires

[joaocc]

blob_service.create_blob_from_path(container, blob_path, file, content_settings=content_settings, timeout=300)

$ time make upload-big-files
./src/7.upload-2-azure.sh    16041-big-files1   az--repoX
Init of upload_pack.py
Latest local pack found: 1.5.3.0203.161011-112303Z
Adding additional mime content types
INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (1): repoX.blob.core.windows.net
DEBUG:requests.packages.urllib3.connectionpool:"GET /repoX-pub?restype=container HTTP/1.1" 200 None
DEBUG:requests.packages.urllib3.connectionpool:"HEAD /repoX-pub/repoX/games/big-files/files-v1/latest-build.cfg HTTP/1.1" 200 0
blob: repoX/games/big-files/files-v1/latest-build.cfg EXISTS
DEBUG:requests.packages.urllib3.connectionpool:"GET /repoX-pub/repoX/games/big-files/files-v1/latest-build.cfg HTTP/1.1" 206 73
DEBUG:requests.packages.urllib3.connectionpool:"HEAD /repoX-pub/repoX/games/big-files/files-v1/1.5.3.0203-161010-165722/.ok HTTP/1.1" 404 0
Local version (1.5.3.0203.161011-112303Z) is equal or newer than Azure version (1.5.3.0203-161010-165722)
uploading webgl.memgz
INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (2): repoX.blob.core.windows.net
DEBUG:requests.packages.urllib3.connectionpool:"PUT /repoX-pub/repoX/games/big-files/files-v1/1.5.3.0203.161011-112303Z/bin.webgl/webgl.mem?timeout=300 HTTP/1.1" 201 None
uploading webgl.datagz
INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (3): repoX.blob.core.windows.net
INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (4): repoX.blob.core.windows.net
INFO:requests.packages.urllib3.connectionpool:Starting new HTTPS connection (5): repoX.blob.core.windows.net
########################################################
Traceback (most recent call last):
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/connectionpool.py", line 544, in urlopen
    body=body, headers=headers)
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/connectionpool.py", line 349, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1106, in request
    self._send_request(method, url, body, headers)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1151, in _send_request
    self.endheaders(body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1102, in endheaders
    self._send_output(message_body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 936, in _send_output
    self.send(message_body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 908, in send
    self.sock.sendall(data)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 891, in sendall
    v = self.send(data[count:])
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 861, in send
    return self._sslobj.write(data)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 586, in write
    return self._sslobj.write(data)
socket.timeout: The write operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.5/site-packages/requests/adapters.py", line 370, in send
    timeout=timeout
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/connectionpool.py", line 597, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/util/retry.py", line 245, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/packages/six.py", line 309, in reraise
    raise value.with_traceback(tb)
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/connectionpool.py", line 544, in urlopen
    body=body, headers=headers)
  File "/usr/local/lib/python3.5/site-packages/requests/packages/urllib3/connectionpool.py", line 349, in _make_request
    conn.request(method, url, **httplib_request_kw)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1106, in request
    self._send_request(method, url, body, headers)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1151, in _send_request
    self.endheaders(body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 1102, in endheaders
    self._send_output(message_body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 936, in _send_output
    self.send(message_body)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/http/client.py", line 908, in send
    self.sock.sendall(data)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 891, in sendall
    v = self.send(data[count:])
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 861, in send
    return self._sslobj.write(data)
  File "/usr/local/Cellar/python3/3.5.2_2/Frameworks/Python.framework/Versions/3.5/lib/python3.5/ssl.py", line 586, in write
    return self._sslobj.write(data)
requests.packages.urllib3.exceptions.ProtocolError: ('Connection aborted.', timeout('The write operation timed out',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.5/site-packages/azure/storage/storageclient.py", line 212, in _perform_request
    response = self._httpclient.perform_request(request)
  File "/usr/local/lib/python3.5/site-packages/azure/storage/_http/httpclient.py", line 114, in perform_request
    proxies=self.proxies)
  File "/usr/local/lib/python3.5/site-packages/requests/sessions.py", line 465, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.5/site-packages/requests/sessions.py", line 573, in send
    r = adapter.send(request, **kwargs)
  File "/usr/local/lib/python3.5/site-packages/requests/adapters.py", line 415, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', timeout('The write operation timed out',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/myroot/src/azure_module.py", line 92, in upload_azure_blob
    blob_service.create_blob_from_path(container, blob_path, file, content_settings=content_settings, timeout=300)
  File "/usr/local/lib/python3.5/site-packages/azure/storage/blob/blockblobservice.py", line 393, in create_blob_from_path
    timeout=timeout)
  File "/usr/local/lib/python3.5/site-packages/azure/storage/blob/blockblobservice.py", line 490, in create_blob_from_stream
    timeout=timeout)
  File "/usr/local/lib/python3.5/site-packages/azure/storage/blob/blockblobservice.py", line 814, in _put_blob
    return self._perform_request(request, _parse_base_properties)
  File "/usr/local/lib/python3.5/site-packages/azure/storage/storageclient.py", line 266, in _perform_request
    raise ex
  File "/usr/local/lib/python3.5/site-packages/azure/storage/storageclient.py", line 242, in _perform_request
    raise AzureException(ex.args[0])
azure.common.AzureException: ('Connection aborted.', timeout('The write operation timed out',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/myroot/src/upload_pack.py", line 158, in <module>
    handle_deploy_target(deploy_yaml, uploader_yaml)
  File "/myroot/src/upload_pack.py", line 130, in handle_deploy_target
    upload_pack_files_to_azure(pack_upload_patterns, container, game_azure_base_dir, blob_service)
  File "/myroot/src/upload_pack.py", line 63, in upload_pack_files_to_azure
    azure_module.upload_azure_blob(file, container, dest_path, blob_service, content_encoding, cache_control)
  File "/myroot/src/azure_module.py", line 95, in upload_azure_blob
    logger.exception(error)
NameError: name 'error' is not defined
make: *** [upload-big-files] Error 1

real  2m10.694s
user  0m1.964s
sys 0m1.381s

[erezvani1529]

Hi @joaocc,

Thanks for bringing up your issue here!

Looks like you are hitting the socket timeout. The value for socket timeout which is being passed by our library to lower layers(request and urllib3) is 11 seconds(please refer to this link for more context on why so).
Note that this is different from the server timeout(the 300 seconds) you have specified through the API.

A few questions to help us clarify:

• How often do you see this issue?
• What is the blob size you are using? The stack trace shows a blob size < 64MB, have you tried different sizes?

Thanks!

[joaocc]

Hi,
We have since moved to calling CLI (the one you install via "npm install -g azure-cli").
We have some small files and some big ones. The big ones can be around 100 or 150MB.
Thx

[letmaik]

Facing the same issue, with a 3MB file. Upload works with Storage Explorer. The timeout happens after 2min roughly. Why not make the socket timeout bigger than 11 seconds or at least make it configurable?

[ashja99]

I'm seeing the same issue, with anything above or around 3MB.

[rambho]

Thanks for your input guys.
Our next release we will generously increase the default socket timeout value and also look into making it configurable for more control.

[EelcoHoogendoorn]

+1 for this issue; for the record, I tried monkey-patching the socket timeout on 0.34 back to the value it had in 0.32, and that did not solve my timeout issues. Downgrading to 0.32 did, however.

Making this more easily configurable strikes me as an essential feature.

[caiiiycuk]

+1

[ValexPix]

+1

[caiiiycuk]

Increasing SOCKET_TIMEOUT in azure/storage/_constants.py to 360 sec helps for me.

[EelcoHoogendoorn]

Looks like you are hitting the socket timeout. The value for socket timeout which is being passed by our library to lower layers(request and urllib3) is 11 seconds(please refer to this link for more context on why so).

After setting articulis.storage._constants.SOCKET_TIMEOUT = None (essentially leaving it up to requests to determine a sane client-side timeout) our problems went away.

How about you expose a kwarg to allow users to override it?

[zezha-msft]

We have made the socket timeout configurable through the service objects, and increased the default value to 20 seconds. I will make a release shortly.

However, I would like to point out that you should always set a socket timeout, if not your request might hang forever. You can refer to the Requests documentation. Setting it to None is NOT recommended.