New messages are not received

[gerryfrancis]

• Operating System (Linux/Mac/Windows/iOS/Android): Android 10 on Fairphone FP2 (Lineage OS 17.1 build QQ3A.200805.001 from 2021-04-30).

• Delta Chat Version: 1.19.2 (nightly build from 2021-05-04).

• Expected behavior: New messages are received.

• Actual behavior: New messages are not received.

• Steps to reproduce the problem: -- Close Delta Chat and start it again. -- Wait for a message to be received. (LOL...)

• Screenshots: N/A.

• Logs: deltachat-log-20210505-103943.txt

Note: Connection parameters never changed, and the address of hostname posteo.de can be resolved, because a MUA running on the same client has absolutely no issue. (See below.)

• Remark(s): When I start a MUA (e.g. FairEmail) on the same OS (Android), I can access my account and see that new messages have been received.

[gerryfrancis]

I restarted the device and tried again. This time, a connection to posteo.de was possible, but no new message come in either. New log file here: deltachat-log-20210505-111551.txt

[gerryfrancis]

It is this line that documents the last action taken before TILT: 05-05 11:13:40.141 6389 6434 I DeltaChat: src/dc_receive_imf.rs:69: Receiving message INBOX/16426, seen=true...

It was a mail sent to be claimed of crashing a bot. I used that mail and sent it to myself with a MUA. Meanwhile, I deleted it from my mail account in both folders, INBOX and Sent. I even restored a backup from yesterday, but the issue remains...

[gerryfrancis]

Just sent a mail from another account to the one at Posteo (Delta Chat) and checked with my Webmail: The mail was delivered successfully, but Delta Chat does not react to it, no further entries in the log file.

Something seems to be no longer in sync, I do not understand why, even a recent database backup has been restored that does not contain the "message bomb"!

[gerryfrancis]

I have a copy of the "message bomb" here in EML format. Members of the "Testing Delta Chat" group should have received it from another member than me appproximately 13 hours ago...

[Hocuri]

05-05 11:13:40.141 6389 6434 I DeltaChat: src/dc_receive_imf.rs:69: Receiving message INBOX/16426, seen=true...

That's weird (ok, which bug is not weird:joy:). DC starts receiving the message, but then something happens. It just vanishes, I'm really reminded to detective stories.

What happens when you login from a new device (or a new installation of DC, you could e.g. download the latest release from F-Droid) without importing a backup, just login with username and pw?

Also, could you just restart DC again, open it, have a message sent to you, and send another log? The log is so empty, with luck we get a better log this time, it's worth a try.

[gerryfrancis]

@Hocuri Thanks for your support, greatly appreciated! :+1:

I made a backup the day before the issue occured. (I do this every time before installing a new nightly build.) When I reset the app (by deleting memory and cache content), I started over again, restored the backup successfully, and all missing messages which I read before were received, too ... until that one message that is referred to in the log file... From this moment on, no new messages arrive in Delta Chat. However, I can see around 100 new messages e.g. in Posteo Webmail...

To me it seems that the UID state in my Posteo account is somehow different, but OTOH why do the MUAs work fine?

That's weird (ok, which bug is not weirdjoy).

@Hocuri You name it! ;)

Will try to start over again, without the backup...

[gerryfrancis]

@Hocuri I started over again with the nightly build mentioned above by creating a brand new profile, but the situation remains: no new messages... :( (I sent a message from another account to me, set chats to ALL...)

[Hocuri]

Can you send another log? That's the best idea I currently have

[gerryfrancis]

@Hocuri Sure, but I do not think we would see anything new either. Instead, could we find out (with a little more detailed logging) if the IMAP server (posteo.de) maybe interrupts transmission after Delta Chat initiated the receiving at that point? I suspect Posteo of sending anything suspicious that Delta Chat does not understand, but the MUAs do...

Will send another log with that nightly build, of course, just a moment...

[gerryfrancis]

Here is the log I saved after I newly created the Delta Chat account: deltachat-log-20210506-134539_2.txt

[gerryfrancis]

WTF...?! I did not look at my device for ~15 minutes, and now the missing messages are received? That is insane!!

[gerryfrancis]

Current log file here: deltachat-log-20210506-222537_2.txt

[Hocuri]

It's getting weirder...

The next step would be to try if the bug happens again if you receive it again, and then I send you a modified APK with more logs. Not 100% sure if that's worth the trouble though.

[gerryfrancis]

@Hocuri It is worth the trouble, because I just restored the backup, and the hang at INBOX/16426 is here again. It seems that if I let Delta Chat run for ~15 minutes it might continue, but this definitely is not normal...

[gerryfrancis]

OK, I restored the backup >1 hour ago, and the hang is still there, nothing relevant logged so far...

[gerryfrancis]

@Hocuri I would like to refer to your offer to test an APK with verbose logging, because my Delta Chat client still does not receive new messages. You could send the link to my common private mail address, if you like. Many thanks in advance for your help! :)

[link2xt]

@gerryfrancis Do you run *nix? Do you have an option to run repl tool with RUST_LOG=repl=info,async_imap=trace,async_smtp=trace? I suspect the problem is somewhere in IMAP protocol parser and IMAP tracing would have showed it.

[gerryfrancis]

@link2xt Unfortunately I have no build environment, I only can run compiled APK's currently. What other than knowledge/skills do I need for this? Maybe I can connect to the IMAP server with a terminal client and do what Delta Chat tries to do, but manually?

[Hocuri]

@gerryfrancis using DC in the terminal is explained here: https://github.com/deltachat/deltachat-core-rust/blob/master/README.md. Never tried this on Windows, but you will probably need some kind of *nix, i.e. WSL, Linux, MacOS.

These commands should do to run DC:

git clone https://github.com/deltachat/deltachat-core-rust.git
curl https://sh.rustup.rs -sSf | sh
cd deltachat-core-rust
RUST_LOG=repl=info,async_imap=trace,async_smtp=trace cargo run --example repl --features repl -- ~/deltachat-db

Usage is explained at https://github.com/deltachat/deltachat-core-rust#using-the-cli-client. Ask if sth doesn't work :)

[gerryfrancis]

@Hocuri Thanks a lot for your instructions, but I am using Windows 8.1 Pro here, which lacks WSL, so I tried Git Bash instead. When I run the last line, I get error: build failed , because I have no Visual Studio installed:

This is a corporate notebook on which I cannot Visual Studio due to various reasons, and I have not been able to use Delta Chat for almost three days now. Could we find a different approach to troubleshoot this issue, please? Thanks in advance!

[link2xt]

Visual studio is not needed, you only need build tools. You can't install them too?

[link2xt]

We can probably make a github action to build repl tool and output binary .exe as an artifact: #2426

[gerryfrancis]

@Hocuri @link2xt I am afraid that will not work on my system, which is Windows 8.1 Pro, because it is not compatible with the Windows 10 SDK:

[Jikstra]

I can build a custom deltachat-desktop exe if that helps? Looks like a suuuper nasty bug..

[link2xt]

@Jikstra a repl tool is needed to run repl.exe example with RUST_LOG=async_imap=trace.

[gerryfrancis]

I welcome anything that directs into verbose logging when the app tries to grab INBOX/16426, but allocating > 6 GB only to install the build tools and analyze the issue is an overkill. The Internet connection I have at home currently offer 20 Mbit/sec, which is ~2.5 MB/sec at its best. Please do not let me go down that road! ;)

[link2xt]

@gerryfrancis I built a binary with github actions at PR #2426, you can download it at https://github.com/deltachat/deltachat-core-rust/pull/2426/checks?check_run_id=2535048296 (check "Artifacts" near "Re-run jobs").

Run it from the command line as RUST_LOG=async_imap=trace repl.exe <path-to-your-database>

Edit: fresh build can be downloaded from https://github.com/deltachat/deltachat-core-rust/actions/runs/823389733

[gerryfrancis]

@link2xt Thanks, downloaded, no dice:

[link2xt]

You are not running from the correct directory (where repl.exe is downloaded).

You don't need bash by the way, run from cmd.exe or powershell.

In the command line, run set RUST_LOG=repl=info,async_imap=trace, then run repl.exe deltachat-db. Then in the delta chat REPL run import-backup to import a backup exported from your primary deltachat setup. Then use connect command to connect and see where it stops. You can run maybenetwork to ping IMAP thread so it tries again.

In powershell the difference is that to set environment variable, you need to run

$env:RUST_LOG = 'repl=info,async_imap=trace'

[gerryfrancis]

run from cmd.exe or powershell

In PowerShell, I had to enter .\repl.exe deltachat-db , and this is what I got:

[link2xt]

Nice. Now make sure you set RUST_LOG variable before running repl.exe, then import backup (throw the .tar into the same directory as repl.exe and import with import-backup your-backup-filename.tar) and run connect.

[gerryfrancis]

Forgot to write that I set RUST_LOG variable before running repl.exe .

The .tar backup file on my Android device has a size of 515 MB, it will take a while to transfer it to my notebook, please hold on...

[gerryfrancis]

Thanks for waiting, and here we are:

[link2xt]

Oh no, it's #2424 duplicate.

[gerryfrancis]

@link2xt I thought that already... ;) Now, how do I get rid of this message? (It should be deleted already, but ...)

[link2xt]

You can open web interface or thunderbird and try to find the message in your account and delete it. It's some recent message with HTML part in the INBOX folder. I have no idea how to find exactly UID 16426 in Thunderbird though :(

[link2xt]

Alternatively you can wait a day or two until #2424 is fixed.

[link2xt]

Closing this one as duplicate.

[gerryfrancis]

@link2xt I deleted the suspected message already, it is no longer available in Webmail, but Delta Chat still tries to get it... :(

[link2xt]

@gerryfrancis The problem is that Delta Chat actually gets it and tries to parse HTML attachment there. The message is still returned by the server. Maybe you need to clear the Trash or otherwise execute EXPUNGE command. In Thunderbird you can do this by clicking "Compress" in the context menu of Inbox folder.

[gerryfrancis]

@link2xt Thanks for your explanation. I think I better leave it like it is now, because I would like to test the fix as soon as it is released...

[Hocuri]

Oh, ok, but it's really annoying that the panic was not shown in the log.

I mean, panic messages on Android never actually tell you much about the cause, but in this case here, we didn't even know a panic had happened.

Maybe we can find a way to solve this via some custom panic handler or by configuring how the lib is loaded in Android, although I couldn't come up with a good solution yet.

But nice thing the "detective story" is solved :) thanks @link2xt :heart:!

[gerryfrancis]

I want to thank the whole team for always being patient with me in such matters! :heart: Although I am living in the Microsoft world, I am always open to Linux stuff to know a thing or two about it. ;)

[link2xt]

@gerryfrancis Latest nightly includes the fix