[Dovecot] more problems with dovecot-1.1 beta3
Hi, Thank you for pointing me about -xc99 flag, I have compiled and installed dovecot inplace of version 1.0.5 without any special actions on the upgrade. And after starting it immediately got in it's log file messages like:
dovecot: Oct 16 23:10:18 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.git-altlinux-ru/dovecot.index.cache: Invalid argument
I have tried to delete dovecot.index.cache files from imap directories, but this did not helped:
dovecot: Oct 16 23:52:24 Error: IMAP(seriv): Corrupted transaction log file /var/spool/imap/seriv/.imap/dovecot.index.log: indexid changed 1189182277 -> 1192593117 dovecot: Oct 16 23:52:24 Error: IMAP(seriv): Index file /var/spool/imap/seriv/.imap/dovecot.index: indexid changed: 1189182277 -> 1192593117 dovecot: Oct 16 23:52:24 Error: IMAP(seriv): Corrupted transaction log file /var/spool/imap/seriv/.imap/dovecot.index.log: indexid changed: 1189182277 -> 1192593117 dovecot: Oct 16 23:52:28 Error: IMAP(seriv): /var/spool/imap/seriv/.imap/dovecot.index view is inconsistent dovecot: Oct 16 23:52:28 Panic: IMAP(seriv): file client.c: line 105: assertion failed: (!client->destroyed) dovecot: Oct 16 23:52:28 Error: IMAP(seriv): Raw backtrace: /opt/dovecot/libexec/dovecot/imap'i_internal_fatal_handler+0x48 [0x8135118] -> /opt/dovecot/libexec/dovecot/imap'i _panic+0x23 [0x8134b03] -> /opt/dovecot/libexec/dovecot/imap'client_destroy+0x33 [0x808ee43] -> /opt/dovecot/libexec/dovecot/imap'client_continue_pending_input+0x5d [0x808fac d] -> /opt/dovecot/libexec/dovecot/imap'idle_finish+0xfa [0x808348a] -> /opt/dovecot/libexec/dovecot/imap'cmd_idle_continue+0x46 [0x8083776] -> /opt/dovecot/libexec/dovecot/i map'client_command_cancel+0x4a [0x808ec6a] -> /opt/dovecot/libexec/dovecot/imap'client_destroy+0x10b [0x808ef1b] -> /opt/dovecot/libexec/dovecot/imap'client_continue_pending_ input+0x5d [0x808facd] -> /opt/dovecot/libexec/dovecot/imap'idle_finish+0xfa [0x808348a] -> /opt/dovecot/libexec/dovecot/imap'cmd_idle_continue+0x202 [0x8083932] -> /opt/dove cot/libexec/dovecot/imap'idle_sync_now+0x84 [0x80836b4] -> /opt/dovecot/libexec/dovecot/imap'idle_callback+0x5b [0x808371b] -> /opt/dovecot/libexec/dovecot/imap'check_timeout +0x14c [0x80e323c] -> / dovecot: Oct 16 23:52:28 Error: IMAP(seriv): opt/dovecot/libexec/dovecot/imap'io_loop_handle_timeouts+0x217 [0x813d057] -> /opt/dovecot/libexec/dovecot/imap'io_loop_handler_r un+0x8d [0x813d9dd] -> /opt/dovecot/libexec/dovecot/imap'io_loop_run+0x4b [0x813d14b] -> /opt/dovecot/libexec/dovecot/imap'main+0x9a [0x809f18a] -> /opt/dovecot/libexec/dovec ot/imap'_start+0x7d [0x807c95d] dovecot: Oct 16 23:52:28 Error: child 7529 (imap) killed with signal 6
Then I have tried to delete all dovecot.index* files from there, but the messages in dovecot.log are almost the same:
deliver(seriv): Oct 18 14:59:49 Error: file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:01:35 Error: IMAP(seriv): Sending log messages too fast, throttling.. dovecot: Oct 18 15:01:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Drafts/dovecot.index.cache: Invalid argument deliver(seriv): Oct 18 15:01:38 Error: file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.sisyphus-cybertalk-lists-altlinux-org/dovecot.index.cache: In valid argument dovecot: Oct 18 15:02:57 Warning: SIGHUP received - reloading configuration dovecot: Oct 18 15:02:58 Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 384). Either grow the limit or change login_max_processes_count a nd max_mail_processes settings dovecot: Oct 18 15:03:13 Warning: Killed with signal 15 deliver(seriv): Oct 18 15:04:07 Error: file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.community-lists-altlinux-org/dovecot.index.cache: Invalid arg ument deliver(seriv): Oct 18 15:04:23 Error: file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.Trash/dovecot.index.cache: Invalid argument deliver(seriv): Oct 18 15:04:50 Error: file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.community-lists-altlinux-org/dovecot.index.cache: Invalid arg ument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument dovecot: Oct 18 15:06:36 Error: IMAP(seriv): Sending log messages too fast, throttling.. dovecot: Oct 18 15:06:37 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument
One more problem is with fd limit: I have a small dovecot installation, so don't want to increase fd limit. I tried to decreasee max_mail_processes, login_max_processes_count and login_max_connections, but still I have
# /opt/dovecot/sbin/dovecot -n # 1.1.beta3: /opt/dovecot/etc/dovecot.conf Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 384). Either grow the limit or change login_max_processes_count and max_mail_processes settings log_path: /tmp/dovecot.log info_log_path: /tmp/dovecot.debug protocols: pop3 pop3s imap imaps ssl_cert_file: /etc/ssl/parkheights.cert ssl_key_file: /etc/ssl/parkheights.key login_dir: /opt/dovecot/var/run/dovecot/login login_executable(default): /opt/dovecot/libexec/dovecot/imap-login login_executable(imap): /opt/dovecot/libexec/dovecot/imap-login login_executable(pop3): /opt/dovecot/libexec/dovecot/pop3-login login_max_connections: 120 max_mail_processes: 128 mail_extra_groups: mail mail_location: maildir:/var/spool/imap/%n/.imap mail_executable(default): /opt/dovecot/libexec/dovecot/imap mail_executable(imap): /opt/dovecot/libexec/dovecot/imap mail_executable(pop3): /opt/dovecot/libexec/dovecot/pop3 mail_plugin_dir(default): /opt/dovecot/lib/dovecot/imap mail_plugin_dir(imap): /opt/dovecot/lib/dovecot/imap mail_plugin_dir(pop3): /opt/dovecot/lib/dovecot/pop3 auth default: verbose: yes debug: yes debug_passwords: yes passdb: driver: ldap args: /opt/dovecot/etc/dovecot-ldap.conf userdb: driver: ldap args: /opt/dovecot/etc/dovecot-ldap.conf userdb: driver: prefetch socket: type: listen master: path: /opt/dovecot/var/run/dovecot/auth-master mode: 384 user: vmail group: vmail bash-3.00# grep login_max /opt/dovecot/etc/dovecot.conf login_max_processes_count = 128 # 16 + login_max_connections * 2 available file descriptors. login_max_connections = 120 bash-3.00# grep max_mail /opt/dovecot/etc/dovecot.conf max_mail_processes = 128
So I reverted to 1.0.5 which works fine for me.
-- WBR, Sergey Ivanov.
On Thu, 2007-10-18 at 15:16 -0400, Sergey wrote:
Thank you for pointing me about -xc99 flag, I have compiled and installed dovecot inplace of version 1.0.5 without any special actions on the upgrade. And after starting it immediately got in it's log file messages like:
dovecot: Oct 16 23:10:18 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.git-altlinux-ru/dovecot.index.cache: Invalid argument
Could you apply this patch and see what it logs then: http://hg.dovecot.org/dovecot/rev/b7d8695d864d
dovecot: Oct 16 23:52:28 Panic: IMAP(seriv): file client.c: line 105: assertion failed: (!client->destroyed)
Fixed: http://hg.dovecot.org/dovecot/rev/86e964111b1f
dovecot: Oct 18 15:02:58 Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 384). Either grow the limit or change login_max_processes_count a nd max_mail_processes settings .. One more problem is with fd limit: I have a small dovecot installation, so don't want to increase fd limit. I tried to decreasee max_mail_processes, login_max_processes_count and login_max_connections, but still I have .. login_max_connections: 120 max_mail_processes: 128
Changing login_max_connections doesn't affect anything because you're using login_process_per_connection=yes.
The needed fd count is calculated from login_max_processes_count(pop3) + login_max_processes_count(imap) + max_mail_processes.
So in your case 128+128+128.
Hi Timo, thanks for explaining how amount of the file descriptor may be counted.
Timo Sirainen wrote:
On Thu, 2007-10-18 at 15:16 -0400, Sergey wrote:
Thank you for pointing me about -xc99 flag, I have compiled and installed dovecot inplace of version 1.0.5 without any special actions on the upgrade. And after starting it immediately got in it's log file messages like:
dovecot: Oct 16 23:10:18 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.git-altlinux-ru/dovecot.index.cache: Invalid argument
Could you apply this patch and see what it logs then: http://hg.dovecot.org/dovecot/rev/b7d8695d864d
I have applied the patch and now I have in the dovecot.log after just 'make install in the new dovecot-1.1 and dovecot-sieve-1.1 dirs, on the opening of the imap Maildir folder:
dovecot: Oct 21 04:00:30 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/.dovecot-cvs-dovecot-org/dovecot.index.cache: Invalid argument dovecot: Oct 21 04:00:30 Error: IMAP(seriv): posix_fallocate() failed: Invalid argument ...
about 10 times a second.
Then I pkill'ed dovecot and did
find /var/spool/imap/ -name 'dovecot.index*' | xargs rm -rf
but got similar messages with new string added before each of them:
dovecot: Oct 21 04:17:35 Error: IMAP(seriv): posix_fallocate() failed: Invalid argument dovecot: Oct 21 04:17:35 Error: IMAP(seriv): file_set_size() failed with index cache file /var/spool/imap/seriv/.imap/dovecot.index.cache: Invalid argument
And, after I enabled smtp service and sent email to myself, I see in dovecot.log
deliver(seriv): Oct 21 04:17:05 Error: posix_fallocate() failed: Invalid argument deliver(seriv): Oct 21 04:17:06 Error: posix_fallocate() failed: Invalid argument
dovecot: Oct 16 23:52:28 Panic: IMAP(seriv): file client.c: line 105: assertion failed: (!client->destroyed)
Yes, no anything like this after applying the patch.
dovecot: Oct 18 15:02:58 Warning: fd limit 256 is lower than what Dovecot can use under full load (more than 384). Either grow the limit or change login_max_processes_count a nd max_mail_processes settings
..
One more problem is with fd limit: I have a small dovecot installation, so don't want to increase fd limit. I tried to decreasee max_mail_processes, login_max_processes_count and login_max_connections, but still I have
..
login_max_connections: 120 max_mail_processes: 128
Changing login_max_connections doesn't affect anything because you're using login_process_per_connection=yes.
The needed fd count is calculated from login_max_processes_count(pop3) + login_max_processes_count(imap) + max_mail_processes.
So in your case 128+128+128.
-- With best regards, Sergey Ivanov
On 21.10.2007, at 11.35, sergey ivanov wrote:
dovecot: Oct 21 04:00:30 Error: IMAP(seriv): posix_fallocate() failed: Invalid argument
I guess this happens if Solaris libc has posix_fallocate() but the
kernel doesn't support it.
This should help: http://hg.dovecot.org/dovecot/rev/a9dfe05dfadd
Timo Sirainen wrote:
On 21.10.2007, at 11.35, sergey ivanov wrote:
dovecot: Oct 21 04:00:30 Error: IMAP(seriv): posix_fallocate() failed: Invalid argument
I guess this happens if Solaris libc has posix_fallocate() but the kernel doesn't support it.
This should help: http://hg.dovecot.org/dovecot/rev/a9dfe05dfadd
Thank you! With this patch 10 first minutes with dovecot-1.1 do not exposed any problem, I will keep eye on it and report if something happens.
Sergey Ivanov.sergey ivanov wrote:
Timo Sirainen wrote:
On 21.10.2007, at 11.35, sergey ivanov wrote:
dovecot: Oct 21 04:00:30 Error: IMAP(seriv): posix_fallocate() failed: Invalid argument
I guess this happens if Solaris libc has posix_fallocate() but the kernel doesn't support it.
This should help: http://hg.dovecot.org/dovecot/rev/a9dfe05dfadd
Thank you! With this patch 10 first minutes with dovecot-1.1 do not exposed any problem, I will keep eye on it and report if something happens.
First 14 hours of the run, everything looks fine but the messages in dovecot.log:
deliver(seriv): Oct 21 09:44:57 Error: Cache file /var/spool/imap/seriv/.imap/.community-lists-altlinux-org/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 11:01:43 Error: Cache file /var/spool/imap/seriv/.imap/.sisyphus-cybertalk-lists-altlinux-org/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 11:12:14 Error: Cache file /var/spool/imap/seriv/.imap/.xen-users-lists-xensource-com/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 11:31:36 Error: Cache file /var/spool/imap/seriv/.imap/.JewisClubMaoz-yahoogroups-com/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 12:00:25 Error: Cache file /var/spool/imap/seriv/.imap/.centos-announce-centos-org/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 15:42:37 Error: Cache file /var/spool/imap/seriv/.imap/.ma-linux-calypso-tux-org/dovecot.index.cache: Newly added field got lost unexpectedly deliver(seriv): Oct 21 17:30:19 Error: Cache file /var/spool/imap/seriv/.imap/.IsraelEldad-yahoogroups-com/dovecot.index.cache: Newly added field got lost unexpectedly
I have deleted all dovecot.index* files after stopping dovecot-1.0.5 and before starting patched dovecot-1.1.
WBR,
Sergey Ivanov.On 22.10.2007, at 6.24, sergey ivanov wrote:
deliver(seriv): Oct 21 09:44:57 Error: Cache file /var/spool/imap/seriv/.imap/.community-lists-altlinux-org/ dovecot.index.cache: Newly added field got lost unexpectedly
This happens once if cache file doesn't exist yet. This and several
other bugs have been fixed in nightly snapshots already, you can use
them until I'll release beta4 probably tomorrow.
participants (3)
-
Sergey
-
sergey ivanov
-
Timo Sirainen