batch operation timeouts not handled gracefully

[klmunday]

There seems to currently be a problem with a /batch endpoint of the backend API. When the endpoint is used to lookup an ASN which according to the /<ASN>/json endpoint "Can't be found" it seems to hang.

I have raised an issue regarding this with your support team and they suggested that I also open an issue here since it can be somewhat handled gracefully in this library.

When fetching the problematic ASNs via getBatchDetails it just hangs until the timeout_per_batch value is exceeded and then throws an exception (see stacktrace below)

Stacktrace

2021-02-07 16:41:41,092 [INFO] looking up ASN range "range(1870, 2000)"
2021-02-07 16:41:41,093 [DEBUG] Starting new HTTPS connection (1): ipinfo.io:443
Traceback (most recent call last):
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 445, in _make_request
    six.raise_from(e, None)
  File "<string>", line 3, in raise_from
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 440, in _make_request
    httplib_response = conn.getresponse()
  File "/usr/lib64/python3.8/http/client.py", line 1347, in getresponse
    response.begin()
  File "/usr/lib64/python3.8/http/client.py", line 307, in begin
    version, status, reason = self._read_status()
  File "/usr/lib64/python3.8/http/client.py", line 268, in _read_status
    line = str(self.fp.readline(_MAXLINE + 1), "iso-8859-1")
  File "/usr/lib64/python3.8/socket.py", line 669, in readinto
    return self._sock.recv_into(b)
  File "/usr/lib64/python3.8/ssl.py", line 1241, in recv_into
    return self.read(nbytes, buffer)
  File "/usr/lib64/python3.8/ssl.py", line 1099, in read
    return self._sslobj.read(len, buffer)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/adapters.py", line 439, in send
    resp = conn.urlopen(
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 755, in urlopen
    retries = retries.increment(
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/util/retry.py", line 531, in increment
    raise six.reraise(type(error), error, _stacktrace)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/packages/six.py", line 735, in reraise
    raise value
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 699, in urlopen
    httplib_response = self._make_request(
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 447, in _make_request
    self._raise_timeout(err=e, url=url, timeout_value=read_timeout)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/urllib3/connectionpool.py", line 336, in _raise_timeout
    raise ReadTimeoutError(
urllib3.exceptions.ReadTimeoutError: HTTPSConnectionPool(host='ipinfo.io', port=443): Read timed out. (read timeout=60)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "api.py", line 86, in <module>
    asn_data = client.getBatchDetails([f"AS{num}" for num in bulk_asns], timeout_per_batch=60, raise_on_fail=False)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/ipinfo/handler.py", line 189, in getBatchDetails
    response = requests.post(
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/api.py", line 119, in post
    return request('post', url, data=data, json=json, **kwargs)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/api.py", line 61, in request
    return session.request(method=method, url=url, **kwargs)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/sessions.py", line 542, in request
    resp = self.send(prep, **send_kwargs)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/sessions.py", line 655, in send
    r = adapter.send(request, **kwargs)
  File "/home/klm/project/venv/lib64/python3.8/site-packages/requests/adapters.py", line 529, in send
    raise ReadTimeout(e, request=request)
requests.exceptions.ReadTimeout: HTTPSConnectionPool(host='ipinfo.io', port=443): Read timed out. (read timeout=60)

The error itself seems to occur at line 189 of handler.py (https://github.com/ipinfo/python/blob/master/ipinfo/handler.py#L189

I've taken a snapshot of the local variables at the time of the call to requests.post on line 189:

Local varstack

{
  "batch_size": 1000,
  "chunk": ["AS1870", "AS1871", "AS1872", "AS1873", "AS1874", "AS1875", "AS1876", "AS1877", "AS1878", "AS1879", "AS1880", "AS1881", "AS1882", "AS1883", ...],
  "headers": {
    "user-agent": "IPinfoClient/Python3/4.1.0",
    "accept": "application/json",
    "authorization": "Bearer <MY API KEY>",
    "content-type": "application/json"
  },
  "i": 0,
  "ip_address": "AS1919",
  "ip_addresses": ["AS1870", "AS1871", "AS1872", "AS1873", "AS1874", "AS1875", "AS1876", "AS1877", "AS1878", "AS1879", "AS1880", "AS1881", "AS1882", "AS1883", ...],
  "lookup_addresses": ["AS1870", "AS1871", "AS1872", "AS1873", "AS1874", "AS1875", "AS1876", "AS1877", "AS1878", "AS1879", "AS1880", "AS1881", "AS1882", "AS1883", ...],
  "raise_on_fail": False
}

My input arguments to getBatchDetails were:
ip_addresses: ["AS1870", ..., "AS1919"] (all 50 between those values)
timeout_per_batch: 60
raise_on_fail: False

I have been able to bypass this problem by making individual calls to getDetails in the meantime. However, being able to use getBatchDetails would be preferable to reduce network overhead.

I do believe that once the issue with /batch has been resolved with the main API that this would likely sort itself but there could be handling for the requests.post failing to catch erroneous cases perhaps?

Thanks

[UmanShahzad]

Hey @klmunday, thanks for reaching out.

This is indeed primarily a backend API issue which'll be fixed very soon.

From the library, you can in the meantime use the async/await handler instead. You would spawn a coroutine for each ASN, and then await them together. Something roughly like this (not tested and incomplete):

import asyncio

async def getAllAsns(asns):
    return await asyncio.gather([
        async_handler.getDetails(asn) for asn in asns
    ])

async def main():
    results = await getAllAsns(["AS1", "AS2"])
    print(results)

You mentioned possibly fixing the code around the requests.post call, but I'm not fully clear on that - do you mean that we should catch the exception and not let it go up if raise_on_fail=False, or something else?

[klmunday]

Hey @UmanShahzad

Thanks for your response and help with emulating the behaviour of the batch operation that is very useful!

My main thought behind capturing the error regarding requests.post was something similar to what you said. Although, when thinking about it, if the lookup errors at this stage then that entire bulk lookup fails, so i'm not actually sure that would be a good route to take since it would result in loss of data if only 1 item in the bulk caused the problem.

Perhaps wait and see until after the /batch endpoint fix? I'm sure that would probably be suffice

[UmanShahzad]

@klmunday Although it wouldn't solve your problem, it would be worth capturing the error from requests.post, because we send multiple requests when the total input size exceeds 1000 (the API limit), and we shouldn't throw an error in that case if raise_on_fail=False, instead returning all successful chunks. It wasn't already being captured mainly because I didn't know requests.posts would throw an exception... one of the issues with exceptions.

But yes, when /batch is fixed to handle non-existent ASNs everything will go back to normal. Apologize for the inconvenience.

[klmunday]

No worries, it does appear I was incorrect about getDetails still working for the problematic ASNs. It seems to throw the same problems. I was about to get around this by directly using requests and checking to see if the resulting status code isn't 200, if it isn't then I just skip that ASN

edit: error occurs on line https://github.com/ipinfo/python/blob/master/ipinfo/handler.py#L90

seems to throw the same exceptions as the getBatchDetails

Thanks again

[UmanShahzad]

@klmunday it should work fine now, with the bad ASN having an error key:

$ curl ipinfo.io/AS1877?token=<token>
{
  "error": "ASN Not Found!"
}

$ echo -e 'AS1877\nAS1878' | curl -XPOST --data-binary @- "https://ipinfo.io/batch?token=<token>"
{
  "AS1878": {
    "asn": "AS1878",
    ...
  },
  "AS1877": {
    "error": "ASN Not Found!"
  }
}

Let me know if it's solved and we can close this issue.

[klmunday]

Can confirm both getBatchDetails and getDetails work with this fix.

Thanks a lot!