[Enhancement] Reconnect to Signature Helper if there is not connection to it.

Fijxu commented 1 week ago

Is your enhancement request related to a problem? Please describe.

Yes, if inv_sig_helper "closes" the connection or it crashes (which happens A LOT) Invidious is not able to reconnect to the signature helper making Invidious very slow, use a lot of CPU, Memory and fail at videoplayback.

This output is shown a lot when trying to open a video with a dead signature helper server:

2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] Signature: Player might be outdated, updating
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] SigHelper: Invalid status code received nil
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] Signature: Player might be outdated, updating
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] SigHelper: Invalid status code received nil
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] Signature: Player might be outdated, updating
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] SigHelper: Invalid status code received nil
2024-09-18 21:03:56 UTC [debug] SigHelper: Error when sending a request
2024-09-18 21:03:56 UTC [debug] Signature: Player might be outdated, updating

Describe the solution you'd like

Reconnect to the signature helper if the connection is closed or it fails. I already have a fix on my fork of Invidious and it has been working well for the last ~2 hours (at the time of posting this issue)

This: https://github.com/iv-org/invidious/blob/cec3cfba774926100095246d80be401155df2f68/src/invidious/helpers/sig_helper.cr#L190-L195

Can be changed to something like this:

begin
  receive_data
rescue ex : IO::EOFError
  LOGGER.info("Connection to helper died, trying to reconnect...")
  # We close the socket because the connection ends with EOFError and the connection itself is not closed (i guess).
  @conn.close
  loop do
    begin
      @conn = Connection.new(@uri_or_path)
    rescue
      LOGGER.debug("Reconnection to helper unsuccessful, retrying.")
      sleep 1
      next
    end
    break if !@conn.closed?
  end

This is probably not the best way to do it but it works really well as far as I can see. It's already implemented in my fork at https://git.nadeko.net/Fijxu/invidious/commit/2db9396dea749f90b79baa8b712e99f6111197fd and https://inv.nadeko.net is using it.

When it tries to reconnect, the output is like this:

# docker compose logs | grep "helper died" -A1                                                                                   
invidious-2-1     | 2024-09-18 21:44:19 UTC [info] Connection to helper died, trying to reconnect...
invidious-2-1     | 2024-09-18 21:44:19 UTC [info] SigHelper: Using helper at 'inv_sig_helper_haproxy:13000'
--
invidious-3-1     | 2024-09-18 21:44:24 UTC [info] Connection to helper died, trying to reconnect...
invidious-3-1     | 2024-09-18 21:44:24 UTC [info] SigHelper: Using helper at 'inv_sig_helper_haproxy:13000'
--
invidious-1       | 2024-09-18 22:27:43 UTC [info] Connection to helper died, trying to reconnect...
invidious-2-1     | 2024-09-18 22:31:48 UTC [info] 200 GET /api/v1/comments/wPdOhH1-MME?format=html&hl=en-US&thin_mode=false 323.92ms
--
invidious-2-1     | 2024-09-18 22:33:55 UTC [info] Connection to helper died, trying to reconnect...
invidious-2-1     | 2024-09-18 22:33:55 UTC [info] SigHelper: Using helper at 'inv_sig_helper_haproxy:13000'
--
invidious-1       | 2024-09-18 22:51:46 UTC [info] Connection to helper died, trying to reconnect...
invidious-1       | 2024-09-18 22:51:46 UTC [info] SigHelper: Using helper at 'inv_sig_helper_haproxy:13000'

Additional context

The connection is never closed because it ends with EOFError making any load balancer workaround useless
When Invidious is not connected to the signature helper, the RAM usage of Invidious rises (Can use up to 1GiB of memory, or even more, but at that point my server already OOM'd the Invidious process)
inv_sig_helper crashes a lot in instances with a lot of traffic. I don't know what triggers it

unixfox commented 1 week ago

ping @SamantazFox

Fijxu commented 1 week ago

Note: there is another issue but this one is more on the side of inv_sig_helper: Sometimes inv_sig_helper hangs, keeping the socket opened without IO::EOFError. Invidious will just send the Opcode and wait for a response from the helper, but the response will never arrive and Invidious will remain waiting forever.

This generally happens when I'm starting the Invidious process, the output is like this:

Connected to redis
2024-09-19 21:02:19 UTC [info] SigHelper: Using helper at '127.0.0.1:12999'
2024-09-19 21:02:19 UTC [debug] SigHelper: Multiplexor listening
2024-09-19 21:02:19 UTC [trace] SigHelper: Send transaction 0x29c2db58 / opcode PLAYER_UPDATE_TIMESTAMP
2024-09-19 21:02:19 UTC [trace] SigHelper: Send transaction 0x29c2db58 - Done

(Connected to redis is from unixfox's patch https://github.com/yewtudotbe/invidious-custom/blob/master/patches/010-use-redis-for-video-cache.patch)

Invidious will just hang there forever, restating inv_sig_helper fixes it.

syeopite commented 1 week ago

For the other problem I suppose we should try to add a timeout

iv-org / invidious

[Enhancement] Reconnect to Signature Helper if there is not connection to it. #4926