Closed Bug 518581 Opened 15 years ago Closed 11 years ago

Gmail account: messages read in inbox not being marked as read in 'gmail->all mail' folder (IMAP flag change at a Gmail IMAP folder, \Seen/-\Seen, Tag added/Tag removed, is not always reflected to other Gmail IMAP folders immediately)

Categories

(MailNews Core :: Networking: IMAP, defect)

Product:
MailNews Core
Component:
Networking: IMAP
Version:
1.9.1 Branch
Platform:
x86
All
Type:
defect
Priority:
Not set
Severity:
normal

Tracking

(Not tracked)

Status:
RESOLVED DUPLICATE of bug 693204

People

(Reporter: davec, Unassigned)

References

(Blocks 2 open bugs)

Details

User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9.1.3) Gecko/20090824 Firefox/3.5.3 (.NET CLR 3.5.30729)
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 6.0; en-US; rv:1.9.1.4pre) Gecko/20090915 Lightning/1.0pre Thunderbird/3.0b4

I've noticed this both in TB3 Betas 3 & 4:

I have 2 Imap/Gmail accounts enabled on this install, as well as 3 non gmail imap accounts. Usually once or twice a day when receiving new mail to these gmail accounts each will report new mail via the popup indicator taking into account both messages in the 'inbox' and the 'gmail->all main' folder. As the problem continues, mail read in the 'inbox' will be marked read there but will not be marked as read in 'gmail->all mail', which means as I get new mail in my inbox, the popup notifier continues to report messages I've already read in the inbox as unread since they aren't marked as so 'gmail->all mail.' Manually marking 'gmail->all mail' as read will fix the problem until new mail is received again and 'gmail->all mail' continues to not mark messages as read when marked read in the inbox.

Note that I'm solely using the 'all folders' view here, not smart folders.

Reproducible: Sometimes

Steps to Reproduce:
I haven't been able to purposefully reproduce this, though it happens quite regularly. Am curious if it has to do with having 2 gmail accounts and switching between them. Perhaps also the presence of non gmail imap accounts affects things also.
Some updates:

1 - This also occurs in safe mode.
2 - It's not an issue of the count, but that the messages subjects already read in Inbox and not marked unread in Gmail->All Mail are showing up in the new mail notifier.

So, as follows:

I get 3 messages. I read all three.
I get 1 new message. Popup notifier says 'You have 1 new message' but the subject preview below that lists the subjects for the 1 new message in the inbox and the subjects for all the messages previously read but still marked as unread in Gmail->All Mail.
I'm really not sure which bug I'm talking about (i.e Bug 502370 or Bug 518581), but I have noticed a few things here:

0. (Yes, zero) It seems to me that TB doesn't expect mails to be marked as unread on the server when it hasn't done marked it itself. Put simply, TB is coded to believe that only it is capable of marking a mail read or unread while it is running. This is expected behavior and this is not where we want to fix this bug. (Unless you want TB to check the message ID, which may or may not be a nice thing to do. But read on, I think this issue can be fixed in a different way)


1. This can happen backwards as well. I can read the mail in All Mail and then check the mail in the other 'Labels' that mails is in and the mail will not be marked as read in these other Folders/Labels. If the initial problem is understood, this should be as well, because one of the reasons (I'm coming to the other) this problem exists is that TB doesn't recognize the Label system, and tries to apply the folder system to GMail. By this logic, the reverse issue should affect us in theory, and it does.


2. This bug is not 100% reproducible. If I read (say) 10 unread mails in my Inbox, reading the first 7 for a long time and quickly glancing over the last three, just to make them read, and immediately go to All Mail, TB checks for new mails and marks ONLY the last three as read, leaving the first seven that I took a long time to read as unread. When I have a mail in three Labels, and I read it in one, it is often marked as read in one of the other two folders while unread in the last one.

Here's my guess, for why TB behaves that way:
It does seem that when a 'folder' is not opened for a long time, the type of checking that TB does (in the background) is different from the type of checking that TB does when I open a folder (in the foreground). If a "background"/automatic check is done on the server, TB seems to check for new messages only. It doesn't check for any other changes. When it does a full check, only the changes since the last "check" seem to be recognized.

How this can be verified (over the next couple of days, I shall try these tests and post the results here):

  a. Disable all automatic and periodic checks ("Check this folder for new messages" in the folder preferences) on one folder. Read a lot of mails that are in that folder from "All Mail" and wait at least ten to fifteen minutes. Now open that folder. If this theory is correct, TB will correctly mark all read messages in that folder as read.

  b. Enable automatic checking of a folder and change settings to check every minute. If this theory is correct, this bug will be far more reproducible and should happen for almost every message. At the moment, this is reproducible but doesn't happen for all mails.

To summarize point No. 2, TB, I think, checks the server only for new mails when it does an automatic check, but when it does a proper check (when you open that folder) it looks only for changes after the last automatic check.


3. The list of read/unread messages syncs itself properly if I restart TB. Since this is the first time I'm checking in that session, I presume TB does a more thorough check and brings everything up-to-date. There is no issue of having unread messages that I've already read in the long term. Sooner or later, everything sorts itself out. It's only *during* a session that the problem holds.

Hope this problem gets fixed (and that this isn't marked "invalid" ;) ). I will be willing to try things out if any help is needed to find what is causing this.

I am running Ubuntu, using TB 3.0.2 from Mozilla binaries packaged into a PPA (ubuntuzilla): 

Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.9.1.8) Gecko/20100216 Thunderbird/3.0.2

I have seen this bug on Windows also. 

Please mark as CONFIRMED, Platform: All. I began using IMAP only after TB3 came, so I cannot confirm the versions that are affected.
(Forgot to add) Of course, if what I wrote above is correct, then the problem lies in TB, not in GMail.
I could see similar phenomenon with Tb 3.0.3, with Gmail IMAP, using single IMAP client(Tb), during test for Bug 450246(tag case) and bug 544439(\Seen flag case).

1. A mail has Gmail Label of [Gmail]/All Mail, Inbox, X/A1, X/A2, X/A3, ...
   "Read status" at all folder
2. Change mail in X/A1 to Unread
   => mail in some folders was changed to Unread. (not opened yet?)
   => mail in Inbox was not changed to Unread.
   => mail in other foldrs was not changed to Unread. (already opened?)
"Work Offline, go back to Work Online, Click the folder" was required to reflect status change.
So, it looked for me next phenomenon.
  If IMAP folder is already opened, re-synchronization of flag is not executed.

Dave Carner(bug opener) and Umang:
  
Can you get IMAP log and check IMAP level flow?
> https://wiki.mozilla.org/MailNews:Logging
> http://www.mozilla.org/projects/nspr/reference/html/prlog.html#25328
> SET NSPR_LOG_MODULES=timestamp,imap:5 (MS Win example)

Does Gmail IMAP return new status("no \Seen flag" status or "\Seen flag" status) after status change by other for the mail?
Does Tb know "change from with \Seen flag to without \Seen flag or vice versa" of the mail in Gmail IMAP folder?
Or Tb knows it but status of MsgDB/thread pane is not refreshed?

> and immediately go to All Mail, TB checks for new mails and marks ONLY the last three as read,

Tb knows highest UID(N) which is used and next UID(N+1) for new mail. Upon new mail check, Tb probably issues "uid (N+1):* flags". If no new mail with UID grater than N, Gmail returns flag status for uid=N. If new mails for Tb exist, Tb can obtain flag status for UID from (N+1) to (N+x). I guess you are looking phenomenon at this stage.
For old mail(UID M, M is less than N), flag status change(\Seen<->No \Seen) can't be obtained unless "uid M fetch flags ..." is issue again. I guess "status of old mail is not changed" is problem around this(phenomenon I saw).
OS: Windows Vista → All
Blocks: tb-gmailWIP
No longer blocks: tb-tagsmeta
When already accessed Inbox is clicked after flag status change at other Gmail IMAP folder, Tb 3 issued next fetch(highest UID Tb knows==11667, no new mail is added to Inbox).
> S-INBOX:SendData: 33 UID fetch 11668:* (FLAGS) 
> S-INBOX:CreateNewLineFromSocket: * 4 FETCH (UID 11667 FLAGS (NonJunk \Seen)) 
> S-INBOX:CreateNewLineFromSocket: 33 OK Success
As Gmail IMAP returns flag data of highest UID=11667 when no new mail, Tb can know flag change of highest UID(=11667 in this case) by the fetch command. So, if last mail(highest UID), this bug's problem(\Seen flag) and Bug 450246 comment #15(tag case) doesn't occur.
As Bug 436315 exists, I tried "Compact", but tag update at other folder was not refleted to mail in Inbox, except last mail(highest UID).
> Bug 436315 don't need to fetch 1:* FLAGS after expunge
Some enhancements like next, "Re-synchronize IMAP flag" menue, will be required?
> 324710 Consider fetching IMAP message flags in the background
Or, "MsgDB is not closed" is cause? (If closed and re-opened upon click, re-synchronization of all mails is executed by open.)

Confirming with my test result.
Status: UNCONFIRMED → NEW
Ever confirmed: true
> Dave Carner(bug opener) and Umang:
> 
> Can you get IMAP log and check IMAP level flow?
> > https://wiki.mozilla.org/MailNews:Logging
> > http://www.mozilla.org/projects/nspr/reference/html/prlog.html#25328
> > SET NSPR_LOG_MODULES=timestamp,imap:5 (MS Win example)
> 
> Does Gmail IMAP return new status("no \Seen flag" status or "\Seen flag"
> status) after status change by other for the mail?
> Does Tb know "change from with \Seen flag to without \Seen flag or vice versa"
> of the mail in Gmail IMAP folder?
> Or Tb knows it but status of MsgDB/thread pane is not refreshed?

Hi,
I tried running:

  $ NSPR_LOG_MODULES=imap:5 thunderbird

But there was way too much text being bombarded at me to be able to understand anything.  Can you explain, since I haven't done this before, what exactly I'm looking for?

Also, I've noticed that the behavior is a lot more random than I thought it was. I have not been able to successfully "corner" Thunderbird and predict that if I do, XYZ, TB will do this. In my initial comment (#3), what I said sounded like the bug was predictable. It's not so.
(In reply to comment #8)
> Also, I've noticed that the behavior is a lot more random than I thought it
> was. I have not been able to successfully "corner" Thunderbird and predict that
> if I do, XYZ, TB will do this. In my initial comment (#3), what I said sounded
> like the bug was predictable. It's not so.

Do you enable "Check for new messages upon sartup/every NN minutes"? If so, it may be by fix of bug 540214, because bug 540214 is landed on Tb 3.0.2 and MsgDB is properly closed after STAT by the fix.
If closed and re-opened(or Work Offine, back to Work Online, click the folder), fetch uid 1:* flags is probably issued and flag changes of old mails are obtained.

> But there was way too much text being bombarded at me to be able to understand
anything.

Get log with small folders, please.
(1) Create folder X/A1, X/A2, X/A3, Show "Order Received" column(UID of mail).
(2) Copy three mails to X/A1, add tag of "To Do"(blue) to three mails.
    X/A1 : change mail status
    X/A2 : opened before change at X/A1
    X/A3 : not opened before change at X/A1. opened after change at X/A1
    mail-1 : to make mail-1 last accessd mail, to keep other's Unread status.
    mail-2 : mail of non-highest UID
    mail-3 : mail of highest UID 
(3) Copy mail-1(lowest uid) to X/A2, X/A3, copy mail-2(next uid) to X/A2, X/A3,
    and copy mail-3(highest uid) to X/A2, X/A3 (to keep same order).
    At all 3 folders, click mail-1(last accessed mail, to keep Unread of 2/3).
    Check all mails in all three folders, and confirm "same status/tag".
(4) Restart Tb with IMAP logging, and Click X/A2, then click X/A1
(5) At X/A1, add tag of "Important"(red) to all three mails,
    change mail-2/mail-3 to Unread, and click mail-1.
(6) Click X/A2, check thread pane(don't touch mail, not to change read/unread)
(7) Click X/A3, check thread pane(don't touch mail, not to change read/unread)
What status/tag(color) is seen for mail-2/3 in X/A2 and X/A3?
(8) Work Offline, go back to Work Online
(9)  Click X/A2, check thread pane(don't touch mail, not to change read/unread)
(10) Click X/A3, check thread pane(don't touch mail, not to change read/unread)
What status/tag(color) is seen for mail-2/3 in X/A2 and X/A3?
(8) Terminate Tb, keep backup of log.
Note: above is similar procedure I used in test of Bug 450246 for tag.

As test is relevant to X/A1, X/A2, X/A3 only, irrelevant logs can easily be removed by text editor. To reduce irrelevant logs since first, I recommend to disable "Check for new messages upon sartup/every NN minutes" when getting log.
Umang, no need to execute test of comment #9.

I could observe that \Seen/no \Seen and addition/removal tag at other folder is immediately reflected to any other folder with Tb 3.0.3 like before.
Reflection to Inbox was after several click of Inbox. It's probably by "cached MsgDb after a while"(still cached, then "uid 1:* flags" is not issued).

When I tested comment #6(and bug 450246 #13 to #15), I saw "too much connections" from Gmail IMAP because I used both Sm2 and Tb3 for same Gmail IMAP access with "max cached connections=5"(Sm2: 2 Gmail IMAP, Tb: 1 Gmail IMAP) and I repeated termination/restart of Tb for testing. Such error may produce phenomeon of "unclosed MsgDB or close failure of MsgDB".
I'll continue to check it in bug 450246.
I could observe "UID fetch 1:* (FLAGS)" upon click of Inbox which was opened in the past.

> Folder is switched at folder pane multiple times.
> Before next, S-INBOX:SendData: 1xx select "S-A-00/A-01" occurred.
>
> At this step, Inbox.msf is opened(checked by MSGDB:5)
> Click Inbox.
> S-A-00/A-03:SendData: 127 select "INBOX" 
> S-INBOX:CreateNewLineFromSocket: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
> S-INBOX:CreateNewLineFromSocket: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)]
> S-INBOX:CreateNewLineFromSocket: * OK [UIDVALIDITY 602312987] 
> S-INBOX:CreateNewLineFromSocket: * 4 EXISTS 
> S-INBOX:CreateNewLineFromSocket: * 0 RECENT 
> S-INBOX:CreateNewLineFromSocket: * OK [UIDNEXT 11668] 
> S-INBOX:CreateNewLineFromSocket: 127 OK [READ-WRITE] INBOX selected. (Success)
> S-INBOX:SendData: 128 getquotaroot "INBOX"
> S-INBOX:CreateNewLineFromSocket: * QUOTAROOT "INBOX" "" 
> S-INBOX:CreateNewLineFromSocket: * QUOTA "" (STORAGE 11514 7609372) 
> S-INBOX:CreateNewLineFromSocket: 128 OK Success 
> S-INBOX:SendData: 129 UID fetch 1:* (FLAGS)

What I saw in comment #6 was possibly phenomenon like next;
- Until "select Inbox" happen again, UID fetch 1:* (FLAGS) is not issued again.
- If connection error occurs on connection for S-INBOX, folder switch by
  "select other-folder" at the connection doesn't occur not so easily.
- "MsgDB is not closed due to soemthing" may produce similar issue,
  because folder open is not invoked.
Umang, can you get log while you are using Tb with next parameter?
> SET NSPR_LOG_MODULES=timestamp,MSGDB:5 (MS Win example)
Run one to two hours with logging, and check whether "number of opened .msf" increases without close, or not, please. (log of "increase as if infinite" was attached to a bug, although it looked local folder/rss/news case.)
Again, I'm not following this very well, but if I do this (On Linux):
  $ NSPR_LOG_MODULES=timestamp,MSGDB:5 thunderbird
Then I'm getting a lot of output again. However, it has the names of many of my folders (which I would not like to post on publicly accessible page like this).

Should I just do a 
  $ NSPR_LOG_MODULES=timestamp,MSGDB:5 thunderbird > tb.log
and send the `tb.log` file to you by email?
Forgot to ask, when I check all these logs, do I enable or disable "Check for new messages every 5 minutes"? (It's enabled right now)
(In reply to comment #13)
> Should I just do a (snip) and send the `tb.log` file to you by email?

There is no need of log data itself. Your check result of "number of opened .msf at each MSGDB:5 logging(looks periodical) increases as if infinetely or not" and of "close of .msf/MsgDB is logged as expected or not" is sufficient.  

(In reply to comment #14)
> do I enable or disable "Check for new messages every 5 minutes"? (It's enabled right now)

If you use Tb 3.0.2 or later, bug 540214 is fixed. So, I think check with enabled is better initially, if enabled is your default setting for daily use, because folder access/MsgDB open doen't happen unless you manually click folder if disabled.
If something wrong around MsgDB open/close will be found, test with disabled will be required for diagnosis, to check whether other component such as Gloda, auto-sync, is culprit or not.
Test result of comment #11 is with "check for ...startup/every 1 minute" enabled, with "max number of cached connections=1" to force folder switch at connection upon each folder click.
Umang, can you check with "max number of cached connections=1"
Summary: Gmail account: messages read in inbox not being marked as read in 'gmail->all mail' folder. → Gmail account: messages read in inbox not being marked as read in 'gmail->all mail' folder (IMAP flag change at an Gmail IMAP folder, \Seen/-\Seen, Tag added/Tag removed, is not always reflected to other Gmail IMAP folders immediately)
Phenomenon I saw with Tb 3.0 in bug 450246 comment #13 to #15 was same problem as this bug.
Component: Folder and Message Lists → Networking: IMAP
Product: Thunderbird → MailNews Core
QA Contact: folders-message-lists → networking.imap
Version: unspecified → 1.9.1 Branch
Summary: Gmail account: messages read in inbox not being marked as read in 'gmail->all mail' folder (IMAP flag change at an Gmail IMAP folder, \Seen/-\Seen, Tag added/Tag removed, is not always reflected to other Gmail IMAP folders immediately) → Gmail account: messages read in inbox not being marked as read in 'gmail->all mail' folder (IMAP flag change at a Gmail IMAP folder, \Seen/-\Seen, Tag added/Tag removed, is not always reflected to other Gmail IMAP folders immediately)
This is the kind of output I get:

Many lines like this:

> 2010-03-09 12:58:38.440820 UTC - -1215604896[b7611060]: /home/umang/.thunderbird/qu5s4b6i.default/ImapMail/imap.googlemail.com/[Gmail].sbd/All Mail.msf - 3 hdrs in use 

then "closing database" after every once in a while:

> 2010-03-09 12:59:44.252318 UTC - -1215604896[b7611060]: closing database    /home/umang/.thunderbird/qu5s4b6i.default/ImapMail/imap.googlemail.com/[Gmail].sbd/All Mail.msf 

and some like this:

2010-03-09 13:02:01.135137 UTC - -1215604896[b7611060]: 5 open DB's

then I see more of the first kind of output:

> 2010-03-09 13:03:27.404664 UTC - -1215604896[b7611060]: /home/umang/.thunderbird/qu5s4b6i.default/ImapMail/imap.googlemail.com/INBOX.msf - 166 hdrs in use 

What is the number I am looking for? I've not exactly understood what I have to do. I can't find "number of opened .msf" anywhere.
(In reply to comment #18)
> What is the number I am looking for?

I wanted to say NNN in "NNN open DB's" of next log by the "number".
> and some like this:
> 2010-03-09 13:02:01.135137 UTC - -1215604896[b7611060]: 5 open DB's
If problem of "MsgDB is never closed" occurs, the NNN increases as if infinitely. So, I'm confident that such problem doesn't exist in your environment by your answer. Thanks for your log analysis.

Note: "PPP hdrs in use" is probably similar to "PPP mails are held in the folder".
hdrs in use refers to how many nsMsgHdr objects are in memory for that folder. It helps us know how much more memory is being used for that folder, and also what the folder is being used for (things like views and gloda indexing create nsMsgHdrs when they use a db; get/setting a property on a folder in the db doesn't cause any headers to get instantiated)
Any progress? Is there any way I can provide more information?
No longer blocks: 512745
I am still affected on TB 5.
I am experiencing this on TB 11.0.1, OSX 10.7.3.

Maybe something in my settings, though, because it seems to be occurring on one account in particular (amongst several gmail imap accounts).

I delete from Inbox ('Remove It Immediately') and it remains unread in All Mail, and shows up for an extended period of time in the new mail notifier.
Blocks: 800003
We could take advantage of the X-GM-LABELS and X-GM-MSGID attributes to fix this bug.

Algorithm would be: If message flags are updated and message has X-GM-LABELS, then iterate labels and find messages with matching X-GM-MSGID and update the flags for those messages.
Still experiencing this with 17.0.5, does any further information need to be provided?
"IDLE does not send unsolicited responses for flag changes" is not Gmail IMAP only issue.
Issue of "Tb is not torelant with 'IDLE does not send unsolicited responses for flag changes'" is not Gmail IMAP only issue.
Because bug 693204 was processed after analysis of many bugs, that bug is crispy than other bugs.
So, duping this bug to bug 693204.
If duping is wrong, re-open this bug, please.
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → DUPLICATE
No longer blocks: 594106
No longer blocks: 544439
No longer depends on: 512745
You need to log in before you can comment on or make changes to this bug.