Clicking on unread messages immediately marks some of them as read

RESOLVED DUPLICATE of bug 662792

Status

MailNews Core
Networking: IMAP
RESOLVED DUPLICATE of bug 662792
7 years ago
7 years ago

People

(Reporter: Mike Robinson, Unassigned)

Tracking

Firefox Tracking Flags

(Not tracked)

Details

(Whiteboard: [has protocol logs])

Attachments

(1 attachment)

(Reporter)

Description

7 years ago
User-Agent:       Opera/9.80 (X11; Linux i686; U; en) Presto/2.6.30 Version/10.63
Build Identifier: Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.2.12) Gecko/20101027 Lightning/1.0b2 Thunderbird/3.1.6

This is my setup:

Folder is Inbox from a local IMAP store, other folders are not affected.
Unified folders enabled
mailnews.mark_message_read.delay.interval = 10
Preview pane is enabled


Reproducible: Always

Steps to Reproduce:
1. Click on a new message
2.
3.
Actual Results:  
Randomly new messages are immediately marked as being read (about 1 in 4). If you then manually mark it as unread again, subsequent clicking on it will not mark it as read again.

Expected Results:  
mailnews.mark_message_read.delay.interval = 10
(Reporter)

Comment 1

7 years ago
Created attachment 492639 [details]
Screen capture
Attachment #492639 - Attachment mime type: application/octet-stream → video/ogg
Is your inbox a large inbox ?

Do you see the same results if you start in -safe-mode (http://support.mozillamessaging.com/en-US/kb/Safe+Mode) ?
(Reporter)

Comment 3

7 years ago
Hi Ludovic,

Thanks for your help. I started TB in safe-mode and it still happens, but not nearly as much (about 1 message in 20 as opposed to about 1 in 4 with safe-mode disabled).

The inbox is quite large (21k messages) however it also happens to me on other folders in the same IMAP account with around 40 messages, so unless the total size of all the folders has something to do with it, I doubt that is what is causing it.

I might also note that the mail is stored in Maildir format on localhost if that helps anything.
(In reply to comment #3)
> Hi Ludovic,
> 
> Thanks for your help. I started TB in safe-mode and it still happens, but not
> nearly as much (about 1 message in 20 as opposed to about 1 in 4 with safe-mode
> disabled).

Hum so an extension was playing a trick ....
 
> The inbox is quite large (21k messages) however it also happens to me on other
> folders in the same IMAP account with around 40 messages, so unless the total
> size of all the folders has something to do with it, I doubt that is what is
> causing it.

Size does matter but I don't know in which proportion.
 
> I might also note that the mail is stored in Maildir format on localhost if
> that helps anything.

Might be interesting at looking into the imap logs and see what's going on there (see https://wiki.mozilla.org/MailNews:Logging on how to log, imap and imapautosync are the one of interest in this case)
(Reporter)

Comment 5

7 years ago
Sorry for taking so long to answer here. I finally got around to logging things and I see for one of the ones that was marked as read the following:

-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:CreateNewLineFromSocket: 22 OK Idle completed.
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:ProcessCurrentURL: entering
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:ProcessCurrentURL:imap://mike@mike:143/fetch%3EUID%3E.INBOX%3E37302:  = currentUrl
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:SendData: 23 UID fetch 37302 (BODYSTRUCTURE)
-1352664208[a8a4c270]: ReadNextLine [stream=b3df49c8 nb=772 needmore=0]
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:CreateNewLineFromSocket: * 22889 FETCH (UID 37302 BODYSTRUCTURE ((("text" "plain" ("charset" "Windows-1252") NIL NIL "quoted-printable" 298 52 NIL NIL NIL NIL)("text" "html" ("charset" "Windows-1252") NIL NIL "quoted-printable" 11299 298 NIL NIL NIL NIL) "alternative" ("boundary" "----=_NextPart_001_010D_01CBB7C3.99721F50") NIL NIL NIL)("image" "jpeg" ("name" "image004.jpg") "<010901cbb7bb$37ab4650$0f00a8c0@PC01>" NIL "ba
-1352664208[a8a4c270]: se64" 15840 NIL NIL NIL NIL)("image" "jpeg" ("name" "Cuba 2x1.jpg") "<010a01cbb7bb$37ab4650$0f00a8c0@PC01>" NIL "base64" 75804 NIL NIL NIL NIL)("image" "jpeg" ("name" "image003.jpg") "<010b01cbb7bb$37ab4650$0f00a8c0@PC01>" NIL "base64" 78460 NIL NIL NIL NIL) "related" ("boundary" "----=_NextPart_000_010C_01CBB7C3.99721F50" "type" "multipart/alternative") NIL NIL NIL))
-1352664208[a8a4c270]: ReadNextLine [stream=b3df49c8 nb=24 needmore=0]
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:CreateNewLineFromSocket: 23 OK Fetch completed.
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:SendData: 24 UID fetch 37302 (UID RFC822.SIZE BODY[])
-1352664208[a8a4c270]: ReadNextLine [stream=b3df49c8 nb=83 needmore=0]
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:CreateNewLineFromSocket: * 22889 FETCH (UID 37302 RFC822.SIZE 184732 FLAGS (\Seen NonJunk) BODY[] {184732}
-1352664208[a8a4c270]: b3b6a000:mike:S-INBOX:STREAM:OPEN Size: 184732: Begin Message Download Stream

The difference between this and any other messages is the "FLAGS (\Seen NonJunk)" part. Is this something that is sent by the server?

I also notice that when I mark the message as being unread and then click on it again, clicking on it does not create anything new in the log, which would leave me to believe that TB is caching the message status until you restart the program.

This is what is logged when I mark the message as read:

-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: DONE
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=24 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: 110 OK Idle completed.
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:ProcessCurrentURL: entering
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:ProcessCurrentURL:imap://mike@mike:143/addmsgflags%3EUID%3E.INBOX%3E37302%3E1:  = currentUrl
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: 111 uid store 37302 +Flags (\Seen)
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=64 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: * 22889 FETCH (UID 37302 MODSEQ (60380) FLAGS (\Seen NonJunk))
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=25 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: 111 OK Store completed.
-1216460688[b750f060]: QI copyState failed:80004003
-1386218640[ae2fbdf0]: CopyNextStreamMessage failed:80004003
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: 112 IDLE
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=10 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: + idling



And unread:

-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: DONE
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=24 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: 112 OK Idle completed.
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:ProcessCurrentURL: entering
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:ProcessCurrentURL:imap://mike@mike:143/subtractmsgflags%3EUID%3E.INBOX%3E37302%3E1:  = currentUrl
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: 113 uid store 37302 -Flags (\Seen)
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=58 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: * 22889 FETCH (UID 37302 MODSEQ (60381) FLAGS (NonJunk))
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=25 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: 113 OK Store completed.
-1216460688[b750f060]: QI copyState failed:80004003
-1386218640[ae2fbdf0]: CopyNextStreamMessage failed:80004003
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:SendData: 114 IDLE
-1386218640[ae2fbdf0]: ReadNextLine [stream=ae06d7e8 nb=10 needmore=0]
-1386218640[ae2fbdf0]: adedf800:mike:S-INBOX:CreateNewLineFromSocket: + idling

I thought that maybe the "QI copyState failed" or "CopyNextStreamMessage failed" parts would be significant, however all messages that I marked as read or unread contain the same lines.

Any ideas what could be going on?
Component: Folder and Message Lists → Networking: IMAP
Product: Thunderbird → MailNews Core
QA Contact: folders-message-lists → networking.imap
Whiteboard: [has protocol logs]

Comment 7

7 years ago
There's a patch in bug 662792 that should fix this. This should only happen on messages > 30K with no external parts (i.e., parts that we don't display inline). I'm hoping I can get that fix in to TB 6, which will be out in six weeks or so.
Status: UNCONFIRMED → RESOLVED
Last Resolved: 7 years ago
Resolution: --- → DUPLICATE
Duplicate of bug: 662792

Comment 8

7 years ago
the list in https://bugzilla.mozilla.org/show_bug.cgi?id=614232#c6 doesn't have an obvious duplicates - many of those have to do with us displaying a message when switching views.

This bug is trick to reproduce. If a suitable message is in the memory cache (e.g., the junk filter streamed it), then clicking on it won't mark it read, because we'll fetch from the memory cache, but when you restart, clicking on it will mark it read. And the disk cache also complicates things.
(Reporter)

Comment 9

7 years ago
Hi David,

That's awesome. Thanks for your help.

BTW, what is TB 6? I see TB 5 in the nightlies and pre-releases, but no 6.

Comment 10

7 years ago
TB 6 is currently http://ftp.mozilla.org/pub/mozilla.org/thunderbird/nightly/latest-comm-aurora/

But I haven't checked the patch in anywhere yet - it will land in nightlies first, then aurora, where I believe it will be called Earlybird, once we've got that set up.
You need to log in before you can comment on or make changes to this bug.