[Dovecot] Question regarding performance of dovecot-1.0.15
Hi,
I have a dovect 1.0.15 on my mailserver and as a Client I use
offlineimap.
Since some time now my mailsynchronisation got slow - I don't know
exactly where the problem is, but I tried to track it down. Usually
the UID-Searches are fast (according to the offlineimap-debugging) but
as soon as it comes to big folders it takes a long time:
[..]
DEBUG[imap]: 37:15.22 < * 1 RECENT
DEBUG[imap]: 37:15.22 matched r'\* (?P<data>\d+) (?P<type>[A-
Z-]+)( (?P<data2>.*))?' => ('1', 'RECENT', None, None)
DEBUG[imap]: 37:15.22 untagged_responses[RECENT] 1 += ["1"]
DEBUG[imap]: 37:15.22 < HAMH49 OK Append completed.
DEBUG[imap]: 37:15.22 matched r'(?P<tag>HAMH\d+) (?P<type>[A-
Z]+) (?P<data>.*)' => ('HAMH49', 'OK', 'Append completed.')
DEBUG[imap]: 37:15.22 > HAMH50 CHECK
DEBUG[imap]: 37:15.49 < HAMH50 OK Check completed.
DEBUG[imap]: 37:15.49 matched r'(?P<tag>HAMH\d+) (?P<type>[A-
Z]+) (?P<data>.*)' => ('HAMH50', 'OK', 'Check completed.')
DEBUG[imap]: savemessage: first attempt to get new UID
DEBUG[imap]: savemessage_searchforheader called for X-OfflineIMAP-
x601334136
-52656d6f7465496d61704976616e6f7661
-446174656e73636875747a2e4343432e646562617465:
1257496634-0840104922121-v5.99.4
DEBUG[imap]: 37:15.49 > HAMH51 UID SEARCH HEADER X-OfflineIMAP-
x601334136
-52656d6f7465496d61704976616e6f7661
-446174656e73636875747a2e4343432e646562617465
"1257496634-0840104922121-v5.99.4"
DEBUG[imap]: 42:46.80 < * SEARCH 24578
DEBUG[imap]: 42:46.80 matched r'\* (?P<type>[A-Z-]+)( (?
P<data>.*))?' => ('SEARCH', ' 24578', '24578')
DEBUG[imap]: 42:46.80 untagged_responses[SEARCH] 0 += ["24578"]
DEBUG[imap]: 42:46.80 < HAMH51 OK Search completed.
DEBUG[imap]: 42:46.80 matched r'(?P<tag>HAMH\d+) (?P<type>[A-
Z]+) (?P<data>.*)' => ('HAMH51', 'OK', 'Search completed.')
DEBUG[imap]: 42:46.80 untagged_responses[SEARCH] => ['24578']
DEBUG[imap]: savemessage_searchforheader got initial matchinguids:
'24578'
DEBUG[imap]: savemessage_searchforheader: matchinguids now ['24578']
DEBUG[imap]: savemessage: returning 24578
Copy message 9480 Maildir[.Datenschutz.CCC.debate] ->
IMAP[Datenschutz.CCC.debate], LocalStatus[.Datenschutz.CCC.debate]
DEBUG[imap]: savemessage: called
DEBUG[imap]: savemessage: using date "15-Mar-2009 18:04:01 +0100"
DEBUG[imap]: savemessage: initial content is: 'Return-path: [..] (here
is the mail)
' DEBUG[imap]: savemessage_addheader: newline = '\r\nX-OfflineIMAP- x1331546026 -52656d6f7465496d61704976616e6f7661 -446174656e73636875747a2e4343432e646562617465:
1257496966-0335241954714-v5.99.4' DEBUG[imap]: savemessage_addheader: trailer = '\r\nEnvelope-to:[..]
DEBUG[imap]: savemessage: new headers are: X-OfflineIMAP-
x1331546026
-52656d6f7465496d61704976616e6f7661
-446174656e73636875747a2e4343432e646562617465: As you can see at the timestamp, it took roundabout 5 minutes to find my configuration: # 1.0.15: /etc/dovecot/dovecot.conf
log_path: /home/rince/dovecot-debug.log
info_log_path: /home/rince/dovecot-debug.log
log_timestamp: %Y-%m-%d %H:%M:%S
protocols: imaps pop3s imap
listen(default): 10.11.12.1
listen(imap): 10.11.12.1
listen(pop3): *
ssl_cert_file: /etc/ssl/certs/ivanova.crt
ssl_key_file: /etc/ssl/private/ivanova.key
login_dir: /var/run/dovecot/login
login_executable(default): /usr/lib/dovecot/imap-login
login_executable(imap): /usr/lib/dovecot/imap-login
login_executable(pop3): /usr/lib/dovecot/pop3-login
login_user: dovecot-login
mail_privileged_group: mail
mail_debug: yes
mail_executable(default): /usr/lib/dovecot/imap
mail_executable(imap): /usr/lib/dovecot/imap
mail_executable(pop3): /usr/lib/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/modules/imap
mail_plugin_dir(imap): /usr/lib/dovecot/modules/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/modules/pop3
pop3_uidl_format(default):
pop3_uidl_format(imap):
pop3_uidl_format(pop3): %08Xu%08Xv
auth default:
user: dovecot-auth
passdb:
driver: passwd-file
args: /etc/dovecot/passwd
userdb:
driver: passwd
userdb:
driver: passwd-file
args: /etc/dovecot/passwd Unfortunately, except the starting-up message, there comes nothing in Let me get this straight: You think that your client, one of the
1257496966-0335241954714-v5.99.4
DEBUG[imap]: savemessage_addheader: called to add X-OfflineIMAP-
x1331546026
-52656d6f7465496d61704976616e6f7661
-446174656e73636875747a2e4343432e646562617465:
1257496966-0335241954714-v5.99.4
DEBUG[imap]: savemessage_addheader: insertionpoint = 63
DEBUG[imap]: savemessage_addheader: leader = 'Return-path:
the next mail. Is this normal? In this mailbox there are right now
around 20.000 mails, which shouldn't be too hard then... or am I
missing something there? Is there a way to see why dovecot needs so
long to find the next mail to synchronise?
the debug-logfiles.Ciao, Hanno
wealthiest,
most powerful men in the world, is secretly a vigilante who spends his
nights
beating criminals to a pulp with his bare hands. And your plan is to
blackmail
this person? Good luck. (Lucius Fox, Morgan Freeman, The Dark
Knight)
On Fri, 2009-11-06 at 11:53 +0100, Hanno Wagner wrote:
DEBUG[imap]: 37:15.49 > HAMH51 UID SEARCH HEADER X-OfflineIMAP- x601334136
Dovecot should serve this request from dovecot.index.cache file, which should be pretty fast.
my configuration:
There's no mention of mail_location setting. Are you using mbox or maildir? If you're using mbox, you could try if setting mbox_very_dirty_syncs=yes helps. Also you could stracing the imap process to see what exactly it's doing. http://wiki.dovecot.org/Debugging/ProcessTracing
Hiho,
Am 06.11.2009 um 21:01 schrieb Timo Sirainen:
There's no mention of mail_location setting. Are you using mbox or maildir? If you're using mbox, you could try if setting mbox_very_dirty_syncs=yes helps. Also you could stracing the imap process to see what exactly it's doing. http://wiki.dovecot.org/Debugging/ProcessTracing
Sorry, it is Maildir.
And interesting enough, now I have two problems ;)
One is a panic in Dovecot, the second the performance. I made an
strace as you propsed, I put it on http://www.rince.de/dovecot.log
Ciao, Hanno
Let me get this straight: You think that your client, one of the
wealthiest,
most powerful men in the world, is secretly a vigilante who spends his
nights
beating criminals to a pulp with his bare hands. And your plan is to
blackmail
this person? Good luck. (Lucius Fox, Morgan Freeman, The Dark
Knight)
On Fri, 2009-11-06 at 21:33 +0100, Hanno Wagner wrote:
And interesting enough, now I have two problems ;)
One is a panic in Dovecot, the second the performance. I made an
strace as you propsed, I put it on http://www.rince.de/dovecot.log
The strace shows the crash instead of the long wait. And for crashes straces are nearly useless. Showing the actual panic message and perhaps gdb backtrace would be a lot more helpful.
Anyway, since v1.0 is in security-fixes-only mode now, finding the cause of the crash isn't very useful either. You'll probably get rid of it by just deleting dovecot.index* files.
Good evening,
Am 06.11.2009 um 23:42 schrieb Timo Sirainen:
The strace shows the crash instead of the long wait. And for crashes straces are nearly useless. Showing the actual panic message and
perhaps gdb backtrace would be a lot more helpful.
Okay, but I just remove d the dovecot.index*-files and it works again.
Now I made a trace for the long waits. I put another strace-log on the
webserver, http://www.rince.de/dovecot.log.gz (since it is unpacked
300MB)
Thank you for looking into my problems here!
Ciao, Hanno
"You all were watching, I take it?" "Yes" "Did you see us fight?" "No" "Trap"
On Sat, 2009-11-07 at 00:06 +0100, Hanno Wagner wrote:
Now I made a trace for the long waits. I put another strace-log on the
webserver, http://www.rince.de/dovecot.log.gz (since it is unpacked
300MB)
Looks like it's opening the maildir files every time and parsing their headers, instead of using the cache file. I don't really know why it's doing that, but it looks like a bug. But like I said, no more bug fixes to v1.0.. Upgrading to v1.1 or v1.2 probably helps.
Hiho,
Am 07.11.2009 um 00:24 schrieb Timo Sirainen:
Looks like it's opening the maildir files every time and parsing their headers, instead of using the cache file. I don't really know why it's doing that, but it looks like a bug. But like I said, no more bug
fixes to v1.0.. Upgrading to v1.1 or v1.2 probably helps.
Okay, I did that - and it worked, thanks! So my problem is solved ;)
Ciao, Hanno
Let me get this straight: You think that your client, one of the
wealthiest,
most powerful men in the world, is secretly a vigilante who spends his
nights
beating criminals to a pulp with his bare hands. And your plan is to
blackmail
this person? Good luck. (Lucius Fox, Morgan Freeman, The Dark
Knight)
participants (2)
-
Hanno Wagner
-
Timo Sirainen