Chasing down YapDatabase sqlite corruption issue

[Nathan Spindel]

Hello,

I'm using YapDatabase in a new iOS app. It's going great, except for an intermittent database corruption bug which causes data loss. This issue happens in the simulator and on multiple devices, and unfortunately I can't reliably reproduce it. The corruption occurs often enough that I need to (a) track it down (b) stop using YapDatabase. I'd greatly prefer the former. ;)

Do you have advice on how to track this down? I've searched around, read Robbie's response in YapDatabase Issue 81 (same symptom) and the ensuing How To Corrupt An SQLite Database File, but none have led me to the root cause. Are there any specific practices or YapDatabase configuration/usage issues to look for that could be culprit?

Here's a snippet of YapDatabaseTransaction logs after the corruption has started (after one day of flawless database use across multiple app launches). For what it's worth I've explicitly disabled iOS Data Protection so I don't think it's related (despite the 'file is encrypted' message). If it helps I'm using the default serializer/deserializer, the default database options, and latest release versions of all the things: YapDatabase 2.7.3, Xcode 7.0.2, iOS 9 SDK.

2015/10/15 21:53:34:350  < app did finish launching >
2015/10/15 21:53:34:351  Opening database at /var/mobile/Containers/Data/Application/06FAA9C2-6EF5-4654-95E6-6693C63231B9/Library/Application Support/Database/db.sqlite
2015/10/15 21:53:34:636  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollections:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 21:53:35:531  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 21:53:35:541  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 22:25:33:416  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database
2015/10/15 22:25:37:263  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database
2015/10/15 22:25:37:357  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database

Any pointers would be greatly appreciated.

Thanks much!

Nathan

[Robbie Hanson]

There are a couple common culprits I can think of. If none of these are the offenders, then there are a few other things we can look into.

- The database file itself is being “synced” by some cloud service. (In which case this probably also applies to the database WAL file too. Making it more than twice as likely to experience corruption.)

Are you storing the database file in such a way that a service is syncing it in the cloud? iCloud drive? Or dropbox? Etc?

- Using YapDatabase from more than one process simultaneously.

Are you doing funky stuff involving Watches or TV’s that may involve multiple processes ?

- Are you using SQLCipher ?

(Not that this is a common culprit, but using the wrong passphrase could be a problem.)

-Robbie Hanson

--
You received this message because you are subscribed to the Google Groups "YapDatabase" group.
To unsubscribe from this group and stop receiving emails from it, send an email to yapdatabase...@googlegroups.com.
To post to this group, send email to yapda...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Nathan Spindel]

Thanks for your reply, Robbie! I've answered your questions in-line below.

On Mon, Oct 19, 2015 at 9:31 AM, Robbie Hanson <robbie...@deusty.com> wrote:

There are a couple common culprits I can think of. If none of these are the offenders, then there are a few other things we can look into.

- The database file itself is being “synced” by some cloud service. (In which case this probably also applies to the database WAL file too. Making it more than twice as likely to experience corruption.)  

Are you storing the database file in such a way that a service is syncing it in the cloud? iCloud drive? Or dropbox? Etc?

No - unless you count the standard iCloud Backup performed by the OS. Have other YapDatabase apps run into corruption issues with iCloud Backup?

 

- Using YapDatabase from more than one process simultaneously.

Are you doing funky stuff involving Watches or TV’s that may involve multiple processes ?

The app just uses one iOS process.

It might be worth mentioning that the app uses background fetch and periodically read/writes to the database in the background (this is still one process total, and both the foreground and background database updates use the same single YapDatabase object and connections).

 

- Are you using SQLCipher ?

No.

What should we look into next? Thanks again for your help in debugging this.

On October 16, 2015 at 5:23:19 PM, Nathan Spindel (nat...@gmail.com) wrote:

Hello,

I'm using YapDatabase in a new iOS app. It's going great, except for an intermittent database corruption bug which causes data loss. This issue happens in the simulator and on multiple devices, and unfortunately I can't reliably reproduce it. The corruption occurs often enough that I need to (a) track it down (b) stop using YapDatabase. I'd greatly prefer the former. ;)

Do you have advice on how to track this down? I've searched around, read Robbie's response in YapDatabase Issue 81 (same symptom) and the ensuing How To Corrupt An SQLite Database File, but none have led me to the root cause. Are there any specific practices or YapDatabase configuration/usage issues to look for that could be culprit?

Here's a snippet of YapDatabaseTransaction logs after the corruption has started (after one day of flawless database use across multiple app launches). For what it's worth I've explicitly disabled iOS Data Protection so I don't think it's related (despite the 'file is encrypted' message). If it helps I'm using the default serializer/deserializer, the default database options, and latest release versions of all the things: YapDatabase 2.7.3, Xcode 7.0.2, iOS 9 SDK.

2015/10/15 21:53:34:350  < app did finish launching >
2015/10/15 21:53:34:351  Opening database at /var/mobile/Containers/Data/Application/06FAA9C2-6EF5-4654-95E6-6693C63231B9/Library/Application Support/Database/db.sqlite
2015/10/15 21:53:34:636  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollections:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 21:53:35:531  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 21:53:35:541  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed
2015/10/15 22:25:33:416  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database
2015/10/15 22:25:37:263  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database
2015/10/15 22:25:37:357  YapDatabaseTransaction: _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 26 file is encrypted or is not a database


Any pointers would be greatly appreciated.

Thanks much!

Nathan

--
You received this message because you are subscribed to the Google Groups "YapDatabase" group.
To unsubscribe from this group and stop receiving emails from it, send an email to yapdatabase...@googlegroups.com.
To post to this group, send email to yapda...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to a topic in the Google Groups "YapDatabase" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/yapdatabase/y-BmIVXGlJA/unsubscribe.
To unsubscribe from this group and all its topics, send an email to yapdatabase...@googlegroups.com.

[Robbie Hanson]

On October 19, 2015 at 10:23:38 AM, Nathan Spindel (nat...@gmail.com) wrote:

Thanks for your reply, Robbie! I've answered your questions in-line below.

On Mon, Oct 19, 2015 at 9:31 AM, Robbie Hanson <robbie...@deusty.com> wrote:

There are a couple common culprits I can think of. If none of these are the offenders, then there are a few other things we can look into.

- The database file itself is being “synced” by some cloud service. (In which case this probably also applies to the database WAL file too. Making it more than twice as likely to experience corruption.)  

Are you storing the database file in such a way that a service is syncing it in the cloud? iCloud drive? Or dropbox? Etc?

No - unless you count the standard iCloud Backup performed by the OS. Have other YapDatabase apps run into corruption issues with iCloud Backup?

Not that I’m aware of. But issue 2.2 (from https://www.sqlite.org/howtocorrupt.html) talks about a close()  on a file descriptor possibly cancelling advisory locks. Which made me envision the OS opening the file in order to stream the contents to the backup. And then close()’ing it afterwards.

I can’t say this is for sure an issue. Especially since you’re only using the database from a single process. But it may be worth disabling iCloud backup for all 3 files just to be sure:

- database, wal, & shm

 

- Using YapDatabase from more than one process simultaneously.

Are you doing funky stuff involving Watches or TV’s that may involve multiple processes ?

The app just uses one iOS process.

It might be worth mentioning that the app uses background fetch and periodically read/writes to the database in the background (this is still one process total, and both the foreground and background database updates use the same single YapDatabase object and connections).

I’m not aware of background read/writes to a local file having any issues.

 

- Are you using SQLCipher ?

No.

What should we look into next? Thanks again for your help in debugging this.

In YapDatabase.m, around line #699, comment out the following lines:

status = sqlite3_exec(db, "PRAGMA synchronous = NORMAL;", NULL, NULL, NULL);

if (status != SQLITE_OK)

{

    YDBLogError(@"Error setting PRAGMA synchronous: %d %s", status, sqlite3_errmsg(db));

    // This isn't critical, so we can continue.

}

Based on the documentation, this shouldn’t be an issue. But I’ve seen cases where the documentation has diverged from the implementation in the past. (Also concerning PRAGMA synchronous.)

This should have the effect of setting PRAGMA synchronous to FULL (the default) for the database connection that performs checkpoints.

Let me know if the problem disappears from this.

[Nathan Spindel]

Thanks Robbie. I tried both of these suggestions, and unfortunately I was still able to reproduce the corruption problem (on first clean launch of the app and a new database, no background / backup were necessary).

In further auditing the app code I realize there are multiple places where it executes a transaction within a transaction (I learned this is not allowed in <https://github.com/yapstudios/YapDatabase/wiki/Thread-Safety>). It's not appearing to cause deadlocks at the moment, but is this error potentially a source of corruption? Regardless I'll fix it and see if the problem persists.

As an aside, it might be helpful in debug builds for YapDatabaseConnection to warn/raise on transaction-within-transaction execution. Have you given any thought to that? I might be willing to help implementing it.

[Robbie Hanson]

I think, perhaps, I’ve misunderstood what you meant this whole time.

When you said “database corruption”, I was operating under the assumption that the database completely broke. 100%. And could no longer be read from or written to.

But from the last email, it sounds like the database is generally working, but every so often you’re seeing this error message appear on the screen:

> _enumerateKeysAndObjectsInCollection:usingBlock:withFilter: - sqlite_step error: 11 database disk image is malformed

If this is the case, then the error message (coming from sqlite) is misleading. As you’ve pointed out, it’s likely because the following code causes a problem:

[databaseConnection readWithBlock:^(YapDatabaseReadTransaction *transaction){

    [transaction enumerateKeysAndObjectsInCollection:collection1 usingBlock:^(NSString *key, id object, BOOL *stop){

    

        [transaction enumerateKeysAndObjectsInCollection:collection2 usingBlock:^(NSString *key, id object, BOOL *stop){

            // enumeration within enumeration

        }];

    }];

}];

The reason for this error is because the enumerate method uses a “prepared” sqlite statement. And the combination of doing an enumerate within another enumerate is causing the two enumerations to “step on each other’s feet”. (They’re sharing the same sqlite statement, and breaking things.)

Did I understand this correctly ?

This is a bug in YapDatabase. And I thank you for pointing it out to me !

-Robbie Hanson

[Nathan Spindel]

Good news: I've refactored the code to use sibling connections instead of transactions-within-transactions, and so far I've not been able to reproduce the corruption issue. This fix looks promising so far!

Yes, you understand me correctly on both counts:

1. I would say the database "partially broke"; as in once the corruption log messages begin there are lost objects or malformed data, and occasionally the inability to update rows (this is across relaunches of the app) with a failure 11 (just like YapDatabase Issue 81).

2. The enumerate-within-another-enumerate is definitely a pattern I was using before the refactor… I'm glad I was able to help find a YapDatabase bug in our sleuthing! I recommend adding a "don't perform transactions-within-transactions on the same connection" to the first FAQ answer on best practices.

Nathan