SQL errors while trying to move / delete messages

[kdltr]

• Operating System: Debian 12 / Android 14
• Delta Chat Version: Desktop 1.50.1 (core 1.152.1) / Android 1.50.2

I noticed Delta Chat was a bit sluggish since the 1.50 update, taking a while to show me new messages, also displaying “updating” constantly on both desktop and mobile.

I started to dig a little bit and noticed that messages were not being deleted on the server (despite having set a deletion timer), the DeltaChat IMAP folder containing around 100000 messages now.

I also noticed that disappearing messages in some groups were in fact not disappearing at all, everything was kept. An example of such is a group where deleted messages were setup on the 7th of september, but everything since then is still there and readable.

Opening the log reveals quite a lot of error messages related to deleting messages, very similar errors on both Android and Desktop clients.

(I had to elide the huge row of question marks in the queries because there were too many to post the issue on github)

On desktop:

2024-12-22T10:13:55.557Z	core/event            	WARNING	""	1	"src/scheduler.rs:728: Failed fetch_idle: fetch_move_delete: move_delete_messages: cannot delete batch of messages \"8220:8221,8227:8228,8230:8231,8291:8293,8298:8299,8301:8303,8311:8344,8351:8395,8402:8823,8825:8960,8965:9010,9013:9096,9110:9113,9124:9145,9166:9203,9210:9211,9213:9214,9217:9677,9680:9681,9684:9690,9693:9694,9697:9714,9717:9912,9917:10473,10477:10601,10608:10611,10614:10615,10617:10830,10847:11106,11109:11413,11416:11510,11513:11615,11620:12137,12140:13372,13375:13422,13425:13885,13890:15763,15765:16203,16206:17670,17672:18406,18408:18843,18846:19245,19247:20282,20285:20387,20389:20409,20411:20549,20551:20796,20799:21185,21189:24521,24526:24954,24959:25005,25010:25226,25231:27870,27873:28846,28851:29120,29122:29603,29605:30377,30379:31531,31535:31536,31540:32123,32126:33966,33971:33973,33975,33977:34731,34734:35007,35012:35325,35330:35627,35629:35632,35637:35640,35643:35913,35917:36715,36718:40765,40770:40810,40814:41725,41730:41846,41851:41856,41861:42182,42185:42255,42260:42519,42522:42721,42725:45432,45435:47152,47157:47234,47237:47780,47784:48510,48512:48533,48535,48537:50852,50856:50879\": cannot remove deleted messages from imap table: too many SQL variables in DELETE FROM imap WHERE id IN (?,?,?,……………?,?,?,?,?,?,?,?,?,?,?,?) at offset 65562: Error code 1: SQL error or missing database"
2024-12-22T10:13:55.557Z	core/event            	WARNING	""	1	"src/imap.rs:309: IMAP got rate limited, waiting for 0h 0m 58s until can connect."

On Android:

12-22 11:18:39.238 5413 5449 🟠 DeltaChat: [accId=1] src/scheduler.rs:728: Failed fetch_idle: fetch_move_delete: move_delete_messages: cannot delete batch of messages "8220:8221,8227:8228,8230:8231,8291:8293,8298:8299,8301:8303,8311:8344,8351:8395,8402:8823,8825:8960,8965:9010,9013:9096,9110:9113,9124:9145,9166:9205,9208:9211,9213:9214,9217:9677,9680:9681,9684:9690,9693:9694,9697:9714,9717:9912,9917:10473,10477:10603,10606:10611,10614:10615,10617:10830,10847:11413,11416:11510,11513:11615,11620:12137,12140:13372,13375:13422,13425:13885,13890:15763,15765:16203,16206:17670,17672:18406,18408:18843,18846:19245,19247:20282,20285:20387,20389:20409,20411:20549,20551:20796,20799:21185,21189:24521,24526:24954,24959:25005,25010:25226,25231:27870,27873:28846,28851:29120,29122:29603,29605:30377,30379:31531,31535:31536,31540:32123,32126:33966,33969:33970,33972,33974,33976,33978:34731,34734:35007,35012:35325,35330:35627,35629:35632,35637:35640,35643:35913,35917:36715,36718:40765,40770:40810,40814:41725,41730:41846,41851:41856,41861:42182,42185:42255,42260:42519,42522:42721,42725:45432,45435:47152,47157:47234,47237:47780,47784:48510,48512:48533,48535,48537:50852,50856:50879": cannot remove deleted messages from imap table: too many SQL variables in DELETE FROM imap WHERE id IN (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,?,
12-22 11:18:39.238 5413 5449 🟠 DeltaChat: [accId=1] src/imap.rs:309: IMAP got rate limited, waiting for 0h 0m 59s until can connect.

Seems like something is generating enormous SQLite queries…
I haven’t looked at the code, but maybe creating a temp table with all the IDs and using an IN statement in the WHERE clause would make more sense. Generating SQL queries seems like a big footgun.

[Hocuri]

The code is here, and does, as you guessed, try to delete all the SQL entries with a query like DELETE FROM imap WHERE id IN (?, ?, ?, ?, ..., ?).

If performance didn't matter, we could just delete the entries in a loop. Somehow we need to get the data into SQL, and I don't see how a temporary table helps here, because for this we would still need to somehow insert all the IDs into the table via params.

Fixing this problem

This problem should be fixable by deleting only up to 900 rows at once in the SQL statement, and doing this in a loop until all rows are deleted.

This should maybe not only be done for this specific SQL statement, but for all the 14 usages of repeat_vars(), because they may have a similar problem - maybe we can extract this logic into a new function. OTOH, some of these 14 usages don't look very likely to cause problems, e.g. lookup_chat_or_create_adhoc_group() looks like it will fail when a classical MUA message with more than 999 recipients is received. Then again, might be nicer to fix the whole problem at once than to get bitten by it later.

Not sure if that's the best fix, maybe someone comes up with a better one.

Reproducing this problem

This problem looks to be reproducable by receiving over 999 messages in one go (this is SQL's maximum) and then setting "Delete Messages from Server" to "At once"; sounds easy enough to write a python test for that, but of course we can't merge it because it will take ages to complete. This way, we could find out whether this is a new problem in 1.50 or if it was just coincidence that it appeared now.

[link2xt]

If performance didn't matter, we could just delete the entries in a loop.

I think we should get rid of repeat_vars() and instead of using it open a transaction, delete all the elements one-by-one in a loop and close the transaction.

[iequidoo]

It seems that a transaction isn't really necessary here, call_write() + preparing a statement and then executing it in a loop is sufficient. But i haven't dived into the code yet.

[link2xt]

Single transaction should make it faster because every time transaction is closed there is an fsync call waiting for the changes to be written to the disk.

[link2xt]

Fix is in #6358.

[link2xt]

And a follow-up issue to cleanup remaining statements: #6359