Anki-android: DeckDueList NullPointerException - Attempt to read from null array

[david-allison-1]

https://couchdb.ankidroid.org/acralyzer/_design/acralyzer/index.html#/report-details/8af3682b-1cc3-4e16-9842-6027fa17e8ea

java.lang.NullPointerException: Attempt to read from null array
at com.ichi2.libanki.sched.Sched.deckDueList(Sched.java:11)
at com.ichi2.libanki.sched.SchedV2.deckDueList(SchedV2.java:1)
at com.ichi2.libanki.sync.Syncer.sanityCheck(Syncer.java:36)
at com.ichi2.libanki.sync.Syncer.sync(Syncer.java:84)
at com.ichi2.async.Connection.doInBackgroundSync(Connection.java:16)
at com.ichi2.async.Connection.doOneInBackground(Connection.java:2)
at com.ichi2.async.Connection.doInBackground(Connection.java:4)
at com.ichi2.async.Connection.doInBackground(Connection.java:1)
at android.os.AsyncTask$2.call(AsyncTask.java:333)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
at java.lang.Thread.run(Thread.java:764)

@Arthur-Milchior - this seems related to 5aa75331f67603df8e18d37ebf9721769f1dcab2

[Arthur-Milchior]

Do you know how I'm supposed to read "com.ichi2.libanki.sched.Sched.deckDueList(Sched.java:11)" exactly ? Because when I check out release 2.11, the 11th line of deckDueList has no array.

What the error means here is that AnkiDroid way trying to get the get the limits of a deck foo::bar, but does not already have the limits for the deck foo. Since checkIntegrity was already called, in theory, foo should already exists. It may have not been processed if, by accident, foo was sorted after foo::bar by the sorting algorithm. Since it takes an order function which takes deck name into consideration, this should theoretically not be possible.
I am not 100% confident over my code, in particular if there is a non-normalized deck name, but I would be surprised that it would be the problem here; in particular because if it was the case, we would see a lot of bug report of this kind.

The remaining explanation would be that the set of deck was changed while deckDueList is executed. There is actually nothing which forbids it. I guess it is theoretically possible that you sync/rename a deck/create a deck just after the method is called. This would mean that the result of this deckDueList is useless, as a new deckDueList will be executed immediately after the action ends. I believe that if I am right the solution would be to check whether .get returns null, and in this case, by default, gets an array containing only zeros. This is not a problem since the result will be discarded anyway. Or we could cancel this task when a sync/deck action occurs.

We could also ignore this ef it occurs extremely rarely.

[mikehardy]

Do you know how I'm supposed to read "com.ichi2.libanki.sched.Sched.deckDueList(Sched.java:11)" exactly ? Because when I check out release 2.11, the 11th line of deckDueList has no array.

The line numbers cannot be trusted unfortunately. With small methods and the full stack trace usually that's enough to still reason through a crash, but unfortunately the de-obfuscation files aren't used in acralyzer after minimizing the APK for release and the correct line number information isn't being preserved for some reason - something about the proguard file isn't correct https://github.com/ankidroid/Anki-Android/blob/master/AnkiDroid/proguard-rules.pro

What the error means here is that AnkiDroid way trying to get the get the limits of a deck foo::bar, but does not already have the limits for the deck foo. Since checkIntegrity was already called, in theory, foo should already exists. It may have not been processed if, by accident, foo was sorted after foo::bar by the sorting algorithm. Since it takes an order function which takes deck name into consideration, this should theoretically not be possible.
I am not 100% confident over my code, in particular if there is a non-normalized deck name, but I would be surprised that it would be the problem here; in particular because if it was the case, we would see a lot of bug report of this kind.

The remaining explanation would be that the set of deck was changed while deckDueList is executed. There is actually nothing which forbids it. I guess it is theoretically possible that you sync/rename a deck/create a deck just after the method is called. This would mean that the result of this deckDueList is useless, as a new deckDueList will be executed immediately after the action ends. I believe that if I am right the solution would be to check whether .get returns null, and in this case, by default, gets an array containing only zeros. This is not a problem since the result will be discarded anyway. Or we could cancel this task when a sync/deck action occurs.

We could also ignore this ef it occurs extremely rarely.

Still better to not crash, a PR that adds log messages at info-level or higher when this happens and with context information that tells you which of your hypotheses are correct could be a fine PR, no risk to merge and could help figure it out on next report after a release with added logging

[Arthur-Milchior]

I posted https://github.com/ankidroid/Anki-Android/pull/6390 which would crash with more useful informations.
However, I don't really understand what you really ask me. Indeed, if there is no crash, we get no bug report, so we can't investigate.
If there is a bug report, then I need to crash so that Acra has it, or is there something else I can do ?

Anyway, I don't even see what useful informations I could get. If I'm right and that some actions occurred and changed the list of deck WHILE this function was executed, there is little I can do to get those exact informations, or am I missing something ?

[Arthur-Milchior]

I've just seen that this was occuring during a sync. I fear I must change my hypothesis.
Either the user uses intent to send to ankidroid action to do using our api (I think we have something like that, but I've never taken a look at it). This would be a really bad idea during a sync however

Or the deck name is not normalized while the parent deck name is normalized (or reciprocally). However, I don't expect it to be the real trouble, because if it was, because in that case, it would not be just a random error, but a collection which never loads, and in this case we may have gotten a bug report or something like that. And anyway, the error would occur infinitely often and not just during a sync.

[mikehardy]

AnkiDroidApp.sendExceptionReport can log something to ACRA without crashing, it can be useful in cases like this - either way I see the PR posted already

It's definitely possible for sync to be configured to run at startup, while AnkiDroid is trying to build reminders

[Arthur-Milchior]

Well, the PR does the minimal work to give us information. It's certainly not a definitive debugging tool.

[david-allison-1]

Had a user on the mailing list with this issue. Have requested the collection.anki2: https://groups.google.com/forum/#!topic/anki-android/Pl1QpDRif-M

[david-allison-1]

Finally got a reproduction. Thanks to @mat4r

This specific case was caused by a newline in the deck string. I've used an explicit \n in the following strings to denote this.

This is fixed in Decks::checkIntegrity for the parent deck, but not for the child decks.

Deck Name
Sketchy::Pharm::8 Antineoplastics::3 Kinase Inhibitors & Monoclonal Antibodies\n::3.1 - Imatinib, erlotinib, sorafenib, sunitinib, vemurafenib

Deck.parent (p)
Sketchy::Pharm::8 Antineoplastics::3 Kinase Inhibitors & Monoclonal Antibodies\n

Actual name in lims (after fix from checkIntegrity)
Sketchy::Pharm::8 Antineoplastics::3 Kinase Inhibitors & Monoclonal Antibodies

Searching lims for p returns null, which crashes.

https://github.com/ankidroid/Anki-Android/blob/755ac02e79987c042a1b053ffe6ce0d1caba1e0d/AnkiDroid/src/main/java/com/ichi2/libanki/sched/Sched.java#L215-L247

[Arthur-Milchior]

Fun fact, did you know in Java, ".trim" remove only the ' ' character https://docs.oracle.com/javase/7/docs/api/java/lang/String.html#trim() https://github.com/ankidroid/Anki-Android/blob/master/AnkiDroid/src/main/java/com/ichi2/libanki/Decks.java#L851
while in rust, it removes all "Unicode Derived Core Property White_Space."
https://doc.rust-lang.org/std/string/struct.String.html
https://github.com/ankitects/anki/blob/master/rslib/src/decks/mod.rs#L128

What I currently don't understand is where we are removing the new line symbol ?

[david-allison-1]

trim() removes newlines. (Technically, anything less than or equal to a space (32) in ASCII)

http://www.asciitable.com/

[Arthur-Milchior]

My bad, I did misread my google search.

It does not remove all unicode whitespace, so it is probably not equivalent to rust method, but that still a pretty good approximation

[david-allison-1]

https://couchdb.ankidroid.org/acralyzer/_design/acralyzer/index.html#/report-details/bf0a44ed-32ed-4cb3-8d4b-9188ab99dff4

[HomamShami]

Hi, this deck is giving me "Attempt to get length of full array" error on Ankidroid, note that Ankidroid Imports the deck name only without any cards in it and throws me this exception, I use Anki 2.1.24 on windows to export it with V2 scheduler enabled and scheduling data enabled , the issue disappeare if I disable one of these two things..

Link to deck :

https://drive.google.com/file/d/1xwwcF8qr8WPLpfHRblQtXZJBJMlrkEVq/view?usp=drivesdk

[david-allison-1]

Thanks! @HomamShami, I've requested access

[HomamShami]

Hi, I gave you access, let me know if it's working..
Meant to make it public in the first place 😅

[david-allison-1]

Hi @HomamShami, it turns out that this is an unrelated issue. Let's move the discussion to https://github.com/ankidroid/Anki-Android/issues/6764

[mikehardy]

We have diagnostic code entered for this one, there's no more action to take I don't think? Marking it for a future milestone and tagging as blocked awaiting new reports

[dodong29]

Have been getting the attached error message when attempting to sync on AnkiDroid. Was directed here by @david-allison-1

[david-allison-1]

Hi @dodong29, thanks!

Could you attach your collection.anki2 files from Anki Desktop and AnkiDroid to further help diagnose this issue.

On AnkiDroid, this is found in the AnkiDroid folder on your phone.

For Anki Desktop this is found: https://docs.ankiweb.net/#/files?id=file-locations

---

If your Anki data is not sensitive, please zip them and upload them here.

If the files contain private information, please send them to gmail: davidallisongithub

Thanks again

[dodong29]

@david-allison-1 here are the files
collection.anki2 phone.zip
collection.zip

[david-allison-1]

The issue has been resolved for the user, but we need to fix the bug

---

@Arthur-Milchior

Deck 1 is named: DANNY SULLIVAN MCM DECK
Deck 2 is named: Danny Sullivan MCM Deck::*MCM_UNTAGGED_CARDS

This crashes when the collection.anki2 is copied to AnkiDroid

[Arthur-Milchior]

So, if I understand correctly, @david-allison-1, you were able to reproduce the bug directly. I assume you were using master or a recent alpha, right ? And it lead to exactly the same error message ?
Should be simple to correct, but honestly, I'm surprised the bug exists at all, I was pretty sure that everything was normalized when processing decks.

[david-allison-1]

@Arthur-Milchior 2.13alpha25 (with a few additional unrelated commits).

The deck normalization process runs, but the decks still have the names above when they're processed by SchedV1's deck due counts.

Does the deck normalization process run during sync? The error message that was posted was different, so that may also want to be investigated.

[Arthur-Milchior]

Last time I checked upstream, normalization is used to have a canonical name when looking for parent, however the content of deck["name"] is not normalized, so that we still display the upper/lower caps the way the user want them. Since we are not checking for parents during sync, no need to normalize caps. (Appart when doing the sanity check, and that's the standard scheduler algorithm which runs there)
That is, the name map contains normalized name. When looking for the parents of "Danny Sullivan MCM Deck::*MCM_UNTAGGED_CARDS" it is normalizing this string and looking for the normalized parent in the name map. So the fact that deck["name"] is not normalized should not be a problem.
The fact that "Danny Sullivan MCM Deck" (normalized) is not in name map should be the problem I believe. It'll be easier to check when I can run this test on an emulator

[david-allison-1]

(Appart when doing the sanity check, and that's the standard scheduler algorithm which runs there)

Totally understood, that was my worry and I didn't recall.

[Arthur-Milchior]

I got no error on master when I opened the "phone.zip" version.
When I tried to opened the other file, I got an error which is worrysome but seems unrelated

W/Collection: Unable to get window size from requery cursor.
    java.lang.NoSuchFieldException: No field sCursorWindowSize in class Lio/requery/android/database/CursorWindow; (declaration of 'io.requery.android.database.CursorWindow' appears in /data/app/com.ichi2.anki-Iwraig6P2ye9T686I-zoUA==/base.apk)
        at java.lang.Class.getDeclaredField(Native Method)
        at com.ichi2.libanki.Collection.getChunk(Collection.java:313)
        at com.ichi2.libanki.Collection.loadColumn(Collection.java:332)
        at com.ichi2.libanki.Collection.load(Collection.java:289)
        at com.ichi2.libanki.Collection.<init>(Collection.java:187)
        at com.ichi2.libanki.Storage.Collection(Storage.java:68)
        at com.ichi2.anki.CollectionHelper.getCol(CollectionHelper.java:122)
        at com.ichi2.anki.CollectionHelper.getCol(CollectionHelper.java:106)
        at com.ichi2.anki.services.BootService.getColSafe(BootService.java:87)
        at com.ichi2.anki.services.BootService.onReceive(BootService.java:50)
        at com.ichi2.anki.AnkiDroidApp.onCreate(AnkiDroidApp.java:274)
        at android.app.Instrumentation.callApplicationOnCreate(Instrumentation.java:1119)
        at android.app.ActivityThread.handleBindApplication(ActivityThread.java:5740)
        at android.app.ActivityThread.-wrap1(Unknown Source:0)
        at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1656)
        at android.os.Handler.dispatchMessage(Handler.java:106)
        at android.os.Looper.loop(Looper.java:164)
        at android.app.ActivityThread.main(ActivityThread.java:6494)
        at java.lang.reflect.Method.invoke(Native Method)
        at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:438)
        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:807)

[mikehardy]

That is most unexpected, so we have it at "warn" level but it is recoverable, we just use the default size then:

        if ("io.requery.android.database.sqlite.SQLiteDatabase".equals(db_name)) {
            try {
                Field cursorWindowSize = io.requery.android.database.CursorWindow.class.getDeclaredField("sCursorWindowSize");
                cursorWindowSize.setAccessible(true);
                sCursorWindowSize = cursorWindowSize.getInt(null);
            } catch (Exception e) {
                Timber.w(e, "Unable to get window size from requery cursor.");
            }
        }

[Arthur-Milchior]

I created a new issue related to this problem, https://github.com/ankidroid/Anki-Android/issues/7031 , because it seems not really related to what we were looking at right now. Would you accept to copy your comment there @mikehardy ?

@david-allison-1 you wrote you were able to reproduce the problem. Can you please let me know which files (I assume you meant "collection.anki2" but I'm not sure), and which version of ankidroid you used ?

[david-allison-1]

@david-allison-1 you wrote you were able to reproduce the problem. Can you please let me know which files (I assume you meant "collection.anki2" but I'm not sure), and which version of ankidroid you used ?

@Arthur-Milchior 2.13alpha25 (with a few additional unrelated commits).

Copy/pasting collection.anki2 into a new profile - first one that I tried, so presumably number 1.

[david-allison-1]

Moving this to 2.13 as it's a sync blocker

[Arthur-Milchior]

The first file is "collection.anki2 phone.zip" and I had no problem opening it, so I'm really surprised. I should note furthermore that I did not see any deck called "DANNY SULLIVAN MCM DECK" in it, so I assume you actually tried to open "collection.anki2", and that I did not get the correct error message because of the requery error.

What I did is: I took the file and put it in Ankidroid folder of the emulator. I then opened ankidroid. Is it what you called "copy/pasting into a new profile" ?

I'll try to open the second file on my phone and see whether I can avoid the database problem to see the actual problem

[Arthur-Milchior]

I was able to reproduce, I'll look at it now

[Arthur-Milchior]

Reproduced it on 2.10.3

    java.lang.NullPointerException: Attempt to read from null array
        at com.ichi2.libanki.sched.Sched.deckDueList(Sched.java:229)
        at com.ichi2.libanki.sched.SchedV2.deckDueTree(SchedV2.java:414)
        at com.ichi2.async.CollectionTask.doInBackgroundLoadDeckCounts(CollectionTask.java:536)
        at com.ichi2.async.CollectionTask.doInBackground(CollectionTask.java:247)
        at com.ichi2.async.CollectionTask.doInBackground(CollectionTask.java:73)
        at android.os.AsyncTask$2.call(AsyncTask.java:333)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)

[Arthur-Milchior]

Reproduced on 2.9.7

E/DeckTask: doInBackgroundLoadDeckCounts - error
    java.lang.NullPointerException: Attempt to read from null array
        at com.ichi2.libanki.Sched.deckDueList(Sched.java:411)
        at com.ichi2.libanki.Sched.deckDueTree(Sched.java:427)
        at com.ichi2.async.DeckTask.doInBackgroundLoadDeckCounts(DeckTask.java:532)
        at com.ichi2.async.DeckTask.doInBackground(DeckTask.java:242)
        at com.ichi2.async.DeckTask.doInBackground(DeckTask.java:70)
        at android.os.AsyncTask$2.call(AsyncTask.java:333)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:245)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1162)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:636)
        at java.lang.Thread.run(Thread.java:764)

This seems to mean it's not a regression in ankidroid actually.

@dodong29 would you please accept to tell us which version of anki you use, and which add-ons, if any ? I suspect that it may have been a regression in anki (I can't easily reproduce this bug with latest version however, so it may already be fixed.)

I still need to fix it, but I kind of like to know that it was not something I introduced.