jellyfin / jellyfin

The Free Software Media System
https://jellyfin.org
GNU General Public License v2.0
33.78k stars 3.09k forks source link

Quick POSTs to DisplayPreferences endpoint can lead to database concurrency problems #5261

Open ferferga opened 3 years ago

ferferga commented 3 years ago

Describe the bug When posting to https://api.jellyfin.org/#operation/UpdateDisplayPreferences too quickly, the server's controller might run the same database query at the same time, leading to concurrency problems

System (please complete the following information):

To Reproduce

  1. Login using jellyfin-vue
  2. Change between darkMode and light mode really quick (multiple times in less than a second)
  3. Error will appear and the following log will be printed:
[2021-02-17 22:37:16.615 +00:00] [ERR] [101] Jellyfin.Server.Middleware.ExceptionMiddleware: Error processing request. URL "GET" "/DisplayPreferences/usersettings".
Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for details.
 ---> Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 19: 'UNIQUE constraint failed: CustomItemDisplayPreferences.UserId, CustomItemDisplayPreferences.ItemId, CustomItemDisplayPreferences.Client, CustomItemDisplayPreferences.Key'.
   at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db)

Also this appears afterwards:

[2021-02-17 22:37:16.668 +00:00] [ERR] [147] Jellyfin.Server.Middleware.ExceptionMiddleware: Error processing request. URL "POST" "/DisplayPreferences/usersettings".
System.InvalidOperationException: A second operation was started on this context before a previous operation completed. This is usually caused by different threads concurrently using the same instance of DbContext. For more information on how to avoid threading issues with DbContext, see https://go.microsoft.com/fwlink/?linkid=2097913.
   at Microsoft.EntityFrameworkCore.Internal.ConcurrencyDetector.EnterCriticalSection()
   at Microsoft.EntityFrameworkCore.Query.Internal.SingleQueryingEnumerable`1.Enumerator.MoveNext()
   at System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source)
   at lambda_method537(Closure , QueryContext )
   at Microsoft.EntityFrameworkCore.Query.Internal.QueryCompiler.Execute[TResult](Expression query)
   at Microsoft.EntityFrameworkCore.Query.Internal.EntityQueryProvider.Execute[TResult](Expression expression)
   at System.Linq.Queryable.FirstOrDefault[TSource](IQueryable`1 source, Expression`1 predicate)
   at Jellyfin.Server.Implementations.Users.DisplayPreferencesManager.GetDisplayPreferences(Guid userId, Guid itemId, String client)
   at Jellyfin.Api.Controllers.DisplayPreferencesController.UpdateDisplayPreferences(String displayPreferencesId, Guid userId, String client, DisplayPreferencesDto displayPreferences)
   at lambda_method755(Closure , Object , Object[] )
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
stale[bot] commented 3 years ago

This issue has gone 120 days without comment. To avoid abandoned issues, it will be closed in 21 days if there are no new comments. If you're the original submitter of this issue, please comment confirming if this issue still affects you in the latest release or nightlies, or close the issue if it has been fixed. If you're another user also affected by this bug, please comment confirming so. Either action will remove the stale label. This bot exists to prevent issues from becoming stale and forgotten. Jellyfin is always moving forward, and bugs are often fixed as side effects of other changes. We therefore ask that bug report authors remain vigilant about their issues to ensure they are closed if fixed, or re-confirmed - perhaps with fresh logs or reproduction examples - regularly. If you have any questions you can reach us on Matrix or Social Media.

nielsvanvelzen commented 2 years ago

Running into this issue in jellyfin-androidtv with 10.7.7 after our move to the SDK for loading display preferences (which makes simultaneous requests to retrieve multiple display preferences). We're just GETting instead of POSTing though.

[2021-10-19 19:37:16.231 +02:00] [ERR] [19] Jellyfin.Server.Middleware.ExceptionMiddleware: Error processing request. URL "GET" "/DisplayPreferences/usersettings".
System.InvalidOperationException: A second operation was started on this context before a previous operation completed. This is usually caused by different threads concurrently using the same instance of DbContext. For more information on how to avoid threading issues with DbContext, see https://go.microsoft.com/fwlink/?linkid=2097913.
   at Microsoft.EntityFrameworkCore.Internal.ConcurrencyDetector.EnterCriticalSection()
   at Microsoft.EntityFrameworkCore.Query.Internal.SingleQueryingEnumerable`1.Enumerator.MoveNext()
   at System.Linq.Enumerable.SingleOrDefault[TSource](IEnumerable`1 source)
   at Jellyfin.Server.Implementations.Users.DisplayPreferencesManager.GetDisplayPreferences(Guid userId, Guid itemId, String client)
   at Jellyfin.Api.Controllers.DisplayPreferencesController.GetDisplayPreferences(String displayPreferencesId, Guid userId, String client)
   at lambda_method321(Closure , Object , Object[] )
   at Microsoft.AspNetCore.Mvc.Infrastructure.ActionMethodExecutor.SyncObjectResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeActionMethodAsync()
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted)
   at Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeNextActionFilterAsync()
barronpm commented 2 years ago

It looks like two different issues are being described here: The first being this stacktrace:

[2021-02-17 22:37:16.615 +00:00] [ERR] [101] Jellyfin.Server.Middleware.ExceptionMiddleware: Error processing request. URL >"GET" "/DisplayPreferences/usersettings".
Microsoft.EntityFrameworkCore.DbUpdateException: An error occurred while updating the entries. See the inner exception for >details.
---> Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 19: 'UNIQUE constraint failed: >CustomItemDisplayPreferences.UserId, CustomItemDisplayPreferences.ItemId, CustomItemDisplayPreferences.Client, >CustomItemDisplayPreferences.Key'.
  at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db)

which seems to be caused by trying to concurrently update the same entry, the fix for which is non-trivial without extensive locking at first glance.

The second is a problem with multiple requests to the same context being invoked simultaneously due to some weird behavior, potentially in our middleware? I'll have to investigate this further.