search

lyarenei / jellyfin-plugin-listenbrainz

ListenBrainz plugin for Jellyfin.
MIT License
78 stars 3 forks source link

[Bug]: crashes the server #64

Closed waaipe closed 10 months ago

waaipe commented 10 months ago

Bug description

I recently noticed that my Jellyfin server is crashing while using this plugin.

Steps to reproduce

  1. Play music on Jellyfin
  2. Wait until the breaking point (this could take up to 10 hours)
  3. The server is now most likely stopped

Expected behavior

I would keep listening to music as usual

Actual behavior

Server crashes, logs always mention an unhandled exception

Relevant log output

[2024-01-01 03:15:43.717 +01:00] [FTL] [103] Main: Unhandled Exception
Jellyfin.Plugin.ListenBrainz.Exceptions.PluginException: No recording MSID is associated with listen timestamp 1704075325
   at Jellyfin.Plugin.ListenBrainz.PluginImplementation.SendFeedbackUsingMsid(UserConfig userConfig, Boolean isFavorite, Int64 listenTs)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.<>c.<.cctor>b__6_0(QueueUserWorkItemCallback quwi)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

....

[2024-01-04 02:50:49.788 +01:00] [FTL] [140] Main: Unhandled Exception
Jellyfin.Plugin.ListenBrainz.Http.Exceptions.RetryException: Retry limit reached
   at Jellyfin.Plugin.ListenBrainz.Http.HttpClient.SendRequest(HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   at Jellyfin.Plugin.ListenBrainz.Api.BaseApiClient.DoRequest[TResponse](HttpRequestMessage requestMessage, CancellationToken cancellationToken)
   at Jellyfin.Plugin.ListenBrainz.Api.BaseApiClient.SendGetRequest[TRequest,TResponse](TRequest request, CancellationToken cancellationToken)
   at Jellyfin.Plugin.ListenBrainz.Api.ListenBrainzApiClient.ValidateToken(ValidateTokenRequest request, CancellationToken cancellationToken)
   at Jellyfin.Plugin.ListenBrainz.Clients.ListenBrainzClient.GetRecordingMsidByListenTs(UserConfig config, Int64 ts)
   at Jellyfin.Plugin.ListenBrainz.PluginImplementation.SendFeedbackUsingMsid(UserConfig userConfig, Boolean isFavorite, Int64 listenTs)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.<>c.<.cctor>b__6_0(QueueUserWorkItemCallback quwi)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

....

[2024-01-05 02:16:53.153 +01:00] [FTL] [208] Main: Unhandled Exception
Jellyfin.Plugin.ListenBrainz.Exceptions.PluginException: No recording MSID is associated with listen timestamp 1704417395
   at Jellyfin.Plugin.ListenBrainz.PluginImplementation.SendFeedbackUsingMsid(UserConfig userConfig, Boolean isFavorite, Int64 listenTs)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.<>c.<.cctor>b__6_0(QueueUserWorkItemCallback quwi)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

Plugin version

3.2.0.0

Jellyfin Version

10.8.13

Additional context

I run Jellyfin on my Windows machine, which is currently up to date. The first part of the log output is with an older version of Jellyfin, but this is most likely not important due to the same error happening with the recent version of Jellyfin later.

lyarenei commented 10 months ago

Hi @waaipe, thanks for the report.

The unhandled exceptions are really weird. I've looked at the code, but to my best knowledge, these exceptions should be properly handled.

Can you please provide more complete logs? Seeing what predeces the unhandled exceptions might give us some clues. Please also enable debug logging, so more info is logged.

Thank you.

waaipe commented 10 months ago

I have enabled debug logging and will provide more complete logs when a crash occurs again.

waaipe commented 10 months ago

log_20240106-u.log

The crash occurs at the very end of the log

lyarenei commented 10 months ago

log_20240106-u.log

The crash occurs at the very end of the log

Thanks for the log. Unfortunately this is not a debug log. When debug log level is active, you would see entries with [DBG], for example like this:

[21:44:01] [DBG] [1] Jellyfin.Networking.Manager.NetworkManager: Refreshing interfaces.
[21:44:01] [DBG] [1] Jellyfin.Networking.Manager.NetworkManager: Discovered 2 interfaces.
[21:44:01] [DBG] [1] Jellyfin.Networking.Manager.NetworkManager: Interfaces addresses : [127.0.0.1/8,192.168.0.119/24]
[21:44:01] [DBG] [1] Jellyfin.Networking.Manager.NetworkManager: Refreshing LAN information.
[21:44:01] [DBG] [1] Jellyfin.Networking.Manager.NetworkManager: Using LAN interface addresses as user provided no LAN details.
waaipe commented 10 months ago

My bad, I have set the debug logging in a wrong file. log_20240108-u.log

lyarenei commented 10 months ago

@waaipe Oh, I see, thanks. I'm currently not feeling very well, so I'm not really in the mood looking into this right now.

So I just want to let you know that I did not forget about this. :)

lyarenei commented 10 months ago

@waaipe I gave up on trying to figure out why the exception was not being caught, so I just removed it. Unfortunately, logging in that part of code suffered a bit, but I want to redo the logging anyway, so that part will be revisited at some point.

Anyway, with the plugin version 3.2.1.0, the server should not crash anymore, at least.