Open Bug 1821755 Opened 2 years ago Updated 24 days ago

IMAP mail content truncated if mail is viewed while Thunderbird sync is occurring with mail.server.default.fetch_by_chunks set to true

Categories

(MailNews Core :: Networking: IMAP, defect)

Thunderbird 102
defect

Tracking

(Not tracked)

UNCONFIRMED

People

(Reporter: jamesmknott, Unassigned)

References

(Depends on 1 open bug)

Details

User Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/111.0.0.0 Safari/537.36

Steps to reproduce:

IMAP mail first downloads new mail headers (only), and then soon after will sync download new mail body content.
If new mail is viewed after new mail header download but before all new message content is sync downloaded, then (long) files (or those with attachments) are truncated -- i.e., the message is cut short. This can also be seen in the *.log.moz_log trace as it simply ends early (compared to a completely downloaded message).

Has been observed on multiple Windows PCs. Has been observed with sync download to INBOX and to DRAFT, and I assume will occur to any sync'ed IMAP folder. Currently on Thunderbird version 102.8.0 (64 bit). Have seen this for at least a month, but only recently have figured out exactly what was causing truncated INBOX messages.

Easily and consistently reproduceable - here is the easiest way to recreate:

  1. Start Thunderbird, and look at DRAFTS folder.
  2. Using webmail and ATT.NET (yahoo) web browser, start to forward a not small (say, 3MB with attachments) message (but do not click SEND). Still using webmail interface, switch to another webmail folder which will then cause ATT.NET to save it as a DRAFT (there is no other way to tell the ATT.NET webmail interface to "save as draft").
  3. Continue to watch Thunderbird DRAFTS folder, and the MOMENT that it shows up on Thunderbird (this would be headers only), click on that email to view.

Actual results:

  1. [bad] Not all of the DRAFT message body will be synced - the bottom will be cut short.. Nothing you can do from now-on will then cause it to completely sync either.

Note: I run on "AT&T Internet 25" which is 25Mbps down and 5Mbps up. With a faster internet, the time between downloading headers and sync downloading message body might be smaller, and thus the probablility of having this truncation might be less.

Expected results:

  1. [good] The entire DRAFT message body SHOULD be synced -- if not immediately, then on the next SYNC (manual or timed automatic) SYNC operation (but this message is never completely SYNCed).
Component: Untriaged → Networking: IMAP
Product: Thunderbird → MailNews Core

Reporter jamesmknott,
I'll try to duplicate what you see. But I'm curious if you see this also on non-yahoo based imap accounts?

I have not tried this on my non-yahoo gmail account, but I will try to duplicate that there as well (as I know that yahoo based mail can be problematic and non-conforming protocols). I'll try to do that in the next day or two. (I do know FOR SURE that a friend (also using att.net) has seen the same problem.)

However I also have created Bug 1822218 which is not exactly the same - but not exactly different -- and related to IMAP message body syncing which I definitely can repeatedly duplicate on both att.net (yahoo) and gmail IMAP syncing. FYI.

I've only tested this on 112a (daily) and haven't seen the reported problem. I'm copying a 16M message with a .png attachment from a non-yahoo account to a yahoo account folder having offline store and, so far, works fine.
:
Also now tested on 102.7.1 and don't see the problem. I click on the message as soon as it appears in the yahoo imap folder and the full message appears along with the large .png attachment.
:
Ok, I tried your webmail method on yahoo but I could never save a draft. So I just copied the 16M size msg to another folder and watched it come in on tb. I think I see what you see. The inline .png attachment only shows partially in tb 102.7.1.
I'm not 100% sure but it looks like tb fetches the first chunk of data, about 10M, and then asks for more and yahoo says it has no more.
Do you see lines like this in your tb imap log at the end before it stops? This line look really bad: FetchTryChunking: Zero bytes chunk fetched; message probably expunged

 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:CreateNewLineFromSocket: Af8AAAAAAAMC/wD9+AgA+PcOAPDsGQD6+wgABgH/AAD+)
 SetConnectionStatus(0x0)
 ReadNextLine [rv=0x0 stream=7f9b2e1f6240 nb=27 needmore=0]
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:CreateNewLineFromSocket: 55 OK UID FETCH completed
 SetConnectionStatus(0x0)
 FetchMessage peek: curFetchSize 10993664 numBytes 10993664
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:SendData: 56 UID fetch 220009 (UID RFC822.SIZE BODY.PEEK[]<10993664.10993664>)
 ReadNextLine [rv=0x0 stream=7f9b2e1f6240 nb=65 needmore=0]
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:CreateNewLineFromSocket: * 5 FETCH (UID 220009 RFC822.SIZE 16712912 BODY[]<10993664> "")
 SetConnectionStatus(0x0)
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:STREAM:CLOSE: Normal Message End Download Stream
 STREAM:CLOSE Server's RFC822.SIZE 16712912, actual size 10993666
 D/IMAP Updating stored message size from 16712912, new size 10993666
 ReadNextLine [rv=0x0 stream=7f9b2e1f6240 nb=27 needmore=0]
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:CreateNewLineFromSocket: 56 OK UID FETCH completed
 SetConnectionStatus(0x0)
 FetchTryChunking: Zero bytes chunk fetched; message probably expunged
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:ImapThreadMainLoop: idlePending set
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:SendData: 57 IDLE
 ReadNextLine [rv=0x0 stream=7f9b2e1f6240 nb=10 needmore=0]
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:CreateNewLineFromSocket: + idling
 SetConnectionStatus(0x0)
 7f999e98d800:staging.imap.mail.yahoo.com:S-CC:HandleIdleResponses: idle mode async waiting
 ReadNextLine [rv=0x0 stream=7f99a22f72e0 nb=36 needmore=0]
 7f99a0210100:staging.imap.mail.yahoo.com:S-INBOX/sfuib/Draft:CreateNewLineFromSocket: * BYE IMAP4rev1 Server logging out
 SetConnectionStatus(0x0)
 ImapThreadMainLoop leaving [this=7f99a0210100]

I cut off the leading time/date and other extraneous stuff at the start of each line above.
Anyhow, what I'm seeing here looks like yahoo messing up. I'll look some more.
If your log looks considerably different than mine, attaching it (using attach file button above) so I can see it might help.

The message I've used consists of something like....
text
inline picture
text
inline picture
text
inline picture

I receive an email like that every day from a friend, and it often happens on his emails. But it's not just related to him (and he isn't att/yahoo). The total message size are typically about 1.5-3.5MB, so they aren't huge.

I will find an existing log or recreate with log later tonight. (hopefully with a "small" test with just showing the problem). I really don't know how to use/read the logs, but I "basically"
set mydate=%date:-4,4%%date:-7,2%%date:~-10,2%
set mytime=%time:0,2%%time:+3,2%
set NSPR_LOG_MODULES=IMAP:5
set NSPR_LOG_FILE=%USERPROFILE%\thunderbird_%mydate%_%mytime%.log
and then start Thunderbird, which creates
thunderbird_20230803_2104.log.moz_log (of varying size
thunderbird_20230803_2104.log.child-1 (always 0 bytes
thunderbird_20230803_2104.log.child-1.moz_log (always 0 bytes
Let me know if you want me to do something different.

The "NSPR" logging var were deprecated years ago, maybe they still work, not sure. But the "correct" ways is now this, adding timestamp and sync:
set MOZ_LOG=IMAP:5,timestamp,sync
set MOZ_LOG_FILE=%USERPROFILE%\thunderbird_%mydate%_%mytime%.log
Or if you don't care about encoding the time/date in the filename, just this is OK:
set MOZ_LOG_FILE=%USERPROFILE%\tblog

The 0 length "child" files produced are useless AFAIK so I don't need to see them. Just show me the tblog.moz_log file or whatever you name it.
For more info see https://wiki.mozilla.org/MailNews:Logging

Concerning your statement "I tried your webmail method on yahoo but I could never save a draft. " >> AFAIK, there is no DIRECT way to "Save as draft" on Yahoo webmail. But, if you start to forward in yahoo webmail , and then click on some unrelated folder, thus changing the "focus" of the webmail, yahoo will save it as a draft. FYI if that helps.

Concerning your statement "The inline .png attachment only shows partially in tb 102.7.1." >> yes, my failing messages had several .jpg, and when failing, a .jpg would be "cut in half" (or "a third"), and the following .jpg would be missing.

I looked for my prior error logs, but regrettably I think I deleted them, as they weren't as "simple" as I'd hoped, and since I could recreate the problem so easily, I was going to create "clean" examples. But as I remember, in a failing situation (where a .jpg would be "cut in half" and other jpgs deleted, the TB log just simply ended quite abruptly -- in the middle of a getnextline sequence (note I really don't know what I'm doing when I look at a TB trace) -- it almost looked like the log file was "cut in half".

When I created this bugzilla entry, I could VERY easily recreate this problem almost EVERY time. But now I cannot recreate the "truncated .jpg lost .jpg" problem any longer. Instead, I notice a new and different phenomena (which is a FAR better result, FYI)....

  1. From TB, I forward an att.net message (text, jpg, text. jpg, text, jpg) to myself.
  2. I watch the TB INBOX for the header to arrive. If it doesn't arrive before I get anxious, I click on the TB "Get Messages - xxx.att.net"
  3. The message now shows up in the TB Inbox. I immediately start clicking, alternating every ~1.5 seconds, the new message and a random older message.
    4a) in the past, that would cause one of the new message .jpgs to get cut "in half" and the remaining jpgs lost. (never recovered). Very easy for me to recreated. But no longer.
    4b) now, so long as I continue to alternate between new and older message, the new message never arrives. Watching the ethernet traffic, it continues and continues, as long as I alternate back and forth. This suggests that all my clicking screws up the message and TB (or yahoo protocols) keeps trying to reload the message FROM THE START (that's why the ethernet traffic never ends). When I finally stop alternating clicking on new and old message, it "appears to me" from the ethernet trace that the full message download IMAP sync then completes, and the full message is displayed. I believe this is what we would want to occur -- don't display the message until IMAP SYNC is complete, so I'm believing that either TB (doubtful, I don't think there have been any TB updates since the time when I could easily recreate the problem), or yahoo has changed/tixed something.

It is my believe, based on various internet comments and other experiences, that yahoo does indeed change things impacting IMAP syncing from time to time, so perhaps others complained to them and they fixed something (??).

So this problem may have resolved itself (not completely sure, but looks good now).

Regrettably, the problem I describe in Bug 1822218 appears to be FAR WORSE than a day or two ago -- to the point that it ALWAYS now "fails" and the .jpgs always seem to appear as "attachments" rather than inline (but only on TB, not on webmail). And these may??? be related, and perhaps yahoo made this better and the other worse???

Of course, in the process of trying to debug this, or create a workaround situation, I may have changed who-knows-what in TB that has "fixed" this. I don't think so, but full disclosure requires I mention this real possibility...

I don't know why but it appears that yahoo can't handle fetching of the message in multiple chunks all the time. So if I set this to false mail.server.default.fetch_by_chunks in advance settings I don't see this bug 1821755 nor bug 1822218 occur.
So try setting that to false and see if it fixes the issues. Go to general settings page and at the bottom go into "advanced setting".
FYI, fetching in smaller chunks, rather than fetching the whole message in one imap fetch command (as occurs with the above pref false) is supposed to allow faster movement between selected messages. So tb just waits for a small chunk to be fetched before stopping the transfer if another messages is selected before the original one is completely fetched (like I think you are describing above. In the code this is called a "pseudo-interrupt").
Also, FYI, tb tries to adjust the "chunk size" to the optimum size depending on estimated network throughput. With fast speed tb uses a larger chunk size.

In a prior post, I said "So this problem may have resolved itself (not completely sure, but looks good now)." Unfortunately (before trying chunks=faulse) it again failed this morning, with the jps separarated as attachments and not inline.

I then configured TB for mail.server.default.fetch_by_chunks to be false, and then from yahoo webmail forwarded a message to both my att.net and gmail.com accounts. I tried this twice. Once, the att.net came in OK, once not OK. Both times, the gmail.com mail came in not ok (jpgs as attachments). So chunks=false isn't a solution.

I may have forgot one thing. When you change the pref for chunks to false you may need to restart tb.
But you are saying the .jpgs come in not inline but as regular attachments. But otherwise all the information is there and nothing is really missing. So maybe there really are two problems here. But it appears the problem is with yahoo. I'll do some more testing.
Still need either a sample email that would get broken up and/or the IMAP:5 log showing what is happening in tb.

I will do additional testing heopfully today, and will try to create a sample email that I can provide to you (I probably should not publicly provide the email I've been using without my sender friend's approval). Thanks!

(In reply to jamesmknott from comment #10)

I will do additional testing heopfully today, and will try to create a sample email that I can provide to you (I probably should not publicly provide the email I've been using without my sender friend's approval). Thanks!

For now won't need sample or imap log since I've duplicated the "only see attachments and not inline images" over at bug 1822218
So I now think this bug and bug 1822218 are separate bugs and not dupes.
But I think this bug 1821755 is definitely a yahoo issue and not a tb issues (i.e., yahoo chokes when tb tries to fetch by chunks).

I notice that yesterday and today I've received more junk mail thru my att.net account than I'd normally receive in a week or more. So perhaps yahoo is doodling with their mail servers (and junk mail processing), and that may? be why we're seeing things change a lot over the last couple of days. Just a hunch, not a fact. FYI.

I set "chunks=false" (see above) back when requested (above)

With "chunks=false" (see above) I do not currently see the original problem, and this appears as a good workaround/solution for me. I'll continue to test over the week, as I'm not 100% positive that my recreation testing approach is 100% valid (as I previously once thought it was fixed when it was not).

Here is how I tested:

  1. My testing: gmail friend sends newsletter to my att.net account once a day. att (yahoo) webmail receives it complete with no truncation
  2. Using att/yahoo webmail, I forward to my gmail account (gmail webmail received complete, no truncation)
  3. Using gmail webmail, I forward it back to my att.net account (att/yahoo webmail received complete, no truncation. (I do this round-trip thru gmail and back so that I can recreate a fresh gmail-based test message at will. I presume? this is a valid test).
  4. On TB I click on Get messages from ATT (via IMAP). The very moment I see TB display the IMAP header, on TB I start clicking (see above) on this and some other random message to simulate "interrupting" the IMAP message body sync.
  5. after doing this "clicking" for 10-20 seconds, I stop. Only after then (another, say 5-10 seconds) does the message body appear on TB, and it is all complete with no truncation.

I now believe this Bug 1821755 is completely separate from Bug 1822218

perhaps it is time to go for bug 1617823

Depends on: 1617823
See Also: → 974425, 1617823
Summary: IMAP mail content truncated if mail is viewed while Thunderbird sync is occurring. → IMAP mail content truncated if mail is viewed while Thunderbird sync is occurring with mail.server.default.fetch_by_chunks set to true
See Also: 1617823
You need to log in before you can comment on or make changes to this bug.