Skip to content

Leaked listening socket on httpd shutdown causes intermittent playback failures #1480

Description

@chrishamm

First of all, thanks for this addon.

HTTPServer.server_close() in kodion/network/http_server.py replaces TCPServer.server_close() entirely and never closes the listening socket. Combined with allow_reuse_port = True on the same class, a shutdown can leave a bound socket behind that nobody accepts on, and the next start_httpd() binds a second socket next to it instead of failing with EADDRINUSE. The kernel then spreads incoming connections across both sockets, and everything that lands on the dead one hangs until the caller times out.

Context

  • Add-on Version: 7.4.4
  • Kodi Version: 21.3-Omega
  • Kodi GUI Language: English (en_gb)
  • Operating System: LibreELEC 12.2.1, aarch64, Python 3.11.13
  • Operating System Language: en_GB.UTF-8

Expected Behavior

shutdown_httpd() releases the proxy port. At most one socket is bound to it at any time.


Current Behavior

Two sockets listening on the proxy port, both owned by the same kodi.bin:

tcp        0      0 127.0.0.1:50152         0.0.0.0:*               LISTEN      1173/kodi.bin
tcp        6      0 127.0.0.1:50152         0.0.0.0:*               LISTEN      1173/kodi.bin

The second one sits at a permanently full accept backlog (6 = request_queue_size 5 + 1) and there were six connections in CLOSE_WAIT next to it. Ten requests to /ping from the box itself, %{http_code} and %{time_total}:

501/0.003470 501/0.002557 000/3.002385 501/0.002180 501/0.007498
501/0.005212 501/0.003338 501/0.002511 000/3.002294 501/0.002650

The 000 ones hit the dead socket and never get an answer. 501 is just because /ping is not a real path, the point is that the live socket answers in 3 ms.

Playback needs the manifest plus a stream of segment requests through the proxy, so in practice most attempts fail:

error <general>: CCurlFile::Open - <http://127.0.0.1:50152/youtube/manifest/dash?file=BnSTr7_NwtU.mpd> Failed with code 0:
error <general>: AddOnLog: inputstream.adaptive: Download failed, internal error: http://127.0.0.1:50152/youtube/manifest/dash?file=BnSTr7_NwtU.mpd
error <general>: CVideoPlayer::OpenInputStream - error opening [plugin://plugin.video.youtube/play/?video_id=BnSTr7_NwtU]
error <general>: Playlist Player: skipping unplayable item: 0, path [plugin://plugin.video.youtube/play/?video_id=BnSTr7_NwtU]

A Kodi restart fixes it and it comes back hours later. That matches how often the shutdown/restart cycle runs here: 10 HTTPServer: Starting lines in one kodi.log, 45 in the previous one.


Steps to Reproduce

  1. Let the addon run normally until the service monitor has gone through a number of idle shutdown/restart cycles. grep "HTTPServer: Shutting down" kodi.log to see them.
  2. netstat -tlnp | grep 50152. Once there are two LISTEN rows for the same PID, one of them with a non-zero Recv-Q, the box is in the broken state.
  3. for i in $(seq 1 10); do curl -s -m 3 -o /dev/null -w "%{http_code} " http://127.0.0.1:50152/ping; done gives a mix of 501 and 000.
  4. Play any video. It usually fails with the errors above, and occasionally works.

I could not pin down which cycle leaks. It is not every one, only those where a handler thread is still alive when the shutdown runs, which is why it takes hours to show up rather than happening on the first restart.


Log

I only have the ordinary event log for this, not a full debug log, since the box had already been in the broken state for days by the time I looked. The relevant lines are quoted above. The netstat and curl output is more conclusive than a debug log would be anyway, and both can be reproduced on any box in this state.


Additional Information

As far as I can tell the sequence is:

  1. shutdown_httpd() starts a thread for self.httpd.shutdown() and joins both threads with a 2 second timeout. If a request handler is still busy, the join times out and it carries on regardless.
  2. self.httpd.server_close() runs. It never calls super() and never touches self.socket, so the listening socket stays open. It also returns early on the AttributeError from self._threads.pop_all().
  3. self.httpd = None drops the reference, but the still-running handler thread holds self.server, so the socket is not garbage collected either. It stays bound and listening with nothing accepting on it.
  4. start_httpd() binds a new socket to the same address. allow_reuse_port = True makes that succeed silently.

What I run locally, on top of 7.4.4:

-    allow_reuse_port = True
+    allow_reuse_port = False

     def server_close(self):
+        self.socket.close()
+
         request_handler = self.RequestHandlerClass

The self.socket.close() is the actual fix. Turning off SO_REUSEPORT is not strictly needed, but with it off a leak that slips through shows up as a visible bind error instead of half the connections silently going nowhere, and I do not think a single server needs it. Since the patched shutdown the port is properly released on every idle shutdown here, and the video that had been failing for a week plays.

Both anxdpanic/master and MoojMidge/master and v7.4 still have the unpatched server_close as of today.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions