Resetting dropped connection results Bad file descriptor exception

[glensc]

Trying to port application to niquest and getting connection reset error on multiple trys, so not a temporary error.

Source:

• Refactor: Use niquests rather requests Taxel/PlexTraktSync#2081 at f7c6adb9 commit

Just in case, I've tried to disable all new features, like ipv6 and http2, http3, multiplexing, the problem remains

            multiplexed=False,
            disable_ipv6=True,
            disable_http2=True,
            disable_http3=True,
            happy_eyeballs=False,

Actual Result

The application is making request of 100 items to plex server and then many requests to https://api.trakt.tv and around the time plex items are processed and trakt api probably dropped connection by that time, and that cleanup seems to result unexpected exception.

2024-10-21 16:51:12,959 DEBUG[trakt.core]:get: https://api.trakt.tv/search/tmdb/116?type=movie
2024-10-21 16:51:12,960 DEBUG[trakt.core]:method, url :: get, https://api.trakt.tv/search/tmdb/116?type=movie
2024-10-21 16:51:12,961 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 16:51:12,963 ERROR[plextraktsync.cli]:('Connection aborted.', OSError(9, 'Bad file descriptor'))

Details

Traceback (most recent call last):
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connectionpool.py", line 1598, in urlopen
    conn = self._get_conn(timeout=pool_timeout, heb_timeout=timeout_obj)
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connectionpool.py", line 675, in _get_conn
    conn.close()
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connection.py", line 310, in close
    super().close()
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/backend/hface.py", line 1672, in close
    self.sock.close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/socket.py", line 501, in close
    self._real_close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/ssl.py", line 1334, in _real_close
    super()._real_close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/socket.py", line 495, in _real_close
    _ss.close(self)
OSError: [Errno 9] Bad file descriptor

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "python-3.9/lib/python3.9/site-packages/niquests/adapters.py", line 941, in send
    resp_or_promise = conn.urlopen(  # type: ignore[call-overload,misc]
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connectionpool.py", line 1698, in urlopen
    retries = retries.increment(
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/util/retry.py", line 499, in increment
    raise reraise(type(error), error, _stacktrace)
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/util/util.py", line 38, in reraise
    raise value.with_traceback(tb)
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connectionpool.py", line 1598, in urlopen
    conn = self._get_conn(timeout=pool_timeout, heb_timeout=timeout_obj)
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connectionpool.py", line 675, in _get_conn
    conn.close()
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/connection.py", line 310, in close
    super().close()
  File "python-3.9/lib/python3.9/site-packages/urllib3_future/backend/hface.py", line 1672, in close
    self.sock.close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/socket.py", line 501, in close
    self._real_close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/ssl.py", line 1334, in _real_close
    super()._real_close()
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/socket.py", line 495, in _real_close
    _ss.close(self)
urllib3_future.exceptions.ProtocolError: ('Connection aborted.', OSError(9, 'Bad file descriptor'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "plextraktsync/cli.py", line 28, in wrap
    cmd(*args, **kwargs)
  File "plextraktsync/commands/sync.py", line 74, in sync
    run_async(runner, walker=w, dry_run=config.dry_run)
  File "python-3.9/lib/python3.9/site-packages/decorator.py", line 232, in fun
    return caller(func, *(extras + args), **kw)
  File "plextraktsync/decorators/coro.py", line 15, in coro
    return asyncio.run(f(*args, **kwargs))
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/opt/homebrew/Cellar/python@3.9/3.9.20/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/base_events.py", line 647, in run_until_complete
    return future.result()
  File "plextraktsync/commands/sync.py", line 13, in run_async
    await runner.sync(**kwargs)
  File "plextraktsync/sync/Sync.py", line 49, in sync
    async for movie in walker.find_movies():
  File "plextraktsync/plan/Walker.py", line 98, in find_movies
    movie = self.mf.resolve_any(plex)
  File "plextraktsync/media/MediaFactory.py", line 39, in resolve_any
    m = self.resolve_guid(guid, show)
  File "plextraktsync/media/MediaFactory.py", line 68, in resolve_guid
    tm = self.trakt.find_by_guid(guid)
  File "plextraktsync/trakt/TraktApi.py", line 259, in find_by_guid
    tm = self.search_by_id(guid.id, id_type=guid.provider, media_type=guid.type)
  File "python-3.9/lib/python3.9/site-packages/decorator.py", line 232, in fun
    return caller(func, *(extras + args), **kw)
  File "plextraktsync/decorators/rate_limit.py", line 20, in rate_limit
    return fn(*args, **kwargs)
  File "python-3.9/lib/python3.9/site-packages/decorator.py", line 232, in fun
    return caller(func, *(extras + args), **kw)
  File "plextraktsync/decorators/retry.py", line 26, in retry
    return fn(*args, **kwargs)
  File "plextraktsync/trakt/TraktApi.py", line 306, in search_by_id
    search = trakt.sync.search_by_id(media_id, id_type=id_type, media_type=media_type)
  File "python-3.9/lib/python3.9/site-packages/trakt/core.py", line 579, in inner
    json_data = self._handle_request('get', url)
  File "python-3.9/lib/python3.9/site-packages/trakt/core.py", line 544, in _handle_request
    response = session.request(method, url, headers=HEADERS,
  File "python-3.9/lib/python3.9/site-packages/requests_cache/session.py", line 183, in request
    return super().request(method, url, *args, headers=headers, **kwargs)  # type: ignore
  File "python-3.9/lib/python3.9/site-packages/niquests/sessions.py", line 563, in request
    resp = self.send(prep, **send_kwargs)
  File "python-3.9/lib/python3.9/site-packages/requests_cache/session.py", line 230, in send
    response = self._send_and_cache(request, actions, cached_response, **kwargs)
  File "python-3.9/lib/python3.9/site-packages/requests_cache/session.py", line 254, in _send_and_cache
    response = super().send(request, **kwargs)
  File "python-3.9/lib/python3.9/site-packages/niquests/sessions.py", line 1223, in send
    r = adapter.send(request, **kwargs)
  File "python-3.9/lib/python3.9/site-packages/niquests/adapters.py", line 978, in send
    raise ConnectionError(err, request=request)
niquests.exceptions.ConnectionError: ('Connection aborted.', OSError(9, 'Bad file descriptor'))

Reproduction Steps

Probably can make minimal reproducer, but maybe the details already here are sufficient.

System Information

$ python -m niquests.help

Details

{
  "charset_normalizer": {
    "version": "3.4.0"
  },
  "http1": {
    "h11": "0.14.0"
  },
  "http2": {
    "jh2": "5.0.3"
  },
  "http3": {
    "enabled": true,
    "qh3": "1.2.1"
  },
  "idna": {
    "version": "3.10"
  },
  "implementation": {
    "name": "CPython",
    "version": "3.9.20"
  },
  "niquests": {
    "version": "3.10.0"
  },
  "ocsp": {
    "enabled": true
  },
  "platform": {
    "release": "23.6.0",
    "system": "Darwin"
  },
  "system_ssl": {
    "version": "30300020"
  },
  "urllib3.future": {
    "cohabitation_version": null,
    "version": "2.11.900"
  },
  "wassima": {
    "certifi_fallback": false,
    "enabled": true,
    "version": "1.1.4"
  }
}

[Ousret]

Probably can make minimal reproducer

I would like that. It would help.

[glensc]

it's not directly related to specific server, other connections get dropped too.

❯ grep 'Resetting dropped connection' plextraktsync.log
2024-10-21 16:51:12,961 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:01:12,069 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:02:35,902 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:02:59,686 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: redacted.plex.direct
2024-10-21 17:04:00,415 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:12:13,450 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:12:38,190 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: redacted.plex.direct
2024-10-21 17:34:41,580 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:36:18,270 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: redacted.plex.direct
2024-10-21 17:36:24,866 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: api.trakt.tv
2024-10-21 17:36:36,595 DEBUG[urllib3_future.connectionpool]:Resetting dropped connection: redacted.plex.direct

[glensc]

A simple reproducer of what I'm guessing is happening, is not working. i.e simple loop with while True and sleep in it

maybe it's better (easier) if I add debug prints somewhere?

[Ousret]

We found the issue.
It is now fixed via linked PR.

regards,