← Back to team overview

desktop-packages team mailing list archive

[Bug 1426174] [NEW] Messaging Menu integration causes endless imap refresh at high message counts

 

Public bug reported:

The Messaging Menu and Unity Launcher integration 1.3.1 extension causes Thunderbird 31.4.0 to endlessly refresh imap folders as message count nears 100000 in a folder.
This is not a regression.

Yesterday and again today, Google throttled my imap access because of
excessive imap requests, which was odd because I only use one machine
(ie., no other devices) for that account's email.

My usage is somewhat outside the norm in that I subscribe to several
high-volume mailings (necessary as a kernel developer) which exceed
20000 emails a month. These emails are server-filtered and so appear to
be delivered directly to the subscribed folder.  There are 23 folders,
each for a different mailing list, tagged for update checks (via "Folder
Properties/General Information/When getting new messages..."). These
folders are not marked for offline sync and storage.

As of today, I have 90000 emails in a just single folder and that's
after deleting email prior to Oct 1.

Yesterday, after Google had disabled my imap access for 2 hrs, I reduced
the number of cached connections from 5 to 1 (I had occasionally seen
errors about too many imap connections when starting up, at least for
the last 2 mos or so).

For the last several hours, Thunderbird has almost constantly been refreshing folders.
I stopped and restarted Thunderbird several times but the constant refresh continued.
So I captured an imap log (122MB within several minutes) and noted what appears to be redundant fetches. For example, 

-1906690176[7fb48d217580]: considering playing queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
-1906690176[7fb48d217580]: creating protocol instance to play queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
-1906690176[7fb48d217580]: proposed url = mailing lists/linux-arm folder for connection personal/mary has To Wait = FALSE can run = FALSE
-1906690176[7fb48d217580]: playing queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:ProcessCurrentURL: entering
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:ProcessCurrentURL:imap://peter%40hurleysoftware%2Ecom@xxxxxxxxxxxxxx:993/select%3E/mailing%20lists/linux-arm:  = currentUrl
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:SendData: 20 select "mailing lists/linux-arm"
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=83 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen $Phishing $label1 $NotPhishing)
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=117 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen $Phishing $label1 $NotPhishing \*)] Flags permitted.
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [UIDVALIDITY 220] UIDs valid.
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=16 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 EXISTS
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=12 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 0 RECENT
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=42 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [UIDNEXT 30319] Predicted next UID.
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=31 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [HIGHESTMODSEQ 16017829]
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=76 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 20 OK [READ-WRITE] mailing lists/linux-arm selected. (Success) [THROTTLED]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 21 getquotaroot "mailing lists/linux-arm"
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=42 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * QUOTAROOT "mailing lists/linux-arm" ""
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=39 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * QUOTA "" (STORAGE 1863907 31457280)
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 21 OK Success [THROTTLED]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 22 UID fetch 1:* (FLAGS)
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=33 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 1 FETCH (UID 1 FLAGS (\Seen))
........
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30312 FETCH (UID 30316 FLAGS ())
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30313 FETCH (UID 30317 FLAGS ())
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 FETCH (UID 30318 FLAGS ())
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 22 OK Success [THROTTLED]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 23 UID fetch 30318 (UID X-GM-MSGID X-GM-THRID X-GM-LABELS RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To X-Mailing-List X-List-Name List-Id)])
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=334 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 FETCH (X-GM-THRID 1491831819459052696 X-GM-MSGID 1494202989826800755 X-GM-LABELS ("mailing lists/dri-devel") UID 30318 RFC822.SIZE 18337 FLAGS () BODY[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To X-Mailing-List X-List-Name List-Id)] {1075}
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:STREAM:OPEN Size: 18337: Begin Message Download Stream
..............
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: )
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:STREAM:CLOSE: Normal Message End Download Stream
1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 23 OK Success [THROTTLED]
-1906690176[7fb48d217580]: proposed url = mailing lists/linux-arm folder for connection mailing lists/linux-arm has To Wait = TRUE can run = FALSE
-1906690176[7fb48d217580]: queuing url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/fetch>UID>/mailing lists/linux-arm>30318?header=filter&emitter=js&fetchCompleteMessage=false


Note that after receiving the "22 OK Success" reply for "22 UID fetch 1:* (FLAGS)", TB only fetched UID 30138 (even though there were actually 12 emails without the Seen flag) and then after receiving the message successfully, queued a url fetch _for the exact same message_!

The "emitter=js" got me thinking that there was some Javascript running,
which led me to disabling the only Extension installed,  the Messaging
Menu and Unity Launcher integration.

Restarted TB and voila -- no more endless updates.

** Affects: thunderbird (Ubuntu)
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Desktop
Packages, which is subscribed to thunderbird in Ubuntu.
https://bugs.launchpad.net/bugs/1426174

Title:
  Messaging Menu integration causes endless imap refresh at high message
  counts

Status in thunderbird package in Ubuntu:
  New

Bug description:
  The Messaging Menu and Unity Launcher integration 1.3.1 extension causes Thunderbird 31.4.0 to endlessly refresh imap folders as message count nears 100000 in a folder.
  This is not a regression.

  Yesterday and again today, Google throttled my imap access because of
  excessive imap requests, which was odd because I only use one machine
  (ie., no other devices) for that account's email.

  My usage is somewhat outside the norm in that I subscribe to several
  high-volume mailings (necessary as a kernel developer) which exceed
  20000 emails a month. These emails are server-filtered and so appear
  to be delivered directly to the subscribed folder.  There are 23
  folders, each for a different mailing list, tagged for update checks
  (via "Folder Properties/General Information/When getting new
  messages..."). These folders are not marked for offline sync and
  storage.

  As of today, I have 90000 emails in a just single folder and that's
  after deleting email prior to Oct 1.

  Yesterday, after Google had disabled my imap access for 2 hrs, I
  reduced the number of cached connections from 5 to 1 (I had
  occasionally seen errors about too many imap connections when starting
  up, at least for the last 2 mos or so).

  For the last several hours, Thunderbird has almost constantly been refreshing folders.
  I stopped and restarted Thunderbird several times but the constant refresh continued.
  So I captured an imap log (122MB within several minutes) and noted what appears to be redundant fetches. For example, 

  -1906690176[7fb48d217580]: considering playing queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
  -1906690176[7fb48d217580]: creating protocol instance to play queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
  -1906690176[7fb48d217580]: proposed url = mailing lists/linux-arm folder for connection personal/mary has To Wait = FALSE can run = FALSE
  -1906690176[7fb48d217580]: playing queued url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/select>/mailing lists/linux-arm
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:ProcessCurrentURL: entering
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:ProcessCurrentURL:imap://peter%40hurleysoftware%2Ecom@xxxxxxxxxxxxxx:993/select%3E/mailing%20lists/linux-arm:  = currentUrl
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-personal/mary:SendData: 20 select "mailing lists/linux-arm"
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=83 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * FLAGS (\Answered \Flagged \Draft \Deleted \Seen $Phishing $label1 $NotPhishing)
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=117 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen $Phishing $label1 $NotPhishing \*)] Flags permitted.
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [UIDVALIDITY 220] UIDs valid.
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=16 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 EXISTS
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=12 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 0 RECENT
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=42 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [UIDNEXT 30319] Predicted next UID.
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=31 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * OK [HIGHESTMODSEQ 16017829]
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=76 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 20 OK [READ-WRITE] mailing lists/linux-arm selected. (Success) [THROTTLED]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 21 getquotaroot "mailing lists/linux-arm"
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=42 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * QUOTAROOT "mailing lists/linux-arm" ""
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=39 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * QUOTA "" (STORAGE 1863907 31457280)
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 21 OK Success [THROTTLED]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 22 UID fetch 1:* (FLAGS)
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=33 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 1 FETCH (UID 1 FLAGS (\Seen))
  ........
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30312 FETCH (UID 30316 FLAGS ())
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30313 FETCH (UID 30317 FLAGS ())
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=36 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 FETCH (UID 30318 FLAGS ())
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 22 OK Success [THROTTLED]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:SendData: 23 UID fetch 30318 (UID X-GM-MSGID X-GM-THRID X-GM-LABELS RFC822.SIZE FLAGS BODY.PEEK[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To X-Mailing-List X-List-Name List-Id)])
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=334 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: * 30314 FETCH (X-GM-THRID 1491831819459052696 X-GM-MSGID 1494202989826800755 X-GM-LABELS ("mailing lists/dri-devel") UID 30318 RFC822.SIZE 18337 FLAGS () BODY[HEADER.FIELDS (From To Cc Bcc Subject Date Message-ID Priority X-Priority References Newsgroups In-Reply-To Content-Type Reply-To X-Mailing-List X-List-Name List-Id)] {1075}
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:STREAM:OPEN Size: 18337: Begin Message Download Stream
  ..............
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: )
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:STREAM:CLOSE: Normal Message End Download Stream
  1766131456[7fb45d732580]: ReadNextLine [stream=3ee29f80 nb=27 needmore=0]
  1766131456[7fb45d732580]: 547f2800:imap.gmail.com:S-mailing lists/linux-arm:CreateNewLineFromSocket: 23 OK Success [THROTTLED]
  -1906690176[7fb48d217580]: proposed url = mailing lists/linux-arm folder for connection mailing lists/linux-arm has To Wait = TRUE can run = FALSE
  -1906690176[7fb48d217580]: queuing url:imap://peter@xxxxxxxxxxxxxxxxxx@imap.gmail.com:993/fetch>UID>/mailing lists/linux-arm>30318?header=filter&emitter=js&fetchCompleteMessage=false

  
  Note that after receiving the "22 OK Success" reply for "22 UID fetch 1:* (FLAGS)", TB only fetched UID 30138 (even though there were actually 12 emails without the Seen flag) and then after receiving the message successfully, queued a url fetch _for the exact same message_!

  The "emitter=js" got me thinking that there was some Javascript
  running, which led me to disabling the only Extension installed,  the
  Messaging Menu and Unity Launcher integration.

  Restarted TB and voila -- no more endless updates.

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/thunderbird/+bug/1426174/+subscriptions


Follow ups

References