search

deltachat / deltachat-core-rust

Delta Chat Rust Core library, used by Android/iOS/desktop apps, bindings and bots 📧
https://delta.chat/en/contribute
Other
659 stars 85 forks source link

Duplicate messages in msgs table with precise same message-id/server_uid and folder #1701

Closed hpk42 closed 4 years ago

hpk42 commented 4 years ago

Core from 1-2 days ago produces duplicate msgs entries. In another chat i got 4 duplicate messages -- these were messages i sent myself from my mobile, and the 4 duplicates are in desktop. But i don't think multi-device is the issue here. The screenshot of the duplicate DB entry below is from a message from someone in dev chat.

duplicate

link2xt commented 4 years ago

If your core does not contain #1694, it is probably already fixed.

hpk42 commented 4 years ago

It's not obvious to me why #1694 would fix this but i can imagine it helps ;) The "msgs" table has no uniqueness constraint on Message-ID or the server_folder/server_uid/uid_validity triple.

link2xt commented 4 years ago

We need to add a constraint on rfc724_mid.

link2xt commented 4 years ago

As for #1694, probably it does not fix indeed, looks like another async issue, multiple coroutines downloading the same message and writing it in parallel.

link2xt commented 4 years ago

It is hard to do using the procedure described in https://www.sqlite.org/lang_altertable.html What to do if during this migration we run out of space? It requires duplicating the table, basically.

hpk42 commented 4 years ago

It appears imap-activity (on inbox, my desktop is not watching DeltaChat folder) is running TWICE:

2020-07-12T15:29:12.024Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/idle.rs:79: Idle has NewData"
2020-07-12T15:29:12.025Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/idle.rs:79: Idle has NewData"
2020-07-12T15:29:12.135Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/job.rs:1049: loading job for Imap-thread"
2020-07-12T15:29:12.198Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/job.rs:1049: loading job for Imap-thread"
2020-07-12T15:29:13.245Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:47: Receiving message INBOX/132096, seen=false..."
2020-07-12T15:29:13.250Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/e2ee.rs:231: Detected Autocrypt-mime message"
2020-07-12T15:29:13.254Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:47: Receiving message INBOX/132096, seen=false..."
2020-07-12T15:29:13.255Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/e2ee.rs:231: Detected Autocrypt-mime message"
2020-07-12T15:29:13.294Z    core/event              DEBUG       "DC_EVENT_NEW_BLOB_FILE"    0   "$BLOBDIR/image-481686425.jpg"
2020-07-12T15:29:13.296Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/mimeparser.rs:732: added blobfile: \"$BLOBDIR/image-481686425.jpg\""
2020-07-12T15:29:13.304Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:817: Message has 1 parts and is assigned to chat #Chat#1040."
2020-07-12T15:29:13.308Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:248: received message 132096 has Message-Id: Gr.pVYi0x9KzZi.hAP80xCTlpU@reutlingen-university.de"
2020-07-12T15:29:13.310Z    core/event              DEBUG       "DC_EVENT_INCOMING_MSG" 1040    85301
2020-07-12T15:29:13.317Z    core/event              DEBUG       "DC_EVENT_NEW_BLOB_FILE"    0   "$BLOBDIR/image-1188345201.jpg"
2020-07-12T15:29:13.318Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/mod.rs:649: 1 mails read from \"INBOX\"."
2020-07-12T15:29:13.426Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/mimeparser.rs:732: added blobfile: \"$BLOBDIR/image-1188345201.jpg\""
2020-07-12T15:29:13.427Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:817: Message has 1 parts and is assigned to chat #Chat#1040."
2020-07-12T15:29:13.624Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/dc_receive_imf.rs:248: received message 132096 has Message-Id: Gr.pVYi0x9KzZi.hAP80xCTlpU@reutlingen-university.de"
2020-07-12T15:29:13.969Z    core/event              DEBUG       "DC_EVENT_INCOMING_MSG" 1040    85302
2020-07-12T15:29:13.975Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/mod.rs:699: fetch_new_messages: ignoring uid 132096, last seen was 132096"
2020-07-12T15:29:13.980Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/mod.rs:649: 1 mails read from \"INBOX\"."
2020-07-12T15:29:13.980Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/mod.rs:649: 0 mails read from \"INBOX\"."
2020-07-12T15:29:14.437Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/mod.rs:699: fetch_new_messages: ignoring uid 132096, last seen was 132096"
2020-07-12T15:29:14.438Z    core/event              INFO        "DC_EVENT_INFO" 0   "src/imap/idle.rs:67: Idle entering wait-on-remote state"
hpk42 commented 4 years ago

as noted by @linkxt on irc it's possible that two desktop processes are running -- or that during account switching the old processes didn't die with stop_io or so. I'll see to monitor this with "ss -t -p".

Note that my desktop/android multi-device setup does not watch DeltaChat and does not move messages. It's a core/node/desktop master from yesterday.

hpk42 commented 4 years ago

it's a desktop issue likely see https://github.com/deltachat/deltachat-desktop/issues/1794