dbname-log.db file does not get truncated on Azure

[mitja-p]

V5.0.5

It seems that when app is deployed to Azure the mydb-log.db never gets emptied. When I copy same files to local computer log is immediately emptied when db.GetCollection<T>(name).EnsureIndex is called.

[mitja-p]

Also, is there any way to know which version is stable and functioning? It seems that version 5.0.x are not very stable despite being out of alpha/beta stage.

[lbnascimento]

@mitja-p If your application is running a lot of operations at the same time, the auto-checkpoint might end up never happening (it only runs when it is able to get exclusive access to the datafile). Try running a manual checkpoint every once in a while.

[mitja-p]

I tried running .Checkpoint() manually on startup with connection parameters "Filename=...;Mode=Exclusive;Upgrade=true" (Upgrade flag is not important as I tried both with and without). It works fine on local computer. Running same command on Azure websites raises error: System.UnauthorizedAccessException: Access to the path 'D:\home\AppData\db\files.db' is denied. at System.IO.FileStream.FlushOSBuffer() at System.IO.FileStream.Flush(Boolean flushToDisk) at LiteDB.StreamExtensions.FlushToDisk(Stream stream) at LiteDB.Engine.DiskService.Write(IEnumerable`1 pages, FileOrigin origin) at LiteDB.Engine.WalIndexService.CheckpointInternal() at LiteDB.Engine.WalIndexService.Checkpoint() at LiteDB.Engine.LiteEngine.Checkpoint() at Storage.FileStorage..ctor(String rootPath)

There is no other access to the database at the time. The database is also little used as it is a test server.

[lbnascimento]

@mitja-p The Mode parameter in the connection string is no longer supported. The datafile is never opened in exclusive mode in v5.

Regarding the UnauthorizedAccessException, is it happening consistently?

[mitja-p]

Yes, it happens consistently. I tried a few times. Including stopping the server. Waiting a minute and then starting in case something would be still locking the file.

[lbnascimento]

@mitja-p Could you try it without Mode and Upgrade parameters and post the stack trace again?

[mitja-p]

I now initialized it with var db = new LiteDatabase(Filename); db.Checkpoint();

The exception stack is the same as above.

[mitja-p]

Also tried rebuild - same thing: System.UnauthorizedAccessException: Access to the path 'D:\home\AppData\db\files.db' is denied. at System.IO.FileStream.FlushOSBuffer() at System.IO.FileStream.Flush(Boolean flushToDisk) at LiteDB.StreamExtensions.FlushToDisk(Stream stream) at LiteDB.Engine.DiskService.Write(IEnumerable`1 pages, FileOrigin origin) at LiteDB.Engine.WalIndexService.CheckpointInternal() at LiteDB.Engine.WalIndexService.Checkpoint() at LiteDB.Engine.LiteEngine.Rebuild(RebuildOptions options) at Storage.FileStorage..ctor(String rootPath)

[lbnascimento]

@mitja-p Could you try running it with the datafile located elsewhere (maybe on C: drive, if you have access to it)? Given that it runs fine in your local computer, it is probably a permission issue of some sort.

[mitja-p]

We are talking about Azure web app. D:\home is the only folder you have access to. It could be permission issue or the nature of the storage on Azure as it is not directly disk filesystem.

[mitja-p]

Can we expect any progress on this? When log file gets to around 10Mb the database stops working.

[mitja-p]

I have made a very simple reproducible example (fails on Azure only):

public class TestItem
{
    public int Id { get; set; }

    /// <summary>
    /// Instrument id
    /// </summary>
    public string IID { get; set; }

    /// <summary>
    /// Relative file name
    /// </summary>
    public string FileName { get; set; }
}


[HttpGet]
public IActionResult Test()
{
    LiteDatabase db;
    db = new LiteDatabase(@"D:\home\test\files.db");
    Response.RegisterForDispose(db);
    int run=0;
    try
    {
        run = 1;
        db.Checkpoint();
        run = 2;
        var coll = db.GetCollection<TestItem>();
        for (var i = 0; i < 10000; i++)
            coll.Upsert(new TestItem() { IID= i.ToString(), FileName = "fn" + i });
        run = 3;
        db.Checkpoint();
        run = 4;
    }
    catch (Exception ex)
    {
        return Ok(new { msg = run + " " + ex.Message+" "+ex.StackTrace });
    }

    return Ok(new { msg = "OK" });
}

(1) No database file present yet: database is created and everything works fine. Only files.db exists when operation ends. (2) Running again reports: Access to the path 'D:\home\test\files.db' is denied.
at System.IO.FileStream.FlushOSBuffer()\r\n
at System.IO.FileStream.Flush(Boolean flushToDisk)\r\n
at LiteDB.StreamExtensions.FlushToDisk(Stream stream)\r\n
at LiteDB.Engine.DiskService.Write(IEnumerable1 pages, FileOrigin origin)\r\n at LiteDB.Engine.WalIndexService.CheckpointInternal()\r\n at LiteDB.Engine.WalIndexService.TryCheckpoint()\r\n at LiteDB.Engine.LiteEngine.AutoTransaction[T](Func2 fn)\r\n
at LiteDB.Engine.LiteEngine.Upsert(String collection, IEnumerable1 docs, BsonAutoId autoId)\r\n at LiteDB.LiteCollection1.Upsert(IEnumerable1 entities)\r\n at LiteDB.LiteCollection1.Upsert(T entity)\r\n
at Test.Controllers.TestController.Test()

There is now a 1.3Mb files.db and 8.2Mb files-log.db.

Running again reports: The process cannot access the file 'D:\home\test\files.db' because it is being used by another process.

(3) Fails at call to Checkpoint() Access to the path 'D:\home\test\files.db' is denied.
at System.IO.FileStream.FlushOSBuffer()\r\n
at System.IO.FileStream.Flush(Boolean flushToDisk)\r\n
at LiteDB.StreamExtensions.FlushToDisk(Stream stream)\r\n
at LiteDB.Engine.DiskService.Write(IEnumerable`1 pages, FileOrigin origin)\r\n
at LiteDB.Engine.WalIndexService.CheckpointInternal()\r\n
at LiteDB.Engine.WalIndexService.Checkpoint()\r\n
at LiteDB.Engine.LiteEngine.Checkpoint()\r\n
at Test.Controllers.TestController.Test()

(4) Running again fails with access denied as above: The process cannot access the file 'D:\home\test\files.db' because it is being used by another process.

To me it seems that some waiting states do not get terminated properly and a thread freezes when closing handles.

[lbnascimento]

@mitja-p Could you provide us your VM specification so we could reproduce it? Anything that helps us to create a VM identical to yours is helpful.

[mitja-p]

Yes, of course. I am using an App service on F1(Free) plan. It is an ASP.NET Core 2.1 app with latest LiteDB version 5.0.7. Do you need anything else?

[henon]

I have the same problem with exactly the same circumstances. After removing the call to Checkpoint the db seems to work but despite the documentation saying it is threadsafe I had to lock every access to the db or I would get corrupt collections all the time.

[henon]

by the way @mitja-p, I have been running a lite db v4.1.4 on azure free plan for years without issues, so downgrading might be a workaround.

[henon]

I have more info concerning this same error. Even calling Dispose() on LiteDb in app shutdown can result in an UnauthorizedAccessException

********************************************************************************
UnauthorizedAccessException: "Access to the path 'D:\home\site\wwwroot\service.db' is denied."
--------------------------------------------------------------------------------
     at System.IO.FileStream.FlushOSBuffer()
     at System.IO.FileStream.Flush(Boolean flushToDisk)
     at LiteDB.StreamExtensions.FlushToDisk(Stream stream)
     at LiteDB.Engine.DiskService.Write(IEnumerable`1 pages, FileOrigin origin)
     at LiteDB.Engine.WalIndexService.CheckpointInternal()
     at LiteDB.Engine.WalIndexService.TryCheckpoint()
     at LiteDB.Engine.LiteEngine.Dispose(Boolean disposing)
     at LiteDB.Engine.LiteEngine.Dispose()
     at LiteDB.LiteDatabase.Dispose(Boolean disposing)
********************************************************************************

[mitja-p]

Thanks! I am downgrading for now.

[LennardF1989]

This particular issue is still present on Azure with v5. Shared mode fixes the problem, but I wonder why Direct doesn't work like everywhere else.

[adamdriscoll]

I've been looking into this the last couple of days. I was able to narrow it down to this call.

https://github.com/mbdavid/LiteDB/blob/master/LiteDB/Engine/Disk/DiskService.cs#L59

Once I commented out the force open of the writer for the data file, it no longer exhibits this behavior and the log file is properly truncated and written to the data file.

            // if not readonly, force open writable datafile
            if (settings.ReadOnly == false)
            {
                //var dummy = _dataPool.Writer.CanRead;
            }

I used this test program to reproduce the problem (.NET 6.0).

https://github.com/mbdavid/LiteDB/issues/1622#issuecomment-617831234

Once I adjusted LiteDB, I also deployed it to my own app (.NET 5.0) and it also does not exhibit this problem.

I'm not sure what the implications are of this change but everything seems to be functioning properly. I'll continue to test and circle back if I run into anything.

[mhflam]

I've also experienced this issue, but it only happens on Azure App Service (Windows). I do not get this problem with Azure App Service (Linux)