Closed Bug 666765 Opened 13 years ago Closed 13 years ago

TB is not robust on slow IMAP server: unable to delete the contents of Trash in IMAP folder, doesn't show status, doesn't restore connections right away

Categories

(Thunderbird :: Folder and Message Lists, defect)

x86_64
FreeBSD
defect
Not set
major

Tracking

(Not tracked)

RESOLVED INCOMPLETE

People

(Reporter: yuri, Unassigned)

Details

(Whiteboard: [closeme 2011-12-15][has protocol logs:reviewed])

User-Agent:       Mozilla/5.0 (X11; FreeBSD amd64; rv:2.0.1) Gecko/20100101 Firefox/4.0.1
Build Identifier: 

I happen to have a huge Trash folder with over 22666 messages.
When I select the commend "Empty Trash" messages first disappear from the screen, but later they reappear again. No error message is displayed (!), they just reappear.

First, status says:
Deleted folder Trash.
And later status says:
Downloading message header XXX of 22666

It should be very easy to delete messages on IMAP server.

Reproducible: Always
thunderbird-3.0.11
this would be an issue with your imap server - an IMAP protocol log would probably help you pinpoint what's going wrong on the server - https://wiki.mozilla.org/MailNews:Logging
Instructions there read:
export NSPR_LOG_MODULES=imap:5
export NSPR_LOG_FILE=/tmp/imap.log


I did that, it created an empty /tmp/imap.log after thunderbird finished.
What am I missing?
did you run thunderbird from the shell where you set the env vars?
Another side effect of that is that INBOX.sbd grows huge over time. Mine was 36GB, and it grew 1.6 GB just overnight. And Trash is the largest file there.
Yes, from the shell
You are using IMAP, right? I don't know for your particular setup how to set the environment variables. Since it created an empty log, it sounds like at least the log file var was set correctly.
http://email.about.com/od/mozillathunderbirdtips/qt/et_mail_log.htm says also suggests the same env variable. Looks like logging is broken.
Logging works fine for everyone else so I suspect it's something on your end.
I notified FreeBSD port maintainer that imap protocol log doesn't work.

I am trying to use the third part logger instead (IMAP proxy http://www.aboutmyip.com/AboutMyXApp/ImapProxy.jsp).

It periodically says that connection is terminated. Unfortunately it's not obvious from the log file on which side, server or client. And TB just keeps reconnecting and fetching the contents of this folder forever.

If the user says: Empty Trash, why TB keeps fetching? No matter what is the original problem in my case, this behavior of TB is wrong. It shouldn't just keep fetching. If for whatever reason it can't delete trash, it should tell user in the popup message "Unable to delete trash: Server error ...". It shouldn't just keep fetching anyways.
Another observation: TB keeps "busy" cursor, but there is no status message.
Every time when the cursor is "busy", status message should show what is going on with the current folder.
Below is the fragment from the IMAP log.
You can see 2 connection terminations.
After the second termination TB doesn't even try to reestablish connection and is saying 'Sending login information' in status. This behavior is also wrong.
Still not clear which side terminates connections.

--- log fragment ---
<...>
6/23/11 7:17 PM - [         6] S <-- References: <AANLkTimOff-yQNJ=hvD+fC4gpuvq7qQYC-r2-eikzuZU@mail.gmail.com> <20101209065216.2wqjbjiia884kgoc@webmail.opentransfer.com> <AANLkTin+28wbEPaHK-1Ktf_JLHnKbpJqm59by52OcE9u@mail.gmail.com> <20101218220058.rhtoxocio00cgwgw@webmail.opentransfer.com> <AANLkTinBhKLvpQVPynuODMJqYTjXngHkSA3bkkmPjqEB@mail.gmail.com>

6/23/11 7:17 PM - [         6] S <-- In-Reply-To: <AANLkTinBhKLvpQVPynuODMJqYTjXngHkSA3bkkmPjqEB@mail.gmail.com>

6/23/11 7:17 PM - [         6] **** CONNECTION TERMINATED in 960017 ms. Error = Broken pipe

6/23/11 7:32 PM - [        -1] S <-- * OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE STARTTLS] Courier-IMAP ready. Copyright 1998-2005 Double Precision, Inc.  See COPYING for distribution information.

6/23/11 7:32 PM - [         8] **** NEW CONNECTION (127.0.0.1)

6/23/11 7:32 PM - [         8] C --> 1 login "xxx@xxx.org" "xxx"

6/23/11 7:34 PM - [         8] S <-- 1 OK LOGIN Ok.

6/23/11 7:34 PM - [         8] **** CONNECTION TERMINATED in 117500 ms. Error = Connection reset

<...long delay here without any motion, TB still says 'Sending login information' ...>
Whiteboard: [has protocol logs]
So I had to delete those messages manually pasting thousands IMAP commands into telnet, like this:
1 store 1 +flags.silent (\Seen \Deleted)
1 store 2 +flags.silent (\Seen \Deleted)
1 store 3 +flags.silent (\Seen \Deleted)
....
1 EXPUNGE

My conclusion: e-mail server probably malfunctions and is very slow and keeps breaking connections. But TB behavior in response is also unreasonable.

Here are my suggestions:

*** Empty Trash operation ***
In the situation when the user says "Empty Trash" TB should stop fetching, and should do this:
1 EXAMINE INBOX.Trash
1 SELECT INBOX.Trash
1 STORE 1 +flags.silent (\Seen \Deleted)
...
1 STORE <number of messages reported by EXAMINE> (\Seen \Deleted)
1 EXPUNGE

*** Status is not shown ***
Additionally, when user clicks on any folder, status bar should show the status for this folder. Now status is often empty in case of slow IMAP server. Especially when the cursor is "busy" sometimes there is no status message, this doesn't make sense.

*** Broken connections not restored ***
When connection is broken during some operation, TB should attempt reconnection right away. I observed that TB sometimes didn't even try to reconnect, see protocol log above.
Summary: Unable to delete the contents of Trash in IMAP folder → TB is not robust on slow IMAP server: unable to delete the contents of Trash in IMAP folder, doesn't show status, doesn't restore connections
Summary: TB is not robust on slow IMAP server: unable to delete the contents of Trash in IMAP folder, doesn't show status, doesn't restore connections → TB is not robust on slow IMAP server: unable to delete the contents of Trash in IMAP folder, doesn't show status, doesn't restore connections right away
You've got a courier server, which is notorious for only allowing four connections per IP address, in some configurations. You can tell TB to only cache four connections in account settings, server settings, advanced button.

We do try to reconnect, but it's not going to work if the server rejects our connection.

We store 1:* flags.silent  \DELETED - we're not going to do it one message at a time, which seems to be what you were suggesting, though I've probably misunderstood.
1:* flags.silent  \DELETED works.
So you should

1 EXAMINE INBOX.Trash
1 SELECT INBOX.Trash
1:* +flags.silent (\Seen \Deleted)
1 EXPUNGE

instead of fetching.
Server doesn't reject connections, I think it drops them randomly after some activity or maybe crashes due to misconfiguration or maybe due to the high message count or high server load.

My suggestion is to improve robustness in such case and do Empty Trash in a short way.
that IS what we do with normal servers. Your server is dropping the connection at an inopportune time. Did you try changing the cache limit?
> that IS what we do with normal servers. Your server is dropping the connection at an inopportune time. Did you try changing the cache limit?

This is not what I observer looking at traffic. TB kept fetching while I was telling it to Empty Trash.
Yuri, Did you try changing the cache limit?
Whiteboard: [has protocol logs] → [closeme 2011-12-15][has protocol logs:reviewed]
Status: UNCONFIRMED → RESOLVED
Closed: 13 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.