[Dovecot] index file vs. memory
Hello,
we have a large base of mailbox users and while pop3-connections are usually closed after the download of all mails, I noticed hundrets of imap-connections kept idle by the users. This is surely according to the idea behind imap, but I'm a bit afraid of overwhelming memory consumption if there are too many imap-connections opened at the same time. Is the index file kept in memory as long as an imap-connection exists, or is it closed as soon as a certain read or write command has finished?
Regards Marten
Am Freitag, 17. Februar 2006 20:49, schrieb Marten Lehmann:
time. Is the index file kept in memory as long as an imap-connection exists, or is it closed as soon as a certain read or write command has finished?
That imap process' memory usage will grow and shrink over time, but I observed (on my small single-user box) imap processes consuming several dozend MB virtual memory sitting around for extended periods of time...
No idea if dovecot can somehow be taught to free it up again as soon as possible or if it does not seem to be needed at the moment any more...
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 22:31 | Tristania - Equilibrium 22:17 | Tristania - Libre 22:13 | Sirenia - In Sumerian Haze 22:07 | Sirenia - A Shadow Of Your Own Self *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On Fri, 2006-02-17 at 22:55 +0100, Gunter Ohrner wrote:
Am Freitag, 17. Februar 2006 20:49, schrieb Marten Lehmann:
time. Is the index file kept in memory as long as an imap-connection exists, or is it closed as soon as a certain read or write command has finished?
That imap process' memory usage will grow and shrink over time, but I observed (on my small single-user box) imap processes consuming several dozend MB virtual memory sitting around for extended periods of time...
No idea if dovecot can somehow be taught to free it up again as soon as possible or if it does not seem to be needed at the moment any more...
I've also noticed that after several days Dovecot eats much more memory than it should. So I suppose there's a leak somewhere. I should try to debug this some day, but since my main mails are in Solaris server, I can't use Valgrind there and I can't really think of any better ways to debug it easily..
You could also check if it's really heap that's eating the memory or if it's just mmaped index files. If you're running Linux, could you do cat /proc/<imap process pid>/maps and show me what it says?
Am Montag, 20. Februar 2006 18:01, schrieb Timo Sirainen:
You could also check if it's really heap that's eating the memory or if it's just mmaped index files. If you're running Linux, could you do cat /proc/<imap process pid>/maps and show me what it says?
I attached some information. (I attached it here, cause it does not show the excessive memory consumption I experience if deleting something, but dovecot's normal day-to-day memory usage I observe.)
I did not copy larger amounts of messages in this case or do anything unsusual.
There is no /proc/PID/smaps-file generated by the kernel I use (2.4 series), but I attached /proc/PID/status as it also looked as if might be interesting.
I'll attach logs of a 200MB+ sized dovecot to the other thread as soon as I prepared a suitable test, currently kMail is giving me headaches with that...
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 11:38 | Theatre of Tragedy - Machine (VNV Nation remix) 11:21 | Dark Noize - Your Only Motions (Single Mix) 11:13 | Ace's Delight - Mental Theme (Ultra Trance Mix 11:10 | Harald Kloser - Techno Download *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
Am Montag, 20. Februar 2006 18:01, schrieb Timo Sirainen:
You could also check if it's really heap that's eating the memory or if it's just mmaped index files. If you're running Linux, could you do cat /proc/<imap process pid>/maps and show me what it says?
Ok, second test:
I started kMail (and thus a new imap process) and moved a few thousand (a bit more than a total of 10,000) mails from one folder to another, moving them in several chunks of about 1000 to 3000 mails each. (kMail bailed out when I tried to move > 10,000 mails at a time ;)
test2 contains the status information after moving of the messages but when the source folder was still selected in kMails GUI.
test3 shows the situation immediately after that, after selecting the INBOX inside kMail.
HTH,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 16:46 | Within Temptation - Candles 16:41 | Within Temptation - Mother Earth 16:36 | Within Temptation - Jane Doe 16:31 | Within Temptation - Pale *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On Tue, 2006-02-21 at 16:58 +0100, Gunter Ohrner wrote:
You could also check if it's really heap that's eating the memory or if it's just mmaped index files. If you're running Linux, could you do cat /proc/<imap process pid>/maps and show me what it says?
Ok, second test:
[...]
It's just mmapped files: 20426 gunter 9 0 185m 15m 960 S 0.2 26.1 68:21.00 imap
See, it's only using 15m real memory, the rest (170m) is virtual -- mmap()ed files.
So what's the problem?
johannes
Am Dienstag, 21. Februar 2006 17:14, schrieb Johannes Berg:
It's just mmapped files: 20426 gunter 9 0 185m 15m 960 S 0.2 26.1 68:21.00 imap See, it's only using 15m real memory, the rest (170m) is virtual -- mmap()ed files.
No, it was paging madly, the box has only 64 MB physical RAM, so it has no choice but to start trashing if a process grows like this.
In "test2" the RSS is 25 MB, which is about the maximum a single process can get, there's always a bit cached and buffered, besides the other processes.
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 20:05 | Therion - Enter Vril-Ya 19:08 | Therion - Seven Secrets of the Sphinx 19:03 | Therion - Sirius B 18:59 | Therion - Call of Dagon *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On Tue, 2006-02-21 at 16:58 +0100, Gunter Ohrner wrote:
Am Montag, 20. Februar 2006 18:01, schrieb Timo Sirainen:
You could also check if it's really heap that's eating the memory or if it's just mmaped index files. If you're running Linux, could you do cat /proc/<imap process pid>/maps and show me what it says?
Ok, second test:
I started kMail (and thus a new imap process) and moved a few thousand (a bit more than a total of 10,000) mails from one folder to another, moving them in several chunks of about 1000 to 3000 mails each. (kMail bailed out when I tried to move > 10,000 mails at a time ;)
You moved them to another IMAP folder, or a local folder?
Do the messages you're moving have any keywords set? eg. some Spam keyword? Some IMAP clients set them automatically.
test2 contains the status information after moving of the messages but when the source folder was still selected in kMails GUI.
One strange thing about it is that it has dovecot.index.cache file mmaped, but not dovecot.index file itself.
What settings have you changed in dovecot.conf? Do you have maildir_copy_with_hardlinks=yes?
Anyway it looks like the heap has grown about 200MB. It shouldn't be doing that.. I tried testing with Kmail v3.5.1 a bit but couldn't break it.
Am Dienstag, 21. Februar 2006 17:59, schrieb Timo Sirainen:
You moved them to another IMAP folder, or a local folder?
I moved them from one IMAP folder to a direct "neighbour folder".
Do the messages you're moving have any keywords set? eg. some Spam keyword? Some IMAP clients set them automatically.
Good question, how can I find out? I did not set any keyword manually and I do not know if kMail does it behind my back...
A ''find .Mailinglisten.Software.Linux.Kernel.* -iname "*keywords*"'' does not return anything.
It also happened with the "stable" release I had before, which even did not support keywords.
test2 contains the status information after moving of the messages but when the source folder was still selected in kMails GUI. What settings have you changed in dovecot.conf? Do you have maildir_copy_with_hardlinks=yes?
Yes.
I atteched my config. However I'm not aware that I'm doing anything paticularly special in my config - it's pretty standard, with one maildir per physical user, which is only one, currently...
Anyway it looks like the heap has grown about 200MB. It shouldn't be doing that.. I tried testing with Kmail v3.5.1 a bit but couldn't break it.
I just wonder what I'm doing wrong, or at least differently than anyone else... I never saw a report before and I do not only have these problems since yesterday... Maybe it's just because I'm running dovecot on such a weak machine and you won't notice it as much on a faster one with more RAM...
If I can do anything to help to debug it, just tell me!
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 20:11 | Therion - Ship of Luna 20:05 | Therion - Enter Vril-Ya 19:08 | Therion - Seven Secrets of the Sphinx 19:03 | Therion - Sirius B *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On Tue, 2006-02-21 at 20:36 +0100, Gunter Ohrner wrote:
Am Dienstag, 21. Februar 2006 17:59, schrieb Timo Sirainen:
You moved them to another IMAP folder, or a local folder?
I moved them from one IMAP folder to a direct "neighbour folder".
Do the messages you're moving have any keywords set? eg. some Spam keyword? Some IMAP clients set them automatically.
Good question, how can I find out? I did not set any keyword manually and I do not know if kMail does it behind my back...
A ''find .Mailinglisten.Software.Linux.Kernel.* -iname "*keywords*"'' does not return anything.
It's in maildir filename. a..z letters after "2," string in the base filename. For example "1059756594.2405.mbox:2,a" has "a" keyword. The "a" is mapped to the actual keyword name in dovecot-keywords file.
It also happened with the "stable" release I had before, which even did not support keywords.
Ok, so not that then.
Anyway it looks like the heap has grown about 200MB. It shouldn't be doing that.. I tried testing with Kmail v3.5.1 a bit but couldn't break it.
I just wonder what I'm doing wrong, or at least differently than anyone else... I never saw a report before and I do not only have these problems since yesterday... Maybe it's just because I'm running dovecot on such a weak machine and you won't notice it as much on a faster one with more RAM...
Since it's growing heap, the process size never goes down. And I've never noticed imap processes larger than 20MB or so (unless there have been many tens of thousands of mails).
If I can do anything to help to debug it, just tell me!
Could you try running some of the imap commands manually to see where exactly it grows the process size?
MAILDIR_COPY_WITH_HARDLINKS=1 MAIL=maildir:/var/maildir/user /usr/local/libexec/dovecot/imap x select mailbox x create tempbox x copy 1:* tempbox x select tempbox x store 1:* +flags \deleted x expunge
or instead of 1:* you could try something like 1:100,150:300,350:500
If none of those commands grow the memory usage, then answer these:
You said it happens while moving mails. Have you tried if it happens with only copying? Also does it matter what mailbox you're copying the mails to? Mostly that your destination mailbox isn't something with millions of messages, right? :)
Am Dienstag, 21. Februar 2006 21:29, schrieb Timo Sirainen:
Could you try running some of the imap commands manually to see where exactly it grows the process size?
Yes, I did.
If none of those commands grow the memory usage, then answer these:
The process size did only grow to about 22 MB...
Have you tried if it happens with only copying?
I just did, it also starts to eat mem...
Also does it matter what mailbox you're copying the mails to? Mostly that your destination mailbox isn't something with millions of messages, right? :)
No, the destination box was completely empty before I started to copy messages...
Tomorrow I'll switch of SSL and log the IMAP chatter between kMail and dovecot. That's slowly getting ridiculous...
However, I fear kMail may generate enormous IMAP commands while copying / deleting, as a selected block of messages in a sorted message list in kMail probably is some more or less random set of message numbers, right?
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 22:33 | Therion - Summernight City (Bonus) 22:28 | Therion - Crying Days (Bonus) 22:23 | Therion - Secret of the Runes 22:20 | Therion - Helheim *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On 2006-02-22 01:17:24 +0100, Gunter Ohrner wrote:
Tomorrow I'll switch of SSL and log the IMAP chatter between kMail and dovecot. That's slowly getting ridiculous...
you dont need to switch of ssl. use the rawlog feature of dovecot. see the config howto set that up.
hope this helps
darix-- openSUSE - SUSE Linux is my linux openSUSE is good for you www.opensuse.org
Am Mittwoch, 22. Februar 2006 12:54, schrieb Marcus Rueckert:
Tomorrow I'll switch of SSL and log the IMAP chatter between kMail and dovecot. That's slowly getting ridiculous... you dont need to switch of ssl. use the rawlog feature of dovecot. see the config howto set that up.
Mh... I uncommented the line
mail_executable = /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
in my "procotol imap {}"-block. I cannot find any rawlog however, there is no process called "rawlog" running and the imap process itself has no filehandle to anything remotely related to a "rawlog" as well...
lsof | egrep '^imap[[:space:]]' | cut -c30-
cwd DIR 33,6 1024 15878 /home/gunter
rtd DIR 33,6 1024 2 /
txt REG 33,6 428364 4136 /usr/lib/dovecot/imap
mem REG 33,6 27304 9751 /lib/libnss_compat-2.3.2.so
mem REG 33,6 32480 9755 /lib/libnss_nis-2.3.2.so
mem REG 33,6 34520 9753 /lib/libnss_files-2.3.2.so
mem REG 33,8 114828
257211 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index
mem REG 33,8 424960
253886 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index.cache
mem REG 33,8 106992
123879 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index.log
mem REG 33,6 91240 10654 /lib/ld-2.3.2.so
mem REG 33,6 1247360 10655 /lib/libc-2.3.2.so
mem REG 33,6 11384 10660 /lib/libdl-2.3.2.so
mem REG 33,6 75040 10663 /lib/libnsl-2.3.2.so
0u unix 0xc3860b90 5909769 socket
1u unix 0xc3860b90 5909769 socket
2w FIFO 0,5 5909779 pipe
3r CHR 1,9 6154 /dev/urandom
4r FIFO 0,5 5909781 pipe
5w FIFO 0,5 5909781 pipe
6r FIFO 0,5 5909782 pipe
7w FIFO 0,5 5909782 pipe
11u REG 33,8 114828
257211 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index
12u REG 33,8 106992
123879 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index.log
13u REG 33,8 424960
253886 /var/lager/var/maildir/gunter/.Mailinglisten.Software.Netz.Dovecot/dovecot.index.cache
Is there anything else I have to do to enable rawlog? (eg. a build time ./configure switch? The rawlog binary is present, however...)
The config file I changed definitely is the one which si read by dovecot, the imap txt is the right one, and I deliberately added a syntax error to the config just to be sure, and it caused an error message as expected.
From the comments in the config file the rawlog should appear in the user's home directory, which it definitely does not:
dir /home/gunter/ -a
total 24 drwxr-xr-x 2 gunter gunter 1024 Oct 3 12:24 . drwxrwsr-x 5 root staff 1024 Jul 24 2005 .. -rw------- 1 gunter gunter 792 Feb 22 12:44 .bash_history -rw-r--r-- 1 gunter gunter 414 Jul 21 2005 .bash_profile -rw-r--r-- 1 gunter gunter 2044 Jul 21 2005 .bashrc -rw------- 1 gunter gunter 112 Feb 22 12:44 .nano_history -rw------- 1 gunter gunter 16167 Feb 22 12:44 .procmailrc
Mh...
Greetings,
Gunter
-- *** Powered by AudioScrobbler --> http://www.last.fm/user/Interneci/ *** 14:36 | Dark Noize - Your Only Motions (Single Mix) 14:27 | Ace's Delight - Mental Theme (Ultra Trance Mix 14:24 | Harald Kloser - Techno Download 14:19 | Juno Reactor - Conga Fury *** PGP-Verschlüsselung bei eMails erwünscht :-) *** PGP: 0x1128F25F ***
On Wed, 2006-02-22 at 14:44 +0100, Gunter Ohrner wrote:
Am Mittwoch, 22. Februar 2006 12:54, schrieb Marcus Rueckert:
Tomorrow I'll switch of SSL and log the IMAP chatter between kMail and dovecot. That's slowly getting ridiculous... you dont need to switch of ssl. use the rawlog feature of dovecot. see the config howto set that up.
Mh... I uncommented the line
mail_executable = /usr/lib/dovecot/rawlog /usr/lib/dovecot/imap
in my "procotol imap {}"-block. I cannot find any rawlog however, there is no process called "rawlog" running and the imap process itself has no filehandle to anything remotely related to a "rawlog" as well...
Create ~/dovecot.rawlog directory.
Am Mittwoch, 22. Februar 2006 15:00, schrieb Timo Sirainen:
Create ~/dovecot.rawlog directory.
Ok, now it works and is rather enlightening.
I wasn't able to create a good testcase yet, especially as my "server" gets THAT slow with rawlog enabled that I'll set up a dovecot test installation on my AMD64 workstation instead. This machine is also fast enough to run meaningful tests with the Valgrind memcheck skin.
However, the rawlog revealed one rason, why kMail might behave differently than the tests suggested so far: Besides moving, marking and deleting messages, kMail also *searches* all messages which are modified: kMail remebers the last search done in a kind of virtual folder which seems to be updated constantly. This causes kmail to issue thousands of search commands of thousands of messages are involved in an operation... So maybe the bug in dovecot itself is a small leak in command processing, and the heap grows command for command by a few bytes which could explain the relatively slow growth experienced by others and the relatively huge growth seen by me...
Copying / moving is also done with hundrets of individual commands, each command listing about 10 article numbers or ranges. I guess kMail copies / moves the messages in the order in which they are displayed and only uses ranges inside the number lists if some messages displayed coincidentially span a range of message numbers.
Greetings,
Gunter
-- +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+ Nevertheless Christoph has a point even if its hidden behind a George Bush approach to diplomacy. -- Alax Cox versucht einen aufkeimenden Flamewar zu löschen ;) +-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+
+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+-+PGP-verschlüsselte Mails bevorzugt! +
On Feb 23, 2006, at 7:20 PM, Gunter Ohrner wrote:
However, the rawlog revealed one rason, why kMail might behave
differently than the tests suggested so far: Besides moving, marking and deleting messages, kMail also *searches* all messages which are modified: kMail remebers the last search done in a kind of virtual folder which
seems to be updated constantly. This causes kmail to issue thousands of search commands of thousands of messages are involved in an operation... So maybe the bug in dovecot itself is a small leak in command processing, and the heap grows command for command by a few bytes which could
explain the relatively slow growth experienced by others and the relatively
huge growth seen by me...
That's probably it. It leaked quite a lot of data for each header/
body search command. There were also smaller leaks for each command
that was executed, which is a bit strange since I thought it hadn't
been that long time ago when I last checked that there were no leaks :)
Try if the attached patch fixes the problem.
On 02/21/2006 03:29:33 PM, Timo Sirainen wrote:
Since it's growing heap, the process size never goes down. And I've never noticed imap processes larger than 20MB or so (unless there have been many tens of thousands of mails).
Here are some statistics of the imap process serving a mailbox of 75,000 messages over time (~30 hours) - the first line of each group comes from "ps alx", the second from "cat /proc/15342/maps":
F UID PID PPID PRI NI VSZ RSS WCHAN STAT TTY TIME COMMAND 4 500 15342 2578 15 0 94648 77740 - S ? 1:10 imap 00595000-0071a000 rw-p 00595000 00:00 0 [heap]
4 500 15342 2578 15 0 95084 78256 - S ? 2:36 imap 00595000-00764000 rw-p 00595000 00:00 0 [heap]
4 500 15342 2578 15 0 95344 79532 - S ? 4:39 imap 00595000-007c4000 rw-p 00595000 00:00 0 [heap]
4 500 15342 2578 15 0 96164 79520 - S ? 6:11 imap 00595000-0088d000 rw-p 00595000 00:00 0 [heap]
During this time new mail came in, got read, and some of those messages were deleted. You can see that as the process ages, the heap does grow.
Regards, Willem Riede.
On Feb 22, 2006, at 5:23 AM, Willem Riede wrote:
Here are some statistics of the imap process serving a mailbox of
75,000 messages over time (~30 hours) - the first line of each group comes
from "ps alx", the second from "cat /proc/15342/maps":F UID PID PPID PRI NI VSZ RSS WCHAN STAT TTY
TIME COMMAND 4 500 15342 2578 15 0 94648 77740 - S ?
1:10 imap 00595000-0071a000 rw-p 00595000 00:00
0 [heap]..
4 500 15342 2578 15 0 96164 79520 - S ?
6:11 imap 00595000-0088d000 rw-p 00595000 00:00
0 [heap]During this time new mail came in, got read, and some of those
messages were deleted. You can see that as the process ages, the heap does grow.
Yes, this isn't unexpected since I'm also seeing the heap grow
slowly. But since it's grown only 1.5MB in 30 hours (to 3MB), that
isn't too bad of a problem.
Could you try running imap with some memory leak detection tool/
library, such as Valgrind or dmalloc? I know I should try that myself
also..
On 02/22/2006 03:02:27 AM, Timo Sirainen wrote:
Yes, this isn't unexpected since I'm also seeing the heap grow
slowly. But since it's grown only 1.5MB in 30 hours (to 3MB), that
isn't too bad of a problem.Could you try running imap with some memory leak detection tool/ library, such as Valgrind or dmalloc? I know I should try that myself
also..
Even though from another mail in this thread I learned that you found some leak(s) already, today I had the time to run valgrind on Dovecot imap.
It made dovecot pretty slow, and my mail client (balsa) didn't like it much (mostly disconnecting for timeout). In fact, at one point it crashed because it had received a block of garbage data - this was the trace leading up to it:
IMAP mailbox: imap://wriede@athena.riede.org/Root IMAP C: DONE IMAP C: b2 NOOP IMAP S: 0 OK Idle completed. IMAP S: b2 OK NOOP completed. IMAP mailbox: imap://wriede@athena.riede.org/RNW IMAP C: b3 NOOP IMAP S: <about 1K of utter unprintable garbage>imap connection severed.
I can't tell whether the sending or the receiving end is to blame, but given that server and client are on the same PC, it is not likely to be a transmission error. But I digress.
I opened a bunch of mailboxes, read some mail, did a couple of searches.
Valgrind found many leaked blocks in each invocation of imap. The typical range of leaked memory is from several hundred bytes to 100K, but one process stood out:
==4353== definitely lost: 18,463,192 bytes in 18,029 blocks.
I'm sending the log files seperately to Timo, as loading everybody's inbox with that is not appropriate.
Regards, Willem Riede.
participants (7)
-
Gunter Ohrner
-
Gunter Ohrner
-
Johannes Berg
-
Marcus Rueckert
-
Marten Lehmann
-
Timo Sirainen
-
Willem Riede