Scrobbles delayed by varying amounts of time after watching media

[Terrance]

When playback finishes, it sometimes takes minutes or hours before the scrobble appears in Trakt. This has two side-effects:

• Watch history items in Trakt have the wrong time, as they appear as ending at the time of submission rather than when playback finished.
• If a background sync happens between playback finishing and the scrobble submission, two history entries are created: one (of type watch, set to the current sync time) from the background sync, and another (scrobble) from the playback tracking.

The most recent case of this was a delay of about 90 minutes. Playback finished at 20:41, which the Trakt plugin seemed to notice, but the timestamp of the resulting scrobble was 22:08. The log claims the import took 107 minutes to complete, which sounds like it was blocking the submission of that scrobble.

Log excerpt (transcoding noise removed)

[19:51:05] [INF] [49] Emby.Server.Implementations.ScheduledTasks.TaskManager: IntervalTrigger fired for task: Import watched states and playback progress from trakt.tv
[19:51:05] [INF] [49] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task SyncFromTraktTask
[19:51:05] [INF] [49] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing Import watched states and playback progress from trakt.tv
[19:51:06] [INF] [44] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched movies for user User: 265
[19:51:06] [INF] [44] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused movies for user User: 1
[19:51:06] [INF] [44] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched shows for user User: 90
[19:51:06] [INF] [44] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused episodes for user User: 3
[19:55:28] [INF] [14] Jellyfin.Api.Helpers.MediaInfoHelper: User policy for User. EnablePlaybackRemuxing: True EnableVideoPlaybackTranscoding: True EnableAudioPlaybackTranscoding: True
[19:55:28] [INF] [14] Jellyfin.Api.Helpers.MediaInfoHelper: StreamBuilder.BuildVideoItem( Profile=Anonymous Profile, Path=/srv/media/item.mp4, AudioStreamIndex=null, SubtitleStreamIndex=null ) => ( PlayMethod=Transcode, TranscodeReason=VideoCodecNotSupported ) media:/videos/...
[20:19:14] [INF] [3] Jellyfin.Networking.Manager.NetworkManager: Defined LAN addresses : [fc00::/7,fe80::/10,10.0.0.0/8,172.16.0.0/12,192.168.0.0/16]
[20:19:14] [INF] [3] Jellyfin.Networking.Manager.NetworkManager: Defined LAN exclusions : []
[20:19:14] [INF] [3] Jellyfin.Networking.Manager.NetworkManager: Using LAN addresses: [fc00::/7,fe80::/10,10.0.0.0/8,172.16.0.0/12,192.168.0.0/16]
[20:21:05] [INF] [60] Emby.Server.Implementations.ScheduledTasks.TaskManager: IntervalTrigger fired for task: Import watched states and playback progress from trakt.tv
[20:21:05] [INF] [60] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task SyncFromTraktTask
[20:21:05] [INF] [31] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing Import watched states and playback progress from trakt.tv
[20:41:53] [INF] [62] Emby.Server.Implementations.Session.SessionManager: Playback stopped reported by app Jellyfin Web 10.8.5 playing Title. Stopped at 3017988 ms
[20:41:56] [INF] [21] Trakt.ServerMediator: Playback stopped
[20:51:05] [INF] [10] Emby.Server.Implementations.ScheduledTasks.TaskManager: IntervalTrigger fired for task: Import watched states and playback progress from trakt.tv
[20:51:05] [INF] [10] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task SyncFromTraktTask
[21:21:05] [INF] [49] Emby.Server.Implementations.ScheduledTasks.TaskManager: IntervalTrigger fired for task: Import watched states and playback progress from trakt.tv
[21:21:05] [INF] [49] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task SyncFromTraktTask
[21:51:05] [INF] [45] Emby.Server.Implementations.ScheduledTasks.TaskManager: IntervalTrigger fired for task: Import watched states and playback progress from trakt.tv
[21:51:05] [INF] [45] Emby.Server.Implementations.ScheduledTasks.TaskManager: Queuing task SyncFromTraktTask
[22:08:13] [INF] [8] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched movies for user User: 265
[22:08:13] [INF] [8] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused movies for user User: 1
[22:08:13] [INF] [8] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched shows for user User: 90
[22:08:13] [INF] [8] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused episodes for user User: 3
[22:08:15] [INF] [8] Emby.Server.Implementations.ScheduledTasks.TaskManager: Import watched states and playback progress from trakt.tv Completed after 107 minute(s) and 10 seconds
[22:08:15] [INF] [8] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks
[22:08:15] [INF] [32] Emby.Server.Implementations.ScheduledTasks.TaskManager: Executing Import watched states and playback progress from trakt.tv
[22:08:16] [INF] [32] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched movies for user User: 265
[22:08:16] [INF] [32] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused movies for user User: 1
[22:08:16] [INF] [32] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv watched shows for user User: 90
[22:08:16] [INF] [32] Trakt.ScheduledTasks.SyncFromTraktTask: Trakt.tv paused episodes for user User: 3
[22:08:18] [INF] [32] Emby.Server.Implementations.ScheduledTasks.TaskManager: Import watched states and playback progress from trakt.tv Completed after 0 minute(s) and 3 seconds
[22:08:18] [INF] [32] Emby.Server.Implementations.ScheduledTasks.TaskManager: ExecuteQueuedTasks