БД Sqlite заблокирована в платформе Azure Dotnet Core Entity Framework

У меня есть простое основное веб-приложение asp.net(v2.1), которое я развернул в службе приложений Azure B1 (и пробовал B2) в Linux. Когда я вызываю dbContext.SaveChanges(), после добавления одной очень простой сущности, запрос занимает около 30 секунд, прежде чем выдает следующую ошибку:

Microsoft.Data.Sqlite.SqliteException(0x80004005): SQLite Error 5: 'database is locked'.

Вот код _dbContext внедряется с ограниченным временем жизни.

public async Task<IActionResult> SignIn([Bind("Email,Password,RedirectUrl")] SignInModel model) { if (ModelState.IsValid) { var user = _dbContext.Users.Include(u => u.Claims).FirstOrDefault(u => u.UserName == model.Email); ... user.LastLogin = DateTimeOffset.Now; await _dbContext.SaveChangesAsync(); ... return Redirect(String.IsNullOrWhiteSpace(model.RedirectUrl) ? "/" : model.RedirectUrl); } else { return View(model); } }

В течение 30 секунд я вижу, через SSH, что файл журнала существует рядом с файлом БД SQLite. Это в конечном итоге удалено.

ОБНОВЛЕНИЕ: Вот журналы. Вы можете видеть, что после одного вызова обновления исключение блокировки выдается ровно через 30 секунд. 30 секунд - это тайм-аут команды SQL. Я наблюдаю за файловой системой с помощью удаленной оболочки SSH, и файл журнала находится там в течение ~ 30 секунд. Это как комбинация сетевого ресурса, используемого службой приложения, и логики блокировки файлов SQLite, сломана или очень медленная.

2018-12-20T15:06:27.660624755Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Hosting.Internal.WebHost[1] 2018-12-20T15:06:27.660656156Z Request starting HTTP/1.1 POST http://insecuresite.azurewebsites.net/Account/SignIn application/x-www-form-urlencoded 56 2018-12-20T15:06:27.660797960Z [15:06:27 DBG] InsecureSite.Middleware.MyCookieAuthHandler:Constructor called. 2018-12-20T15:06:27.660875561Z [15:06:27 DBG] InsecureSite.Middleware.MyCookieAuthHandler:Constructor called. 2018-12-20T15:06:27.660885462Z [15:06:27 DBG] InsecureSite.Middleware.MyCookieAuthHandler:HandleAuthenticateAsync called. 2018-12-20T15:06:27.660890662Z [15:06:27 DBG] InsecureSite.Middleware.MyCookieAuthHandler:HandleAuthenticateAsync called. 2018-12-20T15:06:27.661837484Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] 2018-12-20T15:06:27.661856585Z Route matched with {action = "SignIn", controller = "Account"}. Executing action InsecureSite.Controllers.AccountController.SignIn (InsecureSite) 2018-12-20T15:06:27.662465200Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] 2018-12-20T15:06:27.662478400Z Executing action method InsecureSite.Controllers.AccountController.SignIn (InsecureSite) with arguments (InsecureSite.Models.SignInModel) - Validation state: Valid 2018-12-20T15:06:27.667736726Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Infrastructure[10403] 2018-12-20T15:06:27.667751427Z Entity Framework Core 2.1.4-rtm-31024 initialized 'AppDbContext' using provider 'Microsoft.EntityFrameworkCore.Sqlite' with options: None 2018-12-20T15:06:27.716864407Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Command[20101] 2018-12-20T15:06:27.716886507Z Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30'] 2018-12-20T15:06:27.716892507Z PRAGMA foreign_keys=ON; 2018-12-20T15:06:27.776374136Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Command[20101] 2018-12-20T15:06:27.776410837Z Executed DbCommand (59ms) [Parameters=[@__model_Email_0='?' (Size = 18)], CommandType='Text', CommandTimeout='30'] 2018-12-20T15:06:27.776514640Z SELECT "u"."UserId", "u"."FirstName", "u"."LastLogin", "u"."LastName", "u"."PasswordHash", "u"."UserName" 2018-12-20T15:06:27.776526140Z FROM "Users" AS "u" 2018-12-20T15:06:27.776531140Z WHERE "u"."UserName" = @__model_Email_0 2018-12-20T15:06:27.776536040Z ORDER BY "u"."UserId" 2018-12-20T15:06:27.776540740Z LIMIT 1 2018-12-20T15:06:27.778553489Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Command[20101] 2018-12-20T15:06:27.778567689Z Executed DbCommand (1ms) [Parameters=[@__model_Email_0='?' (Size = 18)], CommandType='Text', CommandTimeout='30'] 2018-12-20T15:06:27.778840096Z SELECT "u.Claims"."UserClaimId", "u.Claims"."Claim", "u.Claims"."UserId", "u.Claims"."Value" 2018-12-20T15:06:27.778852696Z FROM "UserClaims" AS "u.Claims" 2018-12-20T15:06:27.778857796Z INNER JOIN ( 2018-12-20T15:06:27.778862596Z SELECT "u0"."UserId" 2018-12-20T15:06:27.778869696Z FROM "Users" AS "u0" 2018-12-20T15:06:27.778874396Z WHERE "u0"."UserName" = @__model_Email_0 2018-12-20T15:06:27.778879897Z ORDER BY "u0"."UserId" 2018-12-20T15:06:27.780228429Z LIMIT 1 2018-12-20T15:06:27.780242129Z ) AS "t" ON "u.Claims"."UserId" = "t"."UserId" 2018-12-20T15:06:27.780247829Z ORDER BY "t"."UserId" 2018-12-20T15:06:27.789636555Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Command[20101] 2018-12-20T15:06:27.789651955Z Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30'] 2018-12-20T15:06:27.789657656Z PRAGMA foreign_keys=ON; 2018-12-20T15:06:27.794111763Z [40m[32minfo[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Command[20101] 2018-12-20T15:06:27.794126763Z Executed DbCommand (4ms) [Parameters=[@p1='?', @p0='?'], CommandType='Text', CommandTimeout='30'] 2018-12-20T15:06:27.794132363Z UPDATE "Users" SET "LastLogin" = @p0 2018-12-20T15:06:27.794280267Z WHERE "UserId" = @p1; 2018-12-20T15:06:27.794298667Z SELECT changes(); 2018-12-20T15:06:57.833069471Z [41m[30mfail[39m[22m[49m: Microsoft.EntityFrameworkCore.Database.Transaction[20205] 2018-12-20T15:06:57.833107571Z An error occurred using a transaction. 2018-12-20T15:06:57.833113572Z Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'. 2018-12-20T15:06:57.833118772Z at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db) 2018-12-20T15:06:57.833123772Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior) 2018-12-20T15:06:57.833128672Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery() 2018-12-20T15:06:57.833133672Z at Microsoft.Data.Sqlite.SqliteConnectionExtensions.ExecuteNonQuery(SqliteConnection connection, String commandText) 2018-12-20T15:06:57.833138672Z at Microsoft.Data.Sqlite.SqliteTransaction.Commit() 2018-12-20T15:06:57.833143372Z at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Commit() 2018-12-20T15:06:57.853805669Z [41m[30mfail[39m[22m[49m: Microsoft.EntityFrameworkCore.Update[10000] 2018-12-20T15:06:57.853833569Z An exception occurred in the database while saving changes for context type 'InsecureSite.Data.AppDbContext'. 2018-12-20T15:06:57.853928072Z Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'. 2018-12-20T15:06:57.853938272Z at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db) 2018-12-20T15:06:57.853943572Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior) 2018-12-20T15:06:57.854041474Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery() 2018-12-20T15:06:57.854051475Z at Microsoft.Data.Sqlite.SqliteConnectionExtensions.ExecuteNonQuery(SqliteConnection connection, String commandText) 2018-12-20T15:06:57.854056675Z at Microsoft.Data.Sqlite.SqliteTransaction.Commit() 2018-12-20T15:06:57.854137377Z at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Commit() 2018-12-20T15:06:57.854146577Z at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple'2 parameters, CancellationToken cancellationToken) 2018-12-20T15:06:57.854208178Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList'1 entriesToSave, CancellationToken cancellationToken) 2018-12-20T15:06:57.854283180Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.854292080Z at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.854299081Z Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'. 2018-12-20T15:06:57.854366282Z at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db) 2018-12-20T15:06:57.854384483Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior) 2018-12-20T15:06:57.854389683Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery() 2018-12-20T15:06:57.854455384Z at Microsoft.Data.Sqlite.SqliteConnectionExtensions.ExecuteNonQuery(SqliteConnection connection, String commandText) 2018-12-20T15:06:57.854463685Z at Microsoft.Data.Sqlite.SqliteTransaction.Commit() 2018-12-20T15:06:57.854468185Z at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Commit() 2018-12-20T15:06:57.854529686Z at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple'2 parameters, CancellationToken cancellationToken) 2018-12-20T15:06:57.854652489Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList'1 entriesToSave, CancellationToken cancellationToken) 2018-12-20T15:06:57.854673890Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.854748391Z at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.858109772Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2] 2018-12-20T15:06:57.858123973Z Executed action InsecureSite.Controllers.AccountController.SignIn (InsecureSite) in 30193.6715ms 2018-12-20T15:06:57.860885139Z [41m[30mfail[39m[22m[49m: Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware[1] 2018-12-20T15:06:57.860899939Z An unhandled exception has occurred while executing the request. 2018-12-20T15:06:57.860905239Z Microsoft.Data.Sqlite.SqliteException (0x80004005): SQLite Error 5: 'database is locked'. 2018-12-20T15:06:57.861009242Z at Microsoft.Data.Sqlite.SqliteException.ThrowExceptionForRC(Int32 rc, sqlite3 db) 2018-12-20T15:06:57.861018942Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteReader(CommandBehavior behavior) 2018-12-20T15:06:57.861023842Z at Microsoft.Data.Sqlite.SqliteCommand.ExecuteNonQuery() 2018-12-20T15:06:57.861120545Z at Microsoft.Data.Sqlite.SqliteConnectionExtensions.ExecuteNonQuery(SqliteConnection connection, String commandText) 2018-12-20T15:06:57.861130145Z at Microsoft.Data.Sqlite.SqliteTransaction.Commit() 2018-12-20T15:06:57.861134745Z at Microsoft.EntityFrameworkCore.Storage.RelationalTransaction.Commit() 2018-12-20T15:06:57.861237547Z at Microsoft.EntityFrameworkCore.Update.Internal.BatchExecutor.ExecuteAsync(DbContext _, ValueTuple'2 parameters, CancellationToken cancellationToken) 2018-12-20T15:06:57.861311249Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(IReadOnlyList'1 entriesToSave, CancellationToken cancellationToken) 2018-12-20T15:06:57.861320149Z at Microsoft.EntityFrameworkCore.ChangeTracking.Internal.StateManager.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.861392851Z at Microsoft.EntityFrameworkCore.DbContext.SaveChangesAsync(Boolean acceptAllChangesOnSuccess, CancellationToken cancellationToken) 2018-12-20T15:06:57.861401851Z at InsecureSite.Controllers.AccountController.SignIn(SignInModel model) in /home/site/repository/InsecureSite/Controllers/AccountController.cs:line 57 2018-12-20T15:06:57.861463253Z at Microsoft.AspNetCore.Mvc.Internal.ActionMethodExecutor.TaskOfIActionResultExecutor.Execute(IActionResultTypeMapper mapper, ObjectMethodExecutor executor, Object controller, Object[] arguments) 2018-12-20T15:06:57.861472053Z at System.Threading.Tasks.ValueTask'1.get_Result() 2018-12-20T15:06:57.861541855Z at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeActionMethodAsync() 2018-12-20T15:06:57.861550055Z at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeNextActionFilterAsync() 2018-12-20T15:06:57.861554655Z at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Rethrow(ActionExecutedContext context) 2018-12-20T15:06:57.861629257Z at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted) 2018-12-20T15:06:57.861639057Z at Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker.InvokeInnerFilterAsync() 2018-12-20T15:06:57.861718659Z at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeNextResourceFilter() 2018-12-20T15:06:57.861727059Z at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Rethrow(ResourceExecutedContext context) 2018-12-20T15:06:57.861791861Z at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.Next(State& next, Scope& scope, Object& state, Boolean& isCompleted) 2018-12-20T15:06:57.861800861Z at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeFilterPipelineAsync() 2018-12-20T15:06:57.861805561Z at Microsoft.AspNetCore.Mvc.Internal.ResourceInvoker.InvokeAsync() 2018-12-20T15:06:57.861810161Z at Microsoft.AspNetCore.Builder.RouterMiddleware.Invoke(HttpContext httpContext) 2018-12-20T15:06:57.861880363Z at Microsoft.AspNetCore.Authentication.AuthenticationMiddleware.Invoke(HttpContext context) 2018-12-20T15:06:57.861888363Z at Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware.Invoke(HttpContext context) 2018-12-20T15:06:57.861948164Z at Microsoft.AspNetCore.Diagnostics.ExceptionHandlerMiddleware.Invoke(HttpContext context) 2018-12-20T15:06:57.862056667Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] 2018-12-20T15:06:57.862066767Z Route matched with {action = "Error", controller = "Home"}. Executing action InsecureSite.Controllers.HomeController.Error (InsecureSite) 2018-12-20T15:06:57.867899207Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1] 2018-12-20T15:06:57.867914108Z Executing action method InsecureSite.Controllers.HomeController.Error (InsecureSite) - Validation state: Valid 2018-12-20T15:06:57.868025910Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2] 2018-12-20T15:06:57.868045011Z Executed action method InsecureSite.Controllers.HomeController.Error (InsecureSite), returned result Microsoft.AspNetCore.Mvc.ViewResult in 0.0771ms. 2018-12-20T15:06:57.868147613Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[1] 2018-12-20T15:06:57.868157914Z Executing ViewResult, running view Error. 2018-12-20T15:06:57.869182938Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.ViewFeatures.ViewResultExecutor[4] 2018-12-20T15:06:57.869196139Z Executed ViewResult - view Error executed in 7.5623ms. 2018-12-20T15:06:57.869201439Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2] 2018-12-20T15:06:57.869206339Z Executed action InsecureSite.Controllers.HomeController.Error (InsecureSite) in 7.9125ms 2018-12-20T15:06:57.869222639Z [40m[32minfo[39m[22m[49m: Microsoft.AspNetCore.Hosting.Internal.WebHost[2] 2018-12-20T15:06:57.869228039Z Request finished in 30208.5835ms 500 text/html; charset=utf-8 2018-12-20T15:08:44 No new trace in the past 1 min(s).

Других запросов на это веб-приложение нет. Я единственный, кто делает запросы.

Контроллеры могут читать данные из файла БД без ошибок. Я вижу, что пара запросов непосредственно перед неудачной записью занимает 3 мс и 6 мс.

Я видел, что была проблема с блокировкой и несколькими потоками, но она исправлена, и я исправляю более позднюю версию (2.1.4)

Ответы

Ответ 1

Это чаще всего вызвано открытыми или ожидающими запросами на подключение, которые не удалось обработать из-за того, что какой-то более ранний процесс захватил блокировку. Вы можете попробовать следующую реализацию, используя которую соединение и команды могут быть расположены in order.

private static void ExecuteNonQuery(string queryString)
{
    using (var connection = new SQLiteConnection(
               ConnectionString))
    {
        using (var command = new SQLiteCommand(queryString, connection))
        {
            command.Connection.Open();
            command.ExecuteNonQuery();
        }
    }
}

Ответ 2

Можете ли вы поделиться своим методом обновления? иногда база данных блокируется, потому что код С# не использует соединение/транзакцию базы данных надлежащим образом.

Я предлагаю вам взглянуть на ваш метод обновления и посмотреть, правильно ли используются соединение с базой данных и транзакция. Документация Microsoft может помочь

using (var context = new BloggingContext())
{
    using (var transaction = context.Database.BeginTransaction())
    {
        try
        {
            context.Blogs.Add(new Blog { Url = "http://blogs.msdn.com/dotnet" });
            context.SaveChanges();

            context.Blogs.Add(new Blog { Url = "http://blogs.msdn.com/visualstudio" });
            context.SaveChanges();

            var blogs = context.Blogs
                .OrderBy(b => b.Url)
                .ToList();

            // Commit transaction if all commands succeed, transaction will auto-rollback
            // when disposed if either commands fails
            transaction.Commit();
        }
        catch (Exception)
        {
            // TODO: Handle failure
        }
    }
}