Eray Aslan put forth on 5/7/2010 12:44 AM:

On Fri, May 07, 2010 at 12:02:33AM -0500, Stan Hoeppner wrote:

...

Anyone have any ideas? Other than switching to LDA+sieve and have TB check the IMAP folders for new mail?

Try turning off indexing on Thunderbird.

The TB indexing isn't slow. Downloading the message headers is slow.

-- Stan

On 5/7/2010 7:00 AM, Stan Hoeppner wrote:

Charles Marcus put forth on 5/7/2010 5:29 AM:

...

On 2010-05-07 1:02 AM, Stan Hoeppner wrote:

...

I know TBird isn't the greatest IMAP client around,

Actually, its better than most (at least those with a decent GUI)...

...

but I think taking over 60 seconds just to download ~300 messages is way too damn long given the hardware resources, network, and load on the client and server machines.

There is definitely something wrong.

I agree.

...

Do you store your profile on a remote filesystem? There is a known major TB bug that causes it to be dog slow if your profile is not on a local hard drive. It is apparently fixed for 3.1, and I think it even made it into the 3.1b2 that was just released, so you might give it a try if your profile is on a remote filesystem.

The profiles are on the local machine, which is W2K Pro SP4 all M$ patches via auto updates, Win32 TB 3.0.4, Athlon XP 2GHz, 1GB dual channel RAM, 7.2K rpm 120GB Seagate UDMA100.

Maybe some a/v scanning your mail? If so, try turning it off, or switching TB to port 993 (and enable imaps in dovecot).

Ken

The server is an old dual CPU 500MHz Intel box

with 384MB PC100, a new 500GB 7.2K rpm single platter WD Blue SATA drive on a new SiI 3512 card, Intel Pro 100 NIC, Debian Lenny 5.0.4 with custom rolled 2.6.32.9 from kernel.org source, Dovecot 1.2.11 from Lenny backports. For practical purposes, this is a personal server with only a single IMAP client, load average: 0.01, 0.06, 0.03. The only real load it gets is an occasional kernel make, or processing a batch of digital camera photos with imagemagick and curator.

I tested out Outlook Express 6.0, which I've never used before, but was already on the machine as part of W2K. There were only a couple of new messages to grab so I couldn't test new message retrieval speed. However, when I clicked on a couple of IMAP folders containing over 11,000 messages each, they transferred in about 15 seconds per folder. It was freak'n fast. I was pleasantly surprised. Granted this wasn't an apples to apples test.

...

...

TB basically seems to be pulling, or dovecot serving, only about 5 messages/sec over 100Mb ethernet, which is abysmal performance given neither the server nor client have any load. The messages are mostly list mail which are at max a few kilobytes each.

I'm leaning toward a problem with TBird but I've been unable to find a bug report that covers this, nor a forum post anywhere, etc. The closest I've found for "slow startup" are recommendations to compact folders. I have no local folders to compact. I delete immediately and expunge on exit.

Ummm... compacting has nothing to do with 'Local Folders', it has to do with the local mbox files that are used to store the message headers (and bodies of downloaded messages) - and simply expunging is *not* enough. You need to either manually compact them every now and then, or set it to automatically compact regularly.

There are no local mbox files. Those are only created if one sets TB to synchronize IMAP folders to the local drive for offline use, which I do _NOT_ do. That defeats the whole purpose of having a nearby (network latency and b/w wise) fast IMAP server. If I wanted copies of all my mail on my workstation I'd run POP. But I don't. Thus, I don't synchronize.

The only noteworthy TB files I have locally are .msf files in the ~\Application Data\~\ImapMail directory, one per IMAP folder on the server. AFAIK these are the index files TB creates of the message headers it d/l's from the IMAP server. I also have a couple of cache files in the other TB profile directory ~\Local Settings\~\Cache that are rather large, one being ~50MB, the other being ~30MB, both with a current timestamp, meaning both are actively being used. AIUI, compacting folders in TB only affects local mbox files, removing deleted messages, and rewriting the file to eliminate whitespace. In absence of this, I defrag both partitions on my workstation disk frequently. Even after a fresh thorough defrag, this TB startup performance problem still exists. AFAIK, Dovecot does something similar to TB compacting automatically on its mbox files upon expunge.

Regardless of all the mbox and compacting talk, why would this ever affect new message headers being served up to TB by dovecot from the /var/mail/stan file? Every time I exit TB /var/mail/stan gets automatically compacted by dovecot. When I open TB the next time, and there are 300 messages, dovecot reads the partial headers and funnels them to TB. Correct? It seems TB then spins at 100% CPU for 60+ seconds saying "Downloading header x of 300". When it hits ~300, then there is finally network activity as TB seems to sort the messages into the proper IMAP folders, which is lightning quick compared to "downloading message headers".

I don't recall having this performance issue with dovecot 1.0.15. Just in case it's something I nurfed in my dovecot config, here's my dovecot -n output. Keep in mind I've made modifications appropriate for serving a single or just a couple of clients while attempting to cut resources consumed to the bare minimum while maintaining performance.

Thanks for the interest and help Charles. The cause is probably something stupid I did in an effort to optimize. Or something I did that the TB developers never actually expected someone to do, but didn't bother documenting that one shouldn't do it.

# 1.2.11: /etc/dovecot/dovecot.conf # OS: Linux 2.6.32.9 i686 Debian 5.0.4 log_timestamp: %Y-%m-%d %H:%M:%S protocols: imap disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable: /usr/lib/dovecot/imap-login login_process_per_connection: no login_process_size: 16 login_processes_count: 1 login_max_processes_count: 1 login_max_connections: 8 max_mail_processes: 4 mail_privileged_group: mail mailbox_idle_check_interval: 15 mbox_write_locks: fcntl mbox_min_index_size: 2048 mbox_lazy_writes: no mail_process_size: 192 mail_plugins: fts fts_squat imap_client_workarounds: tb-extra-mailbox-sep auth default: worker_max_count: 1 process_size: 16 passdb: driver: pam args: max_requests=1 userdb: driver: passwd plugin: fts: squat fts_squat: partial=4 full=10

-- Ken Anderson Pacific Internet - http://www.pacific.net

Charles Marcus put forth on 5/7/2010 9:28 AM:

On 2010-05-07 8:00 AM, Stan Hoeppner wrote:

...

It seems TB then spins at 100% CPU for 60+ seconds saying "Downloading header x of 300". When it hits ~300, then there is finally network activity as TB seems to sort the messages into the proper IMAP folders, which is lightning quick compared to "downloading message headers".

The only other thing I can think of is some kind of AV on the local computer, but it seems like that would affect OE too - unless you had configured it to not scan OE connections...

I don't use any A/V plugin in TB, and TB is what is using 100% CPU while downloading the new message headers. All other processes are at 0% CPU. The only other non Windows processes running all the time are the Sun Java Quick starter and Java update scheduler.

...

I don't recall having this performance issue with dovecot 1.0.15. Just in case it's something I nurfed in my dovecot config, here's my dovecot -n output.

It would be good if you could confirm this, but, I think that if its a config issue, its more likely a TB config issue (especially since OE seems to not have a problem) - too bad TB doesn't have a way to dump the config changes like dovecot/postfix...

Yeah, that would be nice. The config editor does highlight all user defined settings in bold though.

Did you make any manual config changes to TB using about:config or applying manual changes to user.js?

The only TB change I recall making via about:config was to disable condstore. Since updating to 1.2.11, which fixes condstore support, I reenabled it.

That said, I've made a number of about:config changes in Firefox, which, IIRC, shares config info with TB. However, the about:config changes I've made to FF are all http tweaks, such as pipelining, etc, which shouldn't affect TB. I do have the TB CompactHeader and Enigmail plugins installed, but I wouldn't think these would cause this slow header download issue, as they deal with display. AFAIK they aren't in play during new message header downloads.

-- Stan

Charles Marcus put forth on 5/7/2010 11:58 AM:

On 2010-05-07 11:44 AM, Stan Hoeppner wrote:

...

That said, I've made a number of about:config changes in Firefox, which, IIRC, shares config info with TB. However, the about:config changes I've made to FF are all http tweaks, such as pipelining, etc, which shouldn't affect TB.

Actually, I seem to recall reading something somewhere that they can/do...

You might try reverting those and restarting and see if it makes any difference...

...

I do have the TB CompactHeader and Enigmail plugins installed, but I wouldn't think these would cause this slow header download issue, as they deal with display. AFAIK they aren't in play during new message header downloads.

I have them both installed too, so if they are the cause, it would be in combination with something else specific to your installation.

Sorry, I'm out of ideas... hope you can get it sorted...

I did quite a bit more searching, and though I found nothing specifically linking GLODA to my issues, I disabled it, along with some likely minor other things. For some reason it was enabled by default on my system even though the mozilla docs say it comes disabled by default. Maybe because I was an upgrade instead of a fresh install? Anyway...

I built a fresh TB account profile under a different windows user login (took longer than I'd have liked) and the performance I used to know was fully restored. It was pulling the headers from my 11,000+ message imap folders in less than 10 seconds with this fresh profile.

So, I logged back in under my normal account (I had disabled GLODA before logoff) and I moved the .msf files, the sqlite file, and some other index related stuff to a temp folder. Since I'd moved my rules file nothing got sorted when I fired up TB, but the download of new message headers was faster than I've seen in a long while. I still need to perform an "overnight" test to see if it's speedy with 100+ new messages.

So, preliminarily, it would seem that GLODA and its 50MB+ Sqlite file were mostly to blame. I should have dug deeper into TB before ever bringing this up here. Until today I didn't even realize GLODA was enabled...

I'll post more when I have info on the use case that prompted this thread.

-- Stan

Charles Marcus put forth on 5/7/2010 2:32 PM:

On 2010-05-07 2:55 PM, Stan Hoeppner wrote:

...

I did quite a bit more searching, and though I found nothing specifically linking GLODA to my issues, I disabled it, along with some likely minor other things. For some reason it was enabled by default on my system even though the mozilla docs say it comes disabled by default.

Not sure where you read that, but as far as I know, it has always been enabled by default. In fact there are a couple of bugs about this that I've been very vocal on complaining about this dumb decision of theirs.

Enabling GLODA, forcing all IMAP folders to offline mode (I have 16+ IMAP accounts, and I was *furious* when I learned they stomped on all of my settings like that) *and* enabling Sync all messages for *all* IMAP accounts by default were extraordinarily arrogant and dumb decisions, in my opinion (and I had no qualms with telling them so).

As far as I know, they have not changed this in any of the 3.0.x builds, and said as much in the open bugs...

According to this page found via Google it's disabled by default: https://wiki.mozilla.org/Thunderbird:Using_Gloda

The page last update is listed as 7 March 2009. I'm not sure which version was current at that time. But obviously it was disabled by default at one point. That may have changed. I didn't see it in the 3.0.4 release notes. I may have manually enabled it long ago, not realizing the possible repercussions, and then forgot I enabled it. Like I said, I don't think I did, but it's possible.

-- Stan

Charles Marcus put forth on 5/7/2010 9:36 PM:

On 5/7/2010 5:55 PM, Stan Hoeppner wrote:

...

According to this page found via Google it's disabled by default: https://wiki.mozilla.org/Thunderbird:Using_Gloda

The page last update is listed as 7 March 2009. I'm not sure which version was current at that time. But obviously it was disabled by default at one point. That may have changed. I didn't see it in the 3.0.4 release notes. I may have manually enabled it long ago, not realizing the possible repercussions, and then forgot I enabled it. Like I said, I don't think I did, but it's possible.

Nope - it is definitely enabled by default - that page is outdated/wrong.

Believe me - there were a lot of complaints about it, mine especially.

Understood Charles. I didn't think I had enabled it manually, and this tends to confirm that.

Unfortunately the problem I originally described in this thread still isn't solved. When I just sat down and fired up Tbird I had 125 new messages. Tbird once again demonstrated the slow "loading" behavior. It took about 20 seconds to pull these 125 new messages. As I said previously, it took about 1 minute to pull 300 the other day. But with GLODA now disabled, the sorting into my imap folders was near instantaneous, whereas before it took a little bit longer to sort them.

What is so darn strange is that after I deleted all the index and cache from my Tbird profile yesterday, Tbird downloaded the 11,000+ headers from my debian-users and spam-l dovecot imap folders in about 15 each seconds. Yet it takes 20 seconds to grab headers of 125 new messages? The math doesn't work out.

AFAIK, the only difference between the two scenarios is that new messages are stored in /var/mail and already existing messages are stored in /home/stan/mail. AFAIK, new message header info for those in /var/mail isn't indexed by dovecot until after a request by the client. When the client requests headers from mail in other imap folders, dovecot grabs those headers from its index files, which should be quicker, though I don't know how much quicker it should be.

So the question is, is this slow loading of new messages in Tbird a problem with Tbird itself, or is there a dovecot component to this slowness? In other words, is dovecot lagging in grabbing the header information from new messages in /var/mail since they haven't been indexed yet?

If this is the case, if I switch from having Postfix do local delivery to /var/mail to having Postfix use dovecot LDA, what other changes would I need to make? Would I still be able to sort new messages with Tbird filter rules? What directory would dovecot LDA drop the new messages into? Would I need to make name space changes? I've never actually done anything manually with name spaces. I let dovecot figure it out automagically.

Thanks for the interest in my topic. I know it's not a very interesting one since apparently I'm the only one on the planet experiencing this.

-- Stan

Greetings Patrick, fellow Postfix user, and Postfix author.

Patrick Ben Koetter put forth on 5/8/2010 5:04 PM:

• Stan Hoeppner stan@hardwarefreak.com:

...

If this is the case, if I switch from having Postfix do local delivery to /var/mail to having Postfix use dovecot LDA, what other changes would I need

http://wiki.dovecot.org/LDA/Postfix

...

to make? Would I still be able to sort new messages with Tbird filter

Sure. Tbird filter rules are local, client rules run on your computer and not on the mailserver.

I should have worded that question better. What I was trying to ask is that, if using dovecot LDA, if new messages would still be presented to Tbird in the INBOX imap folder. If LDA dropped new messages into a different imap folder then Tbird wouldn't see them in the INBOX, and that's where all my filter rules apply. Looking back this was probably a dumb question. I asked it because I'm totally unfamiliar with LDA. I'll be reading up on it.

...

rules? What directory would dovecot LDA drop the new messages into? Would

Dovecot deliver will put messages into the same place where Postfix local puts them now.

Got it. That's good to know.

...

I need to make name space changes? I've never actually done anything

Nope, deliver replaces Postfix local LDA transparently.

Good. Fantastic, actually.

...

manually with name spaces. I let dovecot figure it out automagically.

Thanks for the interest in my topic. I know it's not a very interesting one since apparently I'm the only one on the planet experiencing this.

Putting 40k+ messages - IIRC you wrote that - into a single mailbox is not unusual allthough I hardly now any postmaster who recommends that.

The total is somewhere around there, and growing daily due to list mail. I'm not sure of your definition of "single mailbox" here. Yes, the messages are all in the same UNIX user account, but the messages are spread across a number of mbox files, not a single file. I have ~12,000 messages in each of two mbox files, ~5,000 in another, a couple with ~3,000, and a number with less than 1,000. Dovecot handles all of these quickly and easily, with low memory consumption. Searching the large mbox files is quick when the squat indexes aren't stale. Mailbox size, individual mbox size, don't seem to be a performance factor. My only performance problem is related to the INBOX, which usually has less than 150 messages in it. Tbird loads those 150-300 headers from the INBOX folder slower than it loads 12,000+ headers from the debian-users folder or spam-l folder.

At this point I'm assuming the problem has to lie with Tbird, as dovecot should be performing the same regardless of folder size or location on disk, *UNLESS* dovecot hasn't already indexed /var/mail/%user when the client connects. I don't know how dovecot handles indexing of /var/mail/%user files, or more importantly, I don't know *when* dovecot indexes those files. If they aren't indexed before the client connects and requests the contents of INBOX, I can see there being a performance drop, although I wouldn't think it would be great enough to cause a ~20 second delay for 125 messages or 60 seconds for ~300 messages.

Having no index on 40k messages means the mail server needs to scan the directory any time a mail client accesses the mailbox. This takes time and might explain the delay you experience.

Whoa. We've had a major disconnect somewhere in the conversation. I'm not lacking indexes on 40k messages. They're all well indexed by dovecot. Some have multiple indexes due to squat. Performance while accessing any of those 40k is fast as lightning. Again, the performance problem I have is _strictly with new messages in the INBOX folder_. More precisely, Tbird pulling the headers for new messages. IFAIK, Tbird only pulls the headers, not the entire message. It only pulls the entire message when you open/access it.

Dovecots ability always to provide an up to date if you use its LDA deliver was one of the major reasons to use Dovecot for me. We had a non-Dovecot IMAP server with a load of 60. It went down to 2 the day we began to use Dovecot with deliver AND access to messages became faster.

I agree. Dovecot rocks. And it's probably not at fault WRT my current performance issue. I'm just asking the question in the off chance that my performance issue WRT INBOX is due to something I may have screwed up in my dovecot config or setup, or maybe...

Timo identified a bug related to processing of mbox files that was to have been fixed in 1.2.11. I don't think my current issue is related. But, I get the feeling that mbox code paths have taken a back seat to maildir and other code paths through the last few release cycles due to the popularity of the latter and the declining popularity of the former. I am one of the users who helped Timo identify that mbox bug merely by observation here. It's always within the realm of possibility that I've run into another less than optimal code path. Like I sad, it's probably a Tbird issue, but it can't hurt to ask here just in case there might be a dovecot issue in play as well. It could be a problem with both code sets, Tbird and Dovecot, that only surfaces when using both together.

It's an odd obscure "mild" performance problem that just shouldn't exist. I can't find it documented anywhere, nothing like it shows up searching Google. I thought it was related to Tbird's GLODA, but after disabled that and scrubbing all the Tbird cache and index files, the problem still exists. Again, only for INBOX, but not for any other imap folders.

It's frustrating trying to solve this, to say the least. :( I don't have enough in depth knowledge of either application to figure this out on my own. It seems the only way to communicate with the Tbird devs is via bug reports. I can't really file a Tbird bug report as I just don't have enough information available to file one that they can do anything with.

-- Stan

On 2010-05-10 6:06 AM, Charles Marcus wrote:

On 2010-05-09 2:54 AM, Stan Hoeppner wrote:

...

It's frustrating trying to solve this, to say the least. :( I don't have enough in depth knowledge of either application to figure this out on my own.

Hey Stan,

Sorry I can't offer any more help, other than to ask - have you seen/used the troubleshooting techniques available for Thunderbird as described here?

http://wiki.dovecot.org/Debugging/Thunderbird?highlight=%28thunderbird%29|%28log%29

Please do post back if you are ever able to solve this...

Oh - and here:

http://wiki.dovecot.org/Debugging/Rawlog

--

Best regards,

Charles

On 2010-05-10 8:48 AM, Stan Hoeppner wrote:

I'm thinking at this point that the cause of the problem is that I probably use Tbird in a way/methodology that the Tbird devs never anticipated, or discourages. It's seems clear, unfortunately, that their entire mindset is based on a FAT client that caches, indexes, and syncs all messages locally.

What is Tools > Options > Disk Space > Cache set to? I guess it is possible that if you set the cache too low it might cause problems...

Also, for Tools > Account Settings > Synchronization & Storage, have you told TBird to delete any messages under the 'To recover disk space ...' section?

--

Best regards,

Charles

On 2010-05-10 9:44 AM, Stan Hoeppner wrote:

Charles Marcus put forth on 5/10/2010 8:26 AM:

...

Also, for Tools > Account Settings > Synchronization & Storage, have you told TBird to delete any messages under the 'To recover disk space ...' section?

I don't sync messages, so this setting is ignored.

Are you sure (I'm sincerely asking as I don't know)?

Hmmm... Ok, I just re-read the message where you said that you keep your Inbox small (rarely has more than a few hundred messages in it), so what I was thinking - if you have a large number of messages in your Inbox, maybe it is having to parse all of them each time you access the Inbox to see what messages might need to be deleted - was totally irrelevant.

The only other thing I can think of now is:

AFAIK, the only difference between the two scenarios is that new messages are stored in /var/mail and already existing messages are stored in /home/stan/mail.

Maybe its a filesystem issue - what filesystems are used for /var/mail and /home/stan/mail?

--

Best regards,

Charles

Timo Sirainen put forth on 5/22/2010 3:47 AM:

On 9.5.2010, at 9.54, Stan Hoeppner wrote:

...

It's frustrating trying to solve this, to say the least. :( I don't have enough in depth knowledge of either application to figure this out on my own. It seems the only way to communicate with the Tbird devs is via bug reports. I can't really file a Tbird bug report as I just don't have enough information available to file one that they can do anything with.

If you didn't solve it yet .. the way I normally try to figure out why something is taking 100% CPU load is attaching gdb to the process and getting a backtrace. I don't know if there's an easy way to do that with Windows, but if you can manage to do that a few times for a build with debug symbols enabled, it could be enough for developers to figure out what the problem is.

I turned every related knob I could find in about:config and couldn't fix it. And since I use Roundcube now and then I've been wanting to do server side sorting anyway. So, instead of attempting any kind of tracing of TBird, I switched to LDA, wrote a sieve script, and set TBird to check for new mail in IMAP folders. Afterward, when I'd click on an IMAP folder containing new mail, small folders would respond instantly displaying the new mail and the old already cached mails. On large folders (around 3000+ messages and up) it would display the old cached mails instantly, but it would take a few seconds to show the new messages, up to 10 seconds for folders containing 10k+ messages. This didn't really make sense to me as I thought Dovecot's index architecture would work faster.

Upon investigating this issue, I found that the imap process was spinning at 100% CPU until TBird displayed the new messages. As a test I deleted all the messages in my debian-users list mail folder which was at 13k+ messages. I rarely if ever searched it and there is a public archive, so I just whacked it. After doing so, upon opening the folder which would have say, 80 new messages in it, the imap process ran 100% CPU for a second or less, and all the new messages displayed pretty much instantly.

This led me to do more testing, and it basically appears that on my server, there is a linear relationship between mailbox (and thus index.cache) size and response time, regardless of how many new messages are in the imap folder (mbox file). Given that TBird caches all message headers, even when not using gloda, when it asks Dovecot for new mail in a folder, Dovecot would simply respond by sending new mail headers. Maybe this is exactly what Dovecot does. But apparently it's reading a lot more from the cache file or the mailbox file, as it takes forever to respond if the mbox file (imap folder) and respective index.cache file is large.

I've since thinned out most of my list mail folders that were 3000-10000+ messages. All of my folders are at less than 1,000 messages now except for my spam-l folder which is 13,200 messages. All folders respond instantly now when I select them regardless of the number of new messages, _except_ the spam-l folder. It can have one new message in it or 100 new messages, either way, it takes almost exactly 10 seconds for TBird to display the folder contents and the Dovecot imap process runs 100% CPU for that 10 seconds. If there are no new messages, the folder displays instantly. The dovecot.index.cache file is 30MB. The mbox file is 57MB. Apparently Dovecot is reading more than just the new message headers?

-- Stan