Error: acd_cli handling of expired oauth_token (refreshing)

[chrisidefix]

This morning I couldn't acd_cli sync due to what appears to be an expired oauth_token. An error appeared when trying to refresh the token as shows below (I am running Python 3.4 under Mac OS X 10.10.3).

I initially thought the host https://tensile-runway-92512.appspot.com was down (as reported in the error), but this is not the case. I managed to solve this by removing the existing cache and re-syncing, but in case you are interested here is the (verbose) output:

python3 acd_cli.py -v s
15-05-21 09:20:55.517 [INFO] [acd_cli] - Plugin leaf classes: StreamPlugin, TestPlugin
15-05-21 09:20:55.517 [INFO] [acd_cli] - StreamPlugin attached.
15-05-21 09:20:55.517 [INFO] [acd_cli] - TestPlugin attached.
15-05-21 09:20:55.518 [INFO] [acdcli.api.common] - Initializing acd with path "~/Library/Caches/acd_cli".
15-05-21 09:20:55.518 [INFO] [acdcli.api.oauth] - Token expired at 2015-05-19 15:56:30.331763.
15-05-21 09:20:55.518 [INFO] [acdcli.api.oauth] - Refreshing authentication token.
15-05-21 09:20:55.539 [INFO] [requests.packages.urllib3.connectionpool] - Starting new HTTPS connection (1): tensile-runway-92512.appspot.com
15-05-21 09:20:55.540 [ERROR] [acdcli.api.oauth] - Error refreshing authentication token.
Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 544, in urlopen
    body=body, headers=headers)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 341, in _make_request
    self._validate_conn(conn)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 761, in _validate_conn
    conn.connect()
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connection.py", line 204, in connect
    conn = self._new_conn()
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connection.py", line 134, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/util/connection.py", line 88, in create_connection
    raise err
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/util/connection.py", line 78, in create_connection
    sock.connect(sa)
OSError: [Errno 64] Host is down

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/adapters.py", line 370, in send
    timeout=timeout
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 597, in urlopen
    _stacktrace=sys.exc_info()[2])
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/util/retry.py", line 245, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/packages/six.py", line 309, in reraise
    raise value.with_traceback(tb)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 544, in urlopen
    body=body, headers=headers)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 341, in _make_request
    self._validate_conn(conn)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connectionpool.py", line 761, in _validate_conn
    conn.connect()
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connection.py", line 204, in connect
    conn = self._new_conn()
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/connection.py", line 134, in _new_conn
    (self.host, self.port), self.timeout, **extra_kw)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/util/connection.py", line 88, in create_connection
    raise err
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/packages/urllib3/util/connection.py", line 78, in create_connection
    sock.connect(sa)
requests.packages.urllib3.exceptions.ProtocolError: ('Connection aborted.', OSError(64, 'Host is down'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "acd_cli.py", line 940, in <module>
    main()
  File "acd_cli.py", line 920, in main
    if not common.init(CACHE_PATH):
  File "~/acd_cli-github/acdcli/api/common.py", line 61, in init
    return oauth.init(path) and _load_endpoints()
  File "~/acd_cli-github/acdcli/api/oauth.py", line 40, in init
    _get_data()
  File "~/acd_cli-github/acdcli/api/oauth.py", line 67, in _get_data
    _get_auth_token()
  File "~/acd_cli-github/acdcli/api/oauth.py", line 80, in _get_auth_token
    _refresh_auth_token()
  File "~/acd_cli-github/acdcli/api/oauth.py", line 111, in _refresh_auth_token
    response = requests.post(APPSPOT_URL, data=ref)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/api.py", line 108, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/api.py", line 50, in request
    response = session.request(method=method, url=url, **kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/sessions.py", line 465, in request
    resp = self.send(prep, **send_kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/sessions.py", line 573, in send
    r = adapter.send(request, **kwargs)
  File "/Library/Frameworks/Python.framework/Versions/3.4/lib/python3.4/site-packages/requests/adapters.py", line 415, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', OSError(64, 'Host is down'))

[chrisidefix]

UPDATE: after uploading about 100 GB I am receiving the same error again within a few hours of having this problem initially. Any idea what might be going on here? Is it possible that Amazon is resetting the oauth_token or what could this be related to?

PS: after deleting the cache (again) and downloading a new oauth_token I can continue to upload

[yadayada]

The next time this happens, please check that the oauth_data file in your cache directory is correct.

Aside from this, this is basically the indended behavior when the access token cannot be refreshed. There is nothing I can do about a connection error.

But I will wrap the connection error so the exception can be caught and the upload/download queue can potentially process further jobs (and retry the token refresh).

[chrisidefix]

How do I check if oauth_data is correct? It's been in the cache directory since I started using acd_cli and I never changed it. For now I have to keep replacing it every couple of hours. Do you know from the error if the connection error happens with an amazon domain or with https://tensile-runway-92512.appspot.com ? I would like to figure out what is going on if possible.

[yadayada]

You will simply see if there is something wrong. It needs to be refreshed every hour.
It should look something like the below block basically, with one additional field and longer tokens.

{
    "token_type": "bearer",
    "expires_in": 3600,
    "refresh_token": "Atzr|IQEBLzAtAhUAibmh-1N0EVztZJofMx",
    "access_token": "Atza|IQEBLjAsAhQ3yD47Jkj09BfU_qgNk4"
}

The connection error tells me nothing. There should always be a response from the appspot server, even an empty response on error.
I also had a quick look at the server logs and didn't find any failed requests, purely judging from the response length.

Maybe it's a threading error.

[chrisidefix]

My oauth_data looks like you describe it and fine from what I can see (it has exp_time: set as well)

Maybe it's a threading error.

Possibly, but this is not (only) happening when running multiple threads. I actually first saw this error on calling acd_cli.py s (after not using acd_cli.py for a day or two, I wanted to sync again).

Now, this is a repetitive problem for me. Uploading works for a while, but as soon as this error has occurred once (usually while uploading), all I can do is replace oauth_data and restart the uploads. I don't understand why a new oauth_data fixes this, but it does.

Or does this mean that right now I can not refresh the token at all and it probably only works for 3600 seconds, because it doesn't need to refresh during the first hour after generation of oauth_data?

[chrisidefix]

During upload (with `acd_cli.py -x 8) I get this error:

15-05-21 19:04:37.065 [ERROR] [acdcli.api.oauth] - Error refreshing authentication token.
15-05-21 19:04:37.066 [ERROR] [acd_cli] - Uploading "test_file.txt" failed. Code: 1000, msg: ('Connection aborted.', OSError(64, 'Host is down'))

Even if I try uploading with a single thread or syncing after this happens, it just doesn't work.

[yadayada]

How should it work? Nothing can work with an outdated access token that cannot be refreshed.

Maybe it's a threading error.

Possibly,

Nope. If the data is intact, that shouldn't be it.

What does

python3 -c 'import requests; r = requests.post("https://tensile-runway-92512.appspot.com"); print(r.text, r.status_code)'

output?

The debug option could also shed more light on the connection error.

[chrisidefix]

Thanks for looking into this. The above command seems to produce the same error. I assume it must be a problem on my side in this case. Maybe my firewall is acting up - I am going to re-install it and see if that helps anything.

[chrisidefix]

Alright, I managed to re-install my firewall, which appeared to have blocked connections to the appspot.com address and crashed it's UI at the same time, so I didn't receive any info about this.

You are welcome to close this issue. Thanks for your help!