Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Handle urllib3.exceptions.InvalidChunkLength from urllib3 causing bot to go idle #32

Open
ctmbl opened this issue Aug 8, 2023 · 0 comments
Labels
bug Something isn't working

Comments

@ctmbl
Copy link
Contributor

ctmbl commented Aug 8, 2023

In some cases (seemingly random) a request to some RootMe endpoint returns an unexpected chunk.

This seems to be known on the urllib3 project and is probably due to an ambiguity in RFC7230 (HTTP/1.1), causing the client (us) and the server (RootMe) to behave differently thus causing the issue.

The bot, itself, behaves correctly and goes idle as expected, however this seems to happen a bit too frequently and we might want to handle it to avoid the burden of !resume-ing it each time.
Three solutions could be implemented on our side:

  • handle the urllib3 exception
  • handle the requests exception
  • monkeypatch (if doable) the problematic function

Here are the logs:

2023-08-08 01:52:10 ERROR    api.rate_limiter Request GET: https://api.www.root-me.org//auteurs/507545 + {'api_key': 'CENSORED'} Unhandled error. Entering idle state.
2023-08-08 01:52:10 ERROR    api.rate_limiter Entering idle state due to previous errors
2023-08-08 01:52:10 ERROR    bot.root_pythia_cogs check_new_solves loop failed
2023-08-08 01:52:10 ERROR    asyncio Task exception was never retrieved
future: <Task cancelling name='Task-65819' coro=<Loop._loop() done, defined at /usr/local/lib/python3.10/site-packages/discord/ext/tasks/__init__.py:200> exception=RateLimiterError('Unhandled error. Entering idle state.')>
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 761, in _update_chunk_length
    self.chunk_left = int(line, 16)
ValueError: invalid literal for int() with base 16: b''

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 444, in _error_catcher
    yield
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 828, in read_chunked
    self._update_chunk_length()
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 765, in _update_chunk_length
    raise InvalidChunkLength(self, line)
urllib3.exceptions.InvalidChunkLength: InvalidChunkLength(got length b'', 0 bytes read)

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/requests/models.py", line 816, in generate
    yield from self.raw.stream(chunk_size, decode_content=True)
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 624, in stream
    for line in self.read_chunked(amt, decode_content=decode_content):
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 816, in read_chunked
    with self._error_catcher():
  File "/usr/local/lib/python3.10/contextlib.py", line 153, in __exit__
    self.gen.throw(typ, value, traceback)
  File "/usr/local/lib/python3.10/site-packages/urllib3/response.py", line 461, in _error_catcher
    raise ProtocolError("Connection broken: %r" % e, e)
urllib3.exceptions.ProtocolError: ("Connection broken: InvalidChunkLength(got length b'', 0 bytes read)", InvalidChunkLength(got length b'', 0 bytes read))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/opt/root-pythia/src/api/rate_limiter.py", line 162, in handle_requests
    self.requests[request.key]["result"] = self.handle_get_request(request)
  File "/opt/root-pythia/src/api/rate_limiter.py", line 92, in handle_get_request
    resp = requests.get(request.url, cookies=request.cookies, timeout=self._request_timeout)
  File "/usr/local/lib/python3.10/site-packages/requests/api.py", line 73, in get
    return request("get", url, params=params, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/requests/api.py", line 59, in request
    return session.request(method=method, url=url, **kwargs)
  File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 587, in request
    resp = self.send(prep, **send_kwargs)
  File "/usr/local/lib/python3.10/site-packages/requests/sessions.py", line 745, in send
    r.content
  File "/usr/local/lib/python3.10/site-packages/requests/models.py", line 899, in content
    self._content = b"".join(self.iter_content(CONTENT_CHUNK_SIZE)) or b""
  File "/usr/local/lib/python3.10/site-packages/requests/models.py", line 818, in generate
    raise ChunkedEncodingError(e)
requests.exceptions.ChunkedEncodingError: ("Connection broken: InvalidChunkLength(got length b'', 0 bytes read)", InvalidChunkLength(got length b'', 0 bytes read))

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/discord/ext/tasks/__init__.py", line 264, in _loop
    raise exc
  File "/usr/local/lib/python3.10/site-packages/discord/ext/tasks/__init__.py", line 239, in _loop
    await self.coro(*args, **kwargs)
  File "/opt/root-pythia/src/bot/root_pythia_cogs.py", line 102, in check_new_solves
    async for solved_challenge in self.dbmanager.fetch_user_new_solves(user.idx):
  File "/opt/root-pythia/src/bot/dummy_db_manager.py", line 57, in fetch_user_new_solves
    raw_user_data = await self.api_manager.get_user_by_id(idx)
  File "/opt/root-pythia/src/api/rootme_api.py", line 43, in get_user_by_id
    data = await self.rate_limiter.make_request(f"{self.API_URL}/auteurs/{_id}", cookies, "GET")
  File "/opt/root-pythia/src/api/rate_limiter.py", line 211, in make_request
    raise exc from prev_exc
api.rate_limiter.RateLimiterError: Unhandled error. Entering idle state.
@ctmbl ctmbl added the bug Something isn't working label Aug 8, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

1 participant