Hi, again! I am back with a question about the SQL...

# apollo-kotlin

[Eduard Boloș]

Hi, again! I am back with a question about the SQL normalized cached, but this time it might be a bug in the stable library 🙃
We use the Apollo cache as our single source of truth in our apps, and somewhat recently we started getting some weird bug reports about the data shown in the app being stale. We got some video recordings and some application logs, where we can see the following happening:
• the user opens the app, they see old data (let's call it D0), then they pull to refresh
• fresh data (D1) is fetched, persisted in the cache, and updates are propagated to the UI with the new values
• the user closes the app at this point
• when the user opens the app again, the old data (D0) is retrieved instead and shown in the UI
• if they pull to refresh again, the correct data (D1) is fetched and shown again.
and so on 😄
This is very odd behaviour, which we cannot reproduce so far on our devices, but one of the devices we've seen this happening on was a Samsung Galaxy A03 Core (SM-A032F). As for the Apollo version, we are now on 4.0.1, but we got similar bug while we were on version 3.+.
writeToCacheAsynchronously is left to the default of false, btw.
The only idea I had about what might be wrong is that something funny is happening to the sqlite journal, but not sure how to validate this, fix, or debug further.
Any ideas of what might be going on? 🙏

[bod]

Hmm! Do you use the MemoryCache too?

[Eduard Boloș]

yes, we do

[bod]

when you say "and so on", do you mean that no matter what they do they'll keep seeing the old data after restarting the app, until they pull to refresh again?

[Eduard Boloș]

they keep seeing the old data until the cache is refreshed with the new values from the network, which happens through pull to refresh, yes. then they see good data until they close the app and open it again, with the new data seemingly being lost.

[Eduard Boloș]

cc @fred

[bod]

ok so yes it looks like the data is not written to the sql cache. If there's an exception with the SQL cache, actually by default it is swallowed and logged. (Default handler here)

[Eduard Boloș]

oh, this is great to know, thank you! I think that at this point we should hook up our own logger to apolloExceptionHandler, and get more info this way. I'll probably be back in a few days, after we gather more info 😄

[Eduard Boloș]

actually, do you have an idea already what kind of errors are common, what what some remediation techniques could be? (just to shorten the feedback loop a bit)

[bod]

> we should hook up our own logger to apolloExceptionHandler, and get more info
Exactly, that will help!

> do you have an idea already what kind of errors are common
It could be simply a full disk - although I'd expect many apps not working in that case... the user would probably know.

The db could be corrupted in some way.

We've seen SQLiteDatabaseLockedException in the past, but didn't get to the bottom of it.

We've also seen SQLiteBlobTooBigException but that was a problem while reading, not writing, so I don't think it fits.

If there's a db corruption, I don't know if much can be done other than clearing the data.

[Eduard Boloș]

Cool, thanks! I think clearing and repopulating the data in this case would make most sense, but we'll do some testing too see, haha 🤞

[fred]

we started reporting internal errors from Apollo and it turns out they're happening a lot to our users, which might also explain some cache misses we see that we couldn't explain before (and some other mysterious bugs as well)

we basically keep hitting the "Unable to merge records from the database" either because of the SQLiteBlobTooBigException you mentioned (the most prominent) or because of a mysterious NullPointerException, and we also hit the "Unable to read a record from the database" and "Unable to read records from the database" for the same reasons — it seems it's actually only failing on reads and not on writes as we were expecting

[fred]

we're currently considering putting some effort into splitting and decreasing our queries to see if it helps, and maybe also increasing the cursor size (which Eduard found referenced in this PR) — do you see anything else we might want to try or look into?

[bod]

ooh right writing to the cache also does reads first, in order to do the merge, so that makes sense.

[bod]

cursorSize, yes it should help

[bod]

note that it may be the cache keys that are too big, not necessarily the records (can also be both)

[fred]

yup that makes sense, thanks! and have you seen that NPE before or do you have any idea on what exactly might be causing it?

[bod]

hmmm this doesn't ring a bell.

This seems to be inside the SQLDelight generated code that looks like this:

public fun <T : Any> recordsForKeys(key: Collection<String>, mapper: (key: String,
      record: String) -> T): Query<T> = RecordsForKeysQuery(key) { cursor ->
    mapper(
      cursor.getString(0)!!,
      cursor.getString(1)!!
    )
  }

so probably one of the values is null in the db, which is not expected