[Dovecot] Dovecot extremely slow!
Patricio Rojo
pato at oan.cl
Thu Sep 26 01:05:01 EEST 2013
Please help,
Dovecot is running extremely slow for the last couple of weeks and it
seems to be getting worse (or my patience running short).
I attach the 10-master configuration and the log file after running
strace according to: http://wiki.dovecot.org/Debugging/ProcessTracing
I can click on an email and wait for a minute or more before receiving a
connection dropped or no error at all. I use many clients (thunderbird,
windows 8 mail, maildroid for android, squirrelmail) and they all have
similar behavior. It happens both in the inbox and on imap subfolders.
Sometimes it helps changing subfolders back and forth.
I have many imap folders organized in up to 3 levels of subfolders and
use postfix for delivery.
Let me know any other info you require. Thanks!
Patricio
-------------- next part --------------
#default_process_limit = 100
#default_client_limit = 1000
# Default VSZ (virtual memory size) limit for service processes. This is mainly
# intended to catch and kill processes that leak memory before they eat up
# everything.
#default_vsz_limit = 256M
# Login user is internally used by login processes. This is the most untrusted
# user in Dovecot system. It shouldn't have access to anything at all.
#default_login_user = dovenull
# Internal user is used by unprivileged processes. It should be separate from
# login user, so that login processes can't disturb other processes.
#default_internal_user = dovecot
service imap-login {
inet_listener imap {
#port = 143
}
inet_listener imaps {
#port = 993
#ssl = yes
}
# Number of connections to handle before starting a new process. Typically
# the only useful values are 0 (unlimited) or 1. 1 is more secure, but 0
# is faster. <doc/wiki/LoginProcess.txt>
#service_count = 1
# Number of processes to always keep waiting for more connections.
#process_min_avail = 0
# If you set service_count=0, you probably need to grow this.
#vsz_limit = $default_vsz_limit
}
service pop3-login {
inet_listener pop3 {
#port = 110
}
inet_listener pop3s {
#port = 995
#ssl = yes
}
}
service lmtp {
unix_listener lmtp {
#mode = 0666
}
# Create inet listener only if you can't use the above UNIX socket
#inet_listener lmtp {
# Avoid making LMTP visible for the entire internet
#address =
#port =
#}
}
service imap {
# Most of the memory goes to mmap()ing files. You may need to increase this
# limit if you have huge mailboxes.
#vsz_limit = $default_vsz_limit
# Max. number of IMAP processes (connections)
#process_limit = 1024
}
service pop3 {
# Max. number of POP3 processes (connections)
#process_limit = 1024
}
service auth {
# auth_socket_path points to this userdb socket by default. It's typically
# used by dovecot-lda, doveadm, possibly imap process, etc. Users that have
# full permissions to this socket are able to get a list of all usernames and
# get the results of everyone's userdb lookups.
#
# The default 0666 mode allows anyone to connect to the socket, but the
# userdb lookups will succeed only if the userdb returns an "uid" field that
# matches the caller process's UID. Also if caller's uid or gid matches the
# socket's uid or gid the lookup succeeds. Anything else causes a failure.
#
# To give the caller full permissions to lookup all users, set the mode to
# something else than 0666 and Dovecot lets the kernel enforce the
# permissions (e.g. 0777 allows everyone full permissions).
unix_listener auth-userdb {
#mode = 0666
#user =
#group =
}
# Postfix smtp-auth
unix_listener /var/spool/postfix/private/auth {
user = postfix
group = postfix
mode = 0666
}
inet_listener {
port = 12345
}
# Auth process is run as this user.
#user = $default_internal_user
}
service auth-worker {
# Auth worker process is run as root by default, so that it can access
# /etc/shadow. If this isn't necessary, the user should be changed to
# $default_internal_user.
#user = root
}
service dict {
# If dict proxy is used, mail processes should have access to its socket.
# For example: mode=0660, group=vmail and global mail_access_groups=vmail
unix_listener dict {
#mode = 0600
#user =
#group =
}
}
-------------- next part --------------
18:29:13.833120 epoll_wait(9, {}, 6, 23980) = 0
18:29:37.837451 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:29:37.838261 epoll_wait(9, {}, 6, 29999) = 0
18:30:07.867721 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:30:07.868340 epoll_wait(9, {}, 6, 28917) = 0
18:30:36.814608 write(11, "* OK Still here\r\n", 17) = 17
18:30:36.832177 time(NULL) = 1380144636
18:30:36.833279 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1034) = 1
18:30:37.065994 read(11, "DONE\r\n", 8030) = 6
18:30:37.066289 epoll_ctl(9, EPOLL_CTL_DEL, 11, {0, {u32=1413012688, u64=139759648824528}}) = 0
18:30:37.066574 inotify_rm_watch(13, 2) = 0
18:30:37.066795 epoll_ctl(9, EPOLL_CTL_DEL, 13, {0, {u32=1413125552, u64=139759648937392}}) = 0
18:30:37.067053 write(11, "8 OK Idle completed.\r\n", 22) = 22
18:30:37.067185 epoll_ctl(9, EPOLL_CTL_ADD, 11, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413012688, u64=139759648824528}}) = 0
18:30:37.067301 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1800000) = 1
18:30:37.291601 read(11, "9 noop\r\n", 8024) = 8
18:30:37.291914 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:30:37.292250 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.305654 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.305786 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.305964 alarm(180) = 0
18:30:37.306051 fcntl(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:30:37.306458 alarm(0) = 180
18:30:37.306555 time(NULL) = 1380144637
18:30:37.306619 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.306971 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.307141 time(NULL) = 1380144637
18:30:37.307226 fcntl(10, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:30:37.307707 write(11, "9 OK NOOP completed.\r\n", 22) = 22
18:30:37.307986 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1800000) = 1
18:30:37.535951 read(11, "10 UID fetch 191:* (FLAGS)\r\n", 8016) = 28
18:30:37.536285 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.536613 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.536904 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.537254 write(11, "* 189 FETCH (UID 190 FLAGS (\\See"..., 61) = 61
18:30:37.537349 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1800000) = 1
18:30:37.763416 read(11, "11 IDLE\r\n", 7988) = 9
18:30:37.763715 time(NULL) = 1380144637
18:30:37.763994 inotify_add_watch(13, "/home/pato/mail/Astro/conferences", IN_MODIFY|IN_CLOSE_WRITE|IN_CLOSE_NOWRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF) = 3
18:30:37.764617 epoll_ctl(9, EPOLL_CTL_ADD, 13, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413125552, u64=139759648937392}}) = 0
18:30:37.764825 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:30:37.765039 epoll_ctl(9, EPOLL_CTL_DEL, 11, {0, {u32=1413012688, u64=139759648824528}}) = 0
18:30:37.765160 epoll_ctl(9, EPOLL_CTL_ADD, 11, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413012688, u64=139759648824528}}) = 0
18:30:37.765233 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:30:37.765337 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.765430 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.765502 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.765588 alarm(180) = 0
18:30:37.765643 fcntl(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:30:37.765983 alarm(0) = 180
18:30:37.766041 time(NULL) = 1380144637
18:30:37.766092 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.766367 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:30:37.766466 time(NULL) = 1380144637
18:30:37.766518 fcntl(10, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:30:37.766923 write(11, "+ idling\r\n", 10) = 10
18:30:37.767054 epoll_wait(9, {{EPOLLIN, {u32=1413125552, u64=139759648937392}}}, 6, 29998) = 1
18:30:37.767136 read(13, "\2\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 32768) = 16
18:30:37.767211 epoll_wait(9, {}, 6, 29998) = 0
18:31:07.794079 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:31:07.794611 epoll_wait(9, {}, 6, 30000) = 0
18:31:37.821166 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:31:37.821778 epoll_wait(9, {}, 6, 30000) = 0
18:32:07.852108 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:32:07.852770 epoll_wait(9, {}, 6, 28911) = 0
18:32:36.793076 write(11, "* OK Still here\r\n", 17) = 17
18:32:36.793376 time(NULL) = 1380144756
18:32:36.793646 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1059) = 1
18:32:37.029815 read(11, "DONE\r\n", 7979) = 6
18:32:37.030105 epoll_ctl(9, EPOLL_CTL_DEL, 11, {0, {u32=1413012688, u64=139759648824528}}) = 0
18:32:37.030390 inotify_rm_watch(13, 3) = 0
18:32:37.030676 epoll_ctl(9, EPOLL_CTL_DEL, 13, {0, {u32=1413125552, u64=139759648937392}}) = 0
18:32:37.030874 write(11, "11 OK Idle completed.\r\n", 23) = 23
18:32:37.030977 epoll_ctl(9, EPOLL_CTL_ADD, 11, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413012688, u64=139759648824528}}) = 0
18:32:37.031101 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1799999) = 1
18:32:37.280529 read(11, "12 noop\r\n", 7973) = 9
18:32:37.280754 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:32:37.281073 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.281914 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.282202 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.282417 alarm(180) = 0
18:32:37.282503 fcntl(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:32:37.282815 alarm(0) = 180
18:32:37.282867 time(NULL) = 1380144757
18:32:37.282917 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.283174 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.283272 time(NULL) = 1380144757
18:32:37.283321 fcntl(10, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:32:37.283760 write(11, "12 OK NOOP completed.\r\n", 23) = 23
18:32:37.283886 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1800000) = 1
18:32:37.508552 read(11, "13 UID fetch 191:* (FLAGS)\r\n", 7964) = 28
18:32:37.508868 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.509183 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.509412 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.509645 write(11, "* 189 FETCH (UID 190 FLAGS (\\See"..., 61) = 61
18:32:37.509719 epoll_wait(9, {{EPOLLIN, {u32=1413012688, u64=139759648824528}}}, 6, 1800000) = 1
18:32:37.735149 read(11, "14 IDLE\r\n", 7936) = 9
18:32:37.735437 time(NULL) = 1380144757
18:32:37.735713 inotify_add_watch(13, "/home/pato/mail/Astro/conferences", IN_MODIFY|IN_CLOSE_WRITE|IN_CLOSE_NOWRITE|IN_MOVED_FROM|IN_MOVED_TO|IN_CREATE|IN_DELETE|IN_DELETE_SELF) = 4
18:32:37.736237 epoll_ctl(9, EPOLL_CTL_ADD, 13, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413125552, u64=139759648937392}}) = 0
18:32:37.736487 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:32:37.736719 epoll_ctl(9, EPOLL_CTL_DEL, 11, {0, {u32=1413012688, u64=139759648824528}}) = 0
18:32:37.736845 epoll_ctl(9, EPOLL_CTL_ADD, 11, {EPOLLIN|EPOLLPRI|EPOLLERR|EPOLLHUP, {u32=1413012688, u64=139759648824528}}) = 0
18:32:37.736965 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:32:37.737068 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.737159 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.737229 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.737313 alarm(180) = 0
18:32:37.737365 fcntl(10, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:32:37.737693 alarm(0) = 180
18:32:37.737748 time(NULL) = 1380144757
18:32:37.737802 stat("/home/pato/mail/Astro/.imap/conferences/dovecot.index.log", {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.738075 fstat(10, {st_mode=S_IFREG|0644, st_size=11400, ...}) = 0
18:32:37.738173 time(NULL) = 1380144757
18:32:37.738224 fcntl(10, F_SETLK, {type=F_UNLCK, whence=SEEK_SET, start=0, len=0}) = 0
18:32:37.738653 write(11, "+ idling\r\n", 10) = 10
18:32:37.738784 epoll_wait(9, {{EPOLLIN, {u32=1413125552, u64=139759648937392}}}, 6, 29998) = 1
18:32:37.738867 read(13, "\3\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 32768) = 16
18:32:37.738962 epoll_wait(9, {}, 6, 29998) = 0
18:33:07.767247 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:33:07.767582 epoll_wait(9, {}, 6, 30000) = 0
18:33:37.797914 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:33:37.798562 epoll_wait(9, {}, 6, 29999) = 0
18:34:07.827911 stat("/home/pato/mail/Astro/conferences", {st_mode=S_IFREG|0644, st_size=112122083, ...}) = 0
18:34:07.828547 epoll_wait(9, <unfinished ...>
More information about the dovecot
mailing list