Plugin throws an exception and fails if connection to MusicBrainz fails
Maxr1998 opened this issue · 4 comments
Occasionally, my ISP assigns me a shared IP that's banned by MusicBrainz/ListenBrainz, causing listen submission to fail. This failure is expected.
However, it appears that the retry policy doesn't actually work in that case. Additionally, it doesn't print the raw JSON request (anymore). I think this was introduced when recording attributes started to be resolved through MusicBrainz directly.
Logs
Feb 21 00:37:12 iridium docker[303242]: Unhandled exception. [23:37:12] [FTL] [36] Main: Unhandled Exception
Feb 21 00:37:12 iridium docker[303242]: System.Threading.Tasks.TaskCanceledException: The request was canceled due to the configured HttpClient.Timeout of 100 seconds elapsing.
Feb 21 00:37:12 iridium docker[303242]: ---> System.TimeoutException: A task was canceled.
Feb 21 00:37:12 iridium docker[303242]: ---> System.Threading.Tasks.TaskCanceledException: A task was canceled.
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.Tasks.TaskCompletionSourceWithCancellation`1.WaitWithCancellationAsync(CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.HttpConnectionPool.GetHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.HttpConnectionPool.SendWithVersionDetectionAndRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancella>
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.DiagnosticsHandler.SendAsyncCore(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at Microsoft.Extensions.Http.Logging.LoggingHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at Microsoft.Extensions.Http.Logging.LoggingScopeHttpMessageHandler.SendAsync(HttpRequestMessage request, CancellationToken cancellationToken)
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts>
Feb 21 00:37:12 iridium docker[303242]: --- End of inner exception stack trace ---
Feb 21 00:37:12 iridium docker[303242]: --- End of inner exception stack trace ---
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.HttpClient.HandleFailure(Exception e, Boolean telemetryStarted, HttpResponseMessage response, CancellationTokenSource cts, CancellationToken cancella>
Feb 21 00:37:12 iridium docker[303242]: at System.Net.Http.HttpClient.<SendAsync>g__Core|83_0(HttpRequestMessage request, HttpCompletionOption completionOption, CancellationTokenSource cts, Boolean disposeCts>
Feb 21 00:37:12 iridium docker[303242]: at Jellyfin.Plugin.Listenbrainz.Clients.BaseHttpClient.SendRequest(HttpRequestMessage request)
Feb 21 00:37:12 iridium docker[303242]: at Jellyfin.Plugin.Listenbrainz.Clients.BaseMusicbrainzClient.DoRequest[TResponse](HttpRequestMessage requestMessage)
Feb 21 00:37:12 iridium docker[303242]: at Jellyfin.Plugin.Listenbrainz.Clients.BaseMusicbrainzClient.Get[TRequest,TResponse](TRequest request)
Feb 21 00:37:12 iridium docker[303242]: at Jellyfin.Plugin.Listenbrainz.Clients.MusicbrainzClient.GetRecordingData(String trackId)
Feb 21 00:37:12 iridium docker[303242]: at Jellyfin.Plugin.Listenbrainz.Clients.ListenbrainzClient.SubmitListen(LbUser user, User jfUser, SubmitListenRequest request)
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.QueueUserWorkItemCallback.<>c.<.cctor>b__6_0(QueueUserWorkItemCallback quwi)
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.ExecutionContext.RunForThreadPoolUnsafe[TState](ExecutionContext executionContext, Action`1 callback, TState& state)
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.QueueUserWorkItemCallback.Execute()
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.ThreadPoolWorkQueue.Dispatch()
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
Feb 21 00:37:12 iridium docker[303242]: at System.Threading.Thread.StartCallback()
Yeah, this should be fixed pretty easily by handling that cancellation exception.
Additionally, it doesn't print the raw JSON request (anymore).
The request should be in the log as the request is logged before it is sent.
Or do you mean that the subsequent requests are not logged? That sounds like a complete plugin crash.
I think this was introduced when recording attributes started to be resolved through MusicBrainz directly.
MB is integrated basically from the beginning as Jellyfin does not store recording MBIDs. Or do you think that IP got banned because of this plugin? I can think of a scenario where it could happen, but that depends on multiple assumtions and I'm not sure if it would be realistically possible.
The request should be in the log as the request is logged before it is sent. Or do you mean that the subsequent requests are not logged? That sounds like a complete plugin crash.
I was referring to the JSON that's logged for the HTTP request, like this:
Jellyfin.Plugin.Listenbrainz.ServerEntryPoint:
Sending request (98e159b>
Method: POST
URI: https://api.listenbrainz.org/1/submit-listens
Data: {"listen_type":"single","payload":[…]}
This wasn't logged when the requests didn't go through, but would have been useful.
MB is integrated basically from the beginning as Jellyfin does not store recording MBIDs.
I think I misunderstood 37288ba back then, sorry the confusion.
Or do you think that IP got banned because of this plugin? I can think of a scenario where it could happen, but that depends on multiple assumtions and I'm not sure if it would be realistically possible.
No, I doubt that's the reason, it's just that my ISP regular assigns me a new IPv4 address, usually nightly, and I was simply unlucky to have received one that was previously banned.
This wasn't logged when the requests didn't go through, but would have been useful.
I see, you mean the ListenBrainz one. That actually makes sense, since the plugin is too busy crashing.
Anyway, I improved the handling of exceptions in #21. Now the exception should be caught and eventually a retry exception should be raised for the MB request, which in turn should allow LB client to attempt submit without MB metadata.
If you want, you can get the new plugin build from this job.
Thank you! I'll give the preview build a test run and report back if I encounter any issues.