search

bonukai / jellyfin-plugin-mediatracker

Jellyfin plugin for MediaTracker
GNU General Public License v3.0
23 stars 2 forks source link

Jellyfin server occasionally crashes due to unhandled mediatracker plugin exception #9

Closed fluffy-godzilla closed 3 months ago

fluffy-godzilla commented 4 months ago

Occasionally mediatracker plugin causes the following:

[22:42:22] [FTL] [16] Main: Unhandled Exception
System.ArgumentException: An item with the same key has already been added. Key: (17c75d4c-9cc9-4b7a-968a-d31c569246b9, c375fa92-48ca-4243-cf05-48d3a78ac67e)
   at System.Collections.Generic.Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
   at PreviousActions.ShouldSkipAction(User user, Video video, Single progress, String action)
   at Jellyfin.Plugin.MediaTracker.ServerEntryPoint.OnPlaybackChanged(PlaybackProgressEventArgs e, String action)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()

After jellyfin restarting the issue goes away for a while, and then happens again.

I was contemplating just forking and wrapping PreviousActions.ShouldSkipAction in try/catch, but then I'm not a JS dev and don't really know this codebase, so raising a ticket instead.

Jellyfin version: 10.9.7 MediaTracker 2.0.0.0

@bonukai

bonukai commented 4 months ago

This has been addressed in version 2.0.0.1

fluffy-godzilla commented 4 months ago

Thank you

fluffy-godzilla commented 4 months ago

Was too hasty closing the ticket. After installing 2.0.0.1 here's what I see:

[12:36:25] [WRN] [8] Emby.Server.Implementations.Plugins.PluginManager: Unable to reconcile plugin manifest due to an error. /config/data/plugins/MediaTracker_2.0.0.1
System.Text.Json.JsonException: The converter 'Jellyfin.Extensions.Json.Converters.JsonStringConverter' read too much or not enough. Path: $.changelog | LineNumber: 2 | BytePositionInLine: 18.
   at System.Text.Json.ThrowHelper.ThrowJsonException_SerializationConverterRead(JsonConverter converter)
   at System.Text.Json.Serialization.JsonConverter`1.VerifyRead(JsonTokenType tokenType, Int32 depth, Int64 bytesConsumed, Boolean isValueConverter, Utf8JsonReader& reader)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value, Boolean& isPopulatedValue)
   at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.ReadJsonAndSetMember(Object obj, ReadStack& state, Utf8JsonReader& reader)
   at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value, Boolean& isPopulatedValue)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.ContinueDeserialize(ReadBufferState& bufferState, JsonReaderState& jsonReaderState, ReadStack& readStack)
   at System.Text.Json.Serialization.Metadata.JsonTypeInfo`1.DeserializeAsync(Stream utf8Json, CancellationToken cancellationToken)
   at Emby.Server.Implementations.Plugins.PluginManager.ReconcileManifest(PluginManifest manifest, String path)
[12:36:25] [ERR] [8] Emby.Server.Implementations.Plugins.PluginManager: Error deserializing {
    "category": "General",
    "changelog": [
        "refactored ShouldSkipAction"
    ],
    "description": "MediaTracker scrobbler",
    "guid": "c4772eae-799e-490d-abff-4de21f99c95e",
    "name": "MediaTracker",
    "overview": "MediaTracker scrobbler",
    "owner": "bonukai",
    "targetAbi": "10.9.1.0",
    "timestamp": "2024-07-17T16:10:49Z",
    "version": "2.0.0.1"
}.
System.Text.Json.JsonException: The converter 'Jellyfin.Extensions.Json.Converters.JsonStringConverter' read too much or not enough. Path: $.changelog | LineNumber: 2 | BytePositionInLine: 18.
   at System.Text.Json.ThrowHelper.ThrowJsonException_SerializationConverterRead(JsonConverter converter)
   at System.Text.Json.Serialization.JsonConverter`1.VerifyRead(JsonTokenType tokenType, Int32 depth, Int64 bytesConsumed, Boolean isValueConverter, Utf8JsonReader& reader)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value, Boolean& isPopulatedValue)
   at System.Text.Json.Serialization.Metadata.JsonPropertyInfo`1.ReadJsonAndSetMember(Object obj, ReadStack& state, Utf8JsonReader& reader)
   at System.Text.Json.Serialization.Converters.ObjectDefaultConverter`1.OnTryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value)
   at System.Text.Json.Serialization.JsonConverter`1.TryRead(Utf8JsonReader& reader, Type typeToConvert, JsonSerializerOptions options, ReadStack& state, T& value, Boolean& isPopulatedValue)
   at System.Text.Json.Serialization.JsonConverter`1.ReadCore(Utf8JsonReader& reader, JsonSerializerOptions options, ReadStack& state)
   at System.Text.Json.JsonSerializer.ReadFromSpan[TValue](ReadOnlySpan`1 utf8Json, JsonTypeInfo`1 jsonTypeInfo, Nullable`1 actualByteCount)
   at System.Text.Json.JsonSerializer.Deserialize[TValue](ReadOnlySpan`1 utf8Json, JsonSerializerOptions options)
   at Emby.Server.Implementations.Plugins.PluginManager.LoadManifest(String dir)
[12:36:25] [INF] [8] Emby.Server.Implementations.Updates.InstallationManager: Plugin installed: MediaTracker 2.0.0.1
[12:36:26] [INF] [8] Emby.Server.Implementations.ApplicationHost: App needs to be restarted.
fluffy-godzilla commented 3 months ago

@bonukai any chance you can rebuild the 2.0.0.1 release, I think you built it before making the changes in the manifest. The released bundle still has the following in it:

  "category": "General",
    "changelog": [
        "refactored ShouldSkipAction"
    ],
bonukai commented 3 months ago

@fluffy-godzilla I have rebuilded the release

fluffy-godzilla commented 3 months ago

@bonukai The plugin installation issue is gone, but the unhandled exception while updating dictionary is back:

[08:43:41] [INF] [17] Jellyfin.Plugin.MediaTracker.ServerEntryPoint: Updating progress for episode of The IT Crowd S01E02 - 94.06% - playing for user x
[08:43:15] [INF] [12] Emby.Server.Implementations.HttpServer.WebSocketManager: WS 192.168.10.30 request
[08:43:41] [INF] [18] Jellyfin.Plugin.MediaTracker.ServerEntryPoint: Updating progress for episode of The IT Crowd S01E02 - 94.06% - paused for user x
[08:43:43] [INF] [16] Jellyfin.Plugin.MediaTracker.ServerEntryPoint: Adding episode of The IT Crowd S01E02 to seen history for user x
System.ArgumentException: An item with the same key has already been added. Key: (17c75d4c-9cc9-4b7a-968a-d31c569246b9, 691a5178-85fc-90b5-1eee-cd91f90818d5)
   at System.Collections.Generic.Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
   at PreviousActions.CanMarkAsSeen(User user, Video video)
   at Jellyfin.Plugin.MediaTracker.ServerEntryPoint.OnPlaybackChanged(PlaybackProgressEventArgs e, String action)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
Unhandled exception. System.ArgumentException: An item with the same key has already been added. Key: (17c75d4c-9cc9-4b7a-968a-d31c569246b9, 691a5178-85fc-90b5-1eee-cd91f90818d5)

To repro the issue I disabled the plugin, uninstalled it, restarted jellyfin and after it started up restarted it again. After that point jellyfin had the mediatracker plugin 2.0.0.1 running (I verified the version in dashboard and the logs). Then I simply p started playing an episode of a tv show and the skipped towards the very end and as soon as I did it crashed. Hope this helps.

fluffy-godzilla commented 3 months ago

And looking at the prior logs (still belonging to the updated 2.0.0.1 plugin) I see a slightly different exception:

[08:41:35] [INF] [21] Jellyfin.Plugin.MediaTracker.ServerEntryPoint: Updating progress for episode of The IT Crowd S01E02 - 0.00% - paused for user x
[08:41:35] [INF] [19] Jellyfin.Plugin.MediaTracker.ServerEntryPoint: Updating progress for episode of The IT Crowd S01E02 - 0.00% - playing for user x
[08:41:35] [FTL] [22] Main: Unhandled Exception
System.InvalidOperationException: Operations that change non-concurrent collections must have exclusive access. A concurrent update was performed on this collection and corrupted its state. The collection's state is no longer correct.
   at System.Collections.Generic.Dictionary`2.TryInsert(TKey key, TValue value, InsertionBehavior behavior)
   at PreviousActions.ShouldSkipAction(User user, Video video, Single progress, String action)
   at Jellyfin.Plugin.MediaTracker.ServerEntryPoint.OnPlaybackChanged(PlaybackProgressEventArgs e, String action)
   at System.Threading.Tasks.Task.<>c.<ThrowAsync>b__128_1(Object state)
   at System.Threading.QueueUserWorkItemCallback.Execute()
   at System.Threading.ThreadPoolWorkQueue.Dispatch()
   at System.Threading.PortableThreadPool.WorkerThread.WorkerThreadStart()
Unhandled exception. System.InvalidOperationException: Operations that change non-concurrent collections must have exclusive access. A concurrent update was performed on this collection and corrupted its state. The collection's state is no longer correct.
bonukai commented 3 months ago

I can't replicate those errors, could you try to remove the plugin and install it again?

fluffy-godzilla commented 3 months ago

Completely uninstalled 2.0.0.1, then 2.0.0.0 and 1.0.0.0. Removed the repo, restarted jellyfin. Installed 2.0.0.1, restarted jellyfin.

Played various episodes - the issue is gone, hopefully forever. Thanks

fluffy-godzilla commented 3 months ago

Unfortunately the issue still occurs, with the System.InvalidOperationException: Operations that change non-concurrent ... error, it just requires a long period of inactivity (I assume) before it happen.

bonukai commented 3 months ago

The Plugin should be now thread safe, helpfully stopping those errors

fluffy-godzilla commented 3 months ago

@bonukai, I've been testing 2.0.0.2 since you made the changes and so far so good, not a single crash. Great job! Thanks