[Dovecot] 1.0.rc26 released
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
Most importantly this should fix mbox problems in recent RCs.
* Changed --with-headers to --enable-header-install
* If time moves backwards only max. 5 seconds, sleep until we're back
in the original present instead of killing ourself. An error is
still logged.
- IMAP: With namespace prefixes LSUB prefix.* listed INBOX.INBOX.
- deliver: Ignore mbox metadata headers from the message input.
X-IMAP header crashed deliver.
- deliver: If mail_debug=yes, drop out DEBUG environment before
calling sendmail binary. Postfix's sendmail didn't really like it.
- mbox: X-UID brokeness fixes broke rc25 even with valid X-UID headers.
Now the code should finally work right.
- Maildir: When syncing a huge maildir, touch dovecot-uidlist.lock file
once in a while to make sure it doesn't get overwritten by another
process.
- Maildir++ quota: We didn't handle NUL bytes in maildirsize files very
well. Now the file is rebuilt when they're seen (NFS problem).
- Index/view handling fix should fix some crashes/errors
- If index files were moved to a different endianess machine, Dovecot
logged all sorts of errors instead of silently rebuilding them.
- Convert plugin didn't change hierarchy separators in mailbox names.
- PostgreSQL authentication could have lost requests once in a while
with a heavily loaded server.
- Login processes could have crashed in some situations
- auth cache crashed with non-plaintext mechanisms
- If time moves backwards only max. 5 seconds, sleep until we're back in the original present instead of killing ourself. An error is still logged.
This might be a stupid question but this weekend we are about to push our clocks ahead one hour. In the fall when the clocks get set back an hour what does that do to Dovecot?
Our servers are using NTP and I'm not entirely sure how that adjusts the clock. I'm laughing at myself because whatever it does it's worked for us for years. I know I just jinxed myself.
Thanks,
Jim
Jim Horner wrote:
- If time moves backwards only max. 5 seconds, sleep until we're back in the original present instead of killing ourself. An error is still logged.
This might be a stupid question but this weekend we are about to push our clocks ahead one hour. In the fall when the clocks get set back an hour what does that do to Dovecot?
Time is UT in this context, not local time. So DST transitions like this will not trigger it.
Regards,
Christian
Christian Balzer Network/Systems Engineer NOC chibi@gol.com Global OnLine Japan/Fusion Network Services http://www.gol.com/
At 12:52 AM -0500 3/7/07, Jim Horner wrote:
- If time moves backwards only max. 5 seconds, sleep until we're back in the original present instead of killing ourself. An error is still logged.
This might be a stupid question but this weekend we are about to push our clocks ahead one hour. In the fall when the clocks get set back an hour what does that do to Dovecot?
Our servers are using NTP and I'm not entirely sure how that adjusts the clock. I'm laughing at myself because whatever it does it's worked for us for years. I know I just jinxed myself.
The timezone changes only affect the display of time in a particular zone or calculation of absolute time from a zoned form. No sanely-written daemon works with zoned time values except for presentation to humans, i.e. logging. Switching the system time zone (i.e. the offset from GMT to use for presentation of time) does not change the system time. There is no clock adjustment at a DST change.
Bill Cole bill@scconsult.com
On Wed 07 Mar 2007 at 02:28AM, Timo Sirainen wrote:
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
Most importantly this should fix mbox problems in recent RCs.
(Sorry for the long mail)
I've got rc26 up and running on our production box, and we are now migrating users onto it. In a few days we'll see higher user load than we saw in our pilot deployment. So far things look mixed. Some observations:
I'm seeing a lot more imap-login's around than I am used to. Usually there have been just 3; maybe no big deal...? Maybe I made a settings mistake?
# pgrep -x imap-login | wc -l 27 # pgrep -x imap | wc -l 30
I'm seeing a new crash, over and over with one user (I have 580 core files), although gdb is having a tough time getting a backtrace beyond a few frames; I've yet to talk to the user to see what the experience looked like for him.
(gdb) bt full #0 0xfee505a7 in _lwp_kill () from /lib/libc.so.1 No symbol table info available. #1 0xfee4d71b in thr_kill () from /lib/libc.so.1 No symbol table info available. #2 0xfee06502 in raise () from /lib/libc.so.1 No symbol table info available. #3 0xfede4b8d in abort () from /lib/libc.so.1 No symbol table info available. #4 0x080b8ec8 in i_internal_panic_handler (fmt=0x0, args=0x8047024 "\217Â\f\b\230\001") at failures.c:406 backtrace = 0x80e9c68 "0x80b8a2f -> 0x8087b2f -> 0x80830f0 -> 0x80850f2 -> 0x8085560 -> 0x80ad0b0 -> 0x8071296 -> 0x806a1bf -> 0x806a334 -> 0x806ba6e -> 0x806ba02 -> 0x806bbbc -> 0x80be0d9 -> 0x80bdb11 -> 0x8072a08 -> 0x806"... #5 0x080b8a2f in i_panic ( format=0x80d23c0 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:195 No locals. #6 0x08087b2f in mbox_sync_rewrite (sync_ctx=0x8047800, mail_ctx=0x0, end_offset=138189881, move_diff=742, extra_space=The value of variable 'extra_space' is distributed across several locations, and GDB cannot access its value. ) at mbox-sync-rewrite.c:566 mails = (struct mbox_sync_mail *) 0x811dc48 offset = The value of variable 'offset' is distributed across several locations, and GDB cannot access its value. (gdb)
Here is a pstack:
# pstack core.imap.211539.117146 core 'core.imap.211539.117146' of 211539: imap fee505a7 _lwp_kill (1, 6) + 7 fee06502 raise (6) + 22 fede4b8d abort (80fe829, 80e9c68, 8047018, 80b8a2f, 80d23c0, 8047024) + cd 080b8ec8 i_internal_fatal_handler (80d23c0, 8047024, 8047028, 80b7cb6, 80f5568, 8047027) 080b8a2f ???????? (80d23c0, 80cc28f, 198, 80c71ae, 80d2528, a) 08087b2f mbox_sync_rewrite (8047800, 0, 83c9c39, 0, 2e6, 0) + 4f 080830f0 mbox_sync_do (feffcc70, 6799ca3, 98, 1, 29f0cad6, ffffffff) + a84 080850f2 mbox_sync (80fca90, 8, 0, 45f05a57, 80f68a0, 80f6b88) + 40e 08085560 mbox_storage_sync_init (80fca90, 1, 4d3db, 0) + 3c 080ad0b0 mailbox_sync_init (80fca90, 1, 0, 0, 0, 0) + 10 08071296 imap_sync_nonselected (80fca90, 1, 0, 0) + 12 0806a1bf _cmd_select_full (80f6bcc, 0, 22, 8, 806bf90, 22) + 9b 0806a334 cmd_select (80f6bcc, 80fafe0, 7, 80f6bcc) + 10 0806ba6e client_handle_input (80f6b88, 80f6bcc, 8047a48, 806bbab, 2, 80f6b88) + fa 0806ba02 client_handle_input (80bdfdd, 0, 9, 2, 80f5338, 1) + 8e 0806bbbc _client_input (80f6b88, 3, 8047a88, 80be0ce, 1, 1000000) + 74 080be0d9 io_loop_handler_run (80f4380, 0, 80f6b88, 8047c3a) + 131 080bdb11 io_loop_run (80f4380, 1, 80f6498, 32, fee47cd1, fedd63fc) + 21 08072a08 main (1, 8047b18, 8047b20) + 408 08067074 _start (1, 8047c20, 0, 8047c25, 8047c35, 8047c42) + 80
Dovecot is still *really* noisy on endianness switchover, and also I think it has been crashy, too:
Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.imap/INBOX/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/BUGS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/KRNL/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/CBLT/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/MISC/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/ESCS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/NFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/FSPT/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/ZFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/JRSC/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SPAM/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/UFST/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PCFS/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index.log: start_offset (6144) > file size (3400) Error: IMAP(foobar): broken sync positions Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index Error: IMAP(foobar): Fixed index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index: log file sync pos 0,0 -> 33554432, 6144 Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index.log: start_offset (6144) > file size (2808) Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PBAK/dovecot.index.cache: indexid changed Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/PRTI/dovecot.index.cache: indexid changed Info: imap-login: Disconnected: rip=XXX.9.61.63, lip=XXX.YYY.17.63 Info: imap-login: Disconnected: rip=XXX.9.61.63, lip=XXX.YYY.17.63 Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/.imap/Trash/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index.log: unknown record type 0x10 Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/OSOL/dovecot.index Info: IMAP(foobar): Disconnected: Internal error occurred. Refer to server log for more information. [2007-03-07 06:59:21] Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices ... Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted index cache file /home/foobar/Mail/imapd-indices/.Mail/.imap/Sent/dovecot.index.cache: field header points outside file Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index.log: hdr.size too large (133076088) Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index Error: IMAP(foobar): Unexpected transaction log desync with index /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/INBX/dovecot.index Info: IMAP(foobar): Disconnected: Mailbox is in inconsistent state, please relogin. Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input) Error: IMAP(foobar): Raw backtrace: 0x80b8fd3 -> 0x806c1da -> 0x8068f2d -> 0x8069169 -> 0x8069222 -> 0x806935f -> 0x806bfd7 -> 0x806bf5e -> 0x806c140 -> 0x80be67d -> 0x80be0b5 -> 0x8072fac -> 0x806722c Error: child 170842 (imap) killed with signal 6 Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): Corrupted transaction log file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index.log: unknown record type 0x0 Warning: IMAP(foobar): fscking index file /home/foobar/Mail/imapd-indices/.Mail/Incoming/.imap/SUST/dovecot.index Info: IMAP(foobar): Disconnected: Internal error occurred. Refer to server log for more information. [2007-03-07 07:02:32] Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.9.61.63, lip=XXX.YYY.17.63, TLS Info: IMAP(foobar): Effective uid=123456, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar
And on and on. I can live with it, but it'd be nice to have it be detected and dealt with, with perhaps a less alarming message: "{big|little} endian {index|cache} file detected on {little|big} endian system; removing."
Thanks as always,
-dp
-- Daniel Price - Solaris Kernel Engineering - dp@eng.sun.com - blogs.sun.com/dp
On Thu, 2007-03-08 at 11:02 -0800, Dan Price wrote:
On Wed 07 Mar 2007 at 02:28AM, Timo Sirainen wrote:
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
Most importantly this should fix mbox problems in recent RCs.
(Sorry for the long mail)
I've got rc26 up and running on our production box, and we are now migrating users onto it. In a few days we'll see higher user load than we saw in our pilot deployment. So far things look mixed. Some observations:
I'm seeing a lot more imap-login's around than I am used to. Usually there have been just 3; maybe no big deal...? Maybe I made a settings mistake?
# pgrep -x imap-login | wc -l 27 # pgrep -x imap | wc -l 30
Do you have login_process_per_connection=yes? If so, they're probably proxying SSL connections.
#6 0x08087b2f in mbox_sync_rewrite (sync_ctx=0x8047800, mail_ctx=0x0, end_offset=138189881, move_diff=742, extra_space=The value of variable 'extra_space' is distributed across several locations, and GDB cannot access its value. ) at mbox-sync-rewrite.c:566 mails = (struct mbox_sync_mail *) 0x811dc48 offset = The value of variable 'offset' is distributed across several locations, and GDB cannot access its value.
Hmm. I don't think I've seen this assert-crash before. If it's happening often, compiling without -O2 might help more in debugging it.
- Dovecot is still *really* noisy on endianness switchover, and also I think it has been crashy, too:
Looks like I didn't finish fixing the endianess conversion problems. http://dovecot.org/list/dovecot-cvs/2007-March/007997.html should fix them so that it only complains "Corrupted index cache dovecot.index.cache: indexid changed"
Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input)
Any chance of getting gdb backtrace from this?
Error: IMAP(foobar): Raw backtrace: 0x80b8fd3 -> 0x806c1da -> 0x8068f2d -> 0x8069169 -> 0x8069222 -> 0x806935f -> 0x806bfd7 -> 0x806bf5e -> 0x806c140 -> 0x80be67d -> 0x80be0b5 -> 0x8072fac -> 0x806722c
If not, this could be used with gdb to get it: http://dovecot.org/list/dovecot/2006-November/017682.html
Well, swtich to UW-IMAP and you could have hundreds...as many as 600+
Timo Sirainen wrote:
On Thu, 2007-03-08 at 11:02 -0800, Dan Price wrote:
On Wed 07 Mar 2007 at 02:28AM, Timo Sirainen wrote:
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
Most importantly this should fix mbox problems in recent RCs.
(Sorry for the long mail)
I've got rc26 up and running on our production box, and we are now migrating users onto it. In a few days we'll see higher user load than we saw in our pilot deployment. So far things look mixed. Some observations:
I'm seeing a lot more imap-login's around than I am used to. Usually there have been just 3; maybe no big deal...? Maybe I made a settings mistake?
# pgrep -x imap-login | wc -l 27 # pgrep -x imap | wc -l 30
Do you have login_process_per_connection=yes? If so, they're probably proxying SSL connections.
#6 0x08087b2f in mbox_sync_rewrite (sync_ctx=0x8047800, mail_ctx=0x0, end_offset=138189881, move_diff=742, extra_space=The value of variable 'extra_space' is distributed across several locations, and GDB cannot access its value. ) at mbox-sync-rewrite.c:566 mails = (struct mbox_sync_mail *) 0x811dc48 offset = The value of variable 'offset' is distributed across several locations, and GDB cannot access its value.
Hmm. I don't think I've seen this assert-crash before. If it's happening often, compiling without -O2 might help more in debugging it.
- Dovecot is still *really* noisy on endianness switchover, and also I think it has been crashy, too:
Looks like I didn't finish fixing the endianess conversion problems. http://dovecot.org/list/dovecot-cvs/2007-March/007997.html should fix them so that it only complains "Corrupted index cache dovecot.index.cache: indexid changed"
Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input)
Any chance of getting gdb backtrace from this?
Error: IMAP(foobar): Raw backtrace: 0x80b8fd3 -> 0x806c1da -> 0x8068f2d -> 0x8069169 -> 0x8069222 -> 0x806935f -> 0x806bfd7 -> 0x806bf5e -> 0x806c140 -> 0x80be67d -> 0x80be0b5 -> 0x8072fac -> 0x806722c
If not, this could be used with gdb to get it: http://dovecot.org/list/dovecot/2006-November/017682.html
--
Stewart Dean, Unix System Admin, Henderson Computer Resources
Center of Bard College, Annandale-on-Hudson, New York 12504
sdean@bard.edu voice: 845-758-7475, fax: 845-758-7035
On Thu 08 Mar 2007 at 10:09PM, Timo Sirainen wrote:
Do you have login_process_per_connection=yes? If so, they're probably proxying SSL connections.
Ahh. Ok. I didn't have SSL in the pilot. Should I set login_process_per_connection=no? I don't know the best practice here, I took what I thought was the default setting.
Hmm. I don't think I've seen this assert-crash before. If it's happening often, compiling without -O2 might help more in debugging it.
Ok, done. I'll see if it happens again.
Looks like I didn't finish fixing the endianess conversion problems. http://dovecot.org/list/dovecot-cvs/2007-March/007997.html should fix them so that it only complains "Corrupted index cache dovecot.index.cache: indexid changed"
Thanks!
Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input)
Any chance of getting gdb backtrace from this?
I'll see if I can find it. I've been monkeying with adding DTrace probes to Dovecot (patch forthcoming, I am hopeful) and was slightly afraid I caused this-- let me see if it happens again tonight, when we add more users.
-dp
-- Daniel Price - Solaris Kernel Engineering - dp@eng.sun.com - blogs.sun.com/dp
On Thu, 2007-03-08 at 13:50 -0800, Dan Price wrote:
On Thu 08 Mar 2007 at 10:09PM, Timo Sirainen wrote:
Do you have login_process_per_connection=yes? If so, they're probably proxying SSL connections.
Ahh. Ok. I didn't have SSL in the pilot. Should I set login_process_per_connection=no? I don't know the best practice here, I took what I thought was the default setting.
http://wiki.dovecot.org/LoginProcess
Error: IMAP(foobar): file client.c: line 412 (_client_input): assertion failed: (!client->handling_input)
Any chance of getting gdb backtrace from this?
I'll see if I can find it. I've been monkeying with adding DTrace probes to Dovecot (patch forthcoming, I am hopeful) and was slightly afraid I caused this-- let me see if it happens again tonight, when we add more users.
This has been happening with a couple of people, but I haven't yet figured out why it can happen. Backtrace would help getting it fixed.
On Thu 08 Mar 2007 at 01:50PM, Dan Price wrote:
On Thu 08 Mar 2007 at 10:09PM, Timo Sirainen wrote:
Do you have login_process_per_connection=yes? If so, they're probably proxying SSL connections.
Ahh. Ok. I didn't have SSL in the pilot. Should I set login_process_per_connection=no? I don't know the best practice here, I took what I thought was the default setting.
Hmm. I don't think I've seen this assert-crash before. If it's happening often, compiling without -O2 might help more in debugging it.
Ok, done. I'll see if it happens again.
Looks like I didn't finish fixing the endianess conversion problems. http://dovecot.org/list/dovecot-cvs/2007-March/007997.html should fix them so that it only complains "Corrupted index cache dovecot.index.cache: indexid changed"
Today I've got another new crash I haven't seen before-- this is badly impacting the user in question-- since we're crashing on their inbox. This is running on our unoptimized -g only instance-- as requested yesterday. Should we go back to rc24?
-dp
Info: imap-login: Login: user=<foobar>, method=PLAIN, rip=XXX.YYY.61.79, lip=AAA.BBB.17.59 Info: IMAP(foobar): Effective uid=27522, gid=10, home=/home/foobar Info: IMAP(foobar): mbox: data=/home/foobar:INBOX=/var/mail/foobar:INDEX=/home/foobar/Mail/imapd-indices Info: IMAP(foobar): mbox: root=/home/foobar, index=/home/foobar/Mail/imapd-indices, inbox=/var/mail/foobar Error: IMAP(foobar): file mbox-sync-update.c: line 458 (mbox_sync_update_header_from): assertion failed: (ctx->mail.uid == 0 || ctx->mail.uid == mail->uid) Error: IMAP(foobar): Raw backtrace: 0x80bdb2f -> 0x808e51e -> 0x808d56b -> 0x80881f0 -> 0x808a1f2 -> 0x808a660 -> 0x80b21b0 -> 0x8075a8a -> 0x806ba5c -> 0x806bc10 -> 0x806da64 -> 0x806dc59 -> 0x806dd77 -> 0x80c31d9 -> 0x80c2c11 -> 0x8077d2c -> 0x8067b90 Error: child 274367 (imap) killed with signal 6
(gdb) bt full #0 0xfee505a7 in _lwp_kill () from /lib/libc.so.1 No symbol table info available. #1 0xfee4d71b in thr_kill () from /lib/libc.so.1 No symbol table info available. #2 0xfee06502 in raise () from /lib/libc.so.1 No symbol table info available. #3 0xfede4b8d in abort () from /lib/libc.so.1 No symbol table info available. #4 0x080bdfc8 in i_internal_panic_handler (fmt=0x0, args=0x8046fe4 "i!\r\bÊ\001") at failures.c:406 backtrace = 0x80eedd8 "0x80bdb2f -> 0x808e51e -> 0x808d56b -> 0x80881f0 -> 0x808a1f2 -> 0x808a660 -> 0x80b21b0 -> 0x8075a8a -> 0x806ba5c -> 0x806bc10 -> 0x806da64 -> 0x806dc59 -> 0x806dd77 -> 0x80c31d9 -> 0x80c2c11 -> 0x807"... #5 0x080bdb2f in i_panic (format=0x80d7838 "file %s: line %d (%s): assertion failed: (%s)") at failures.c:195 No locals. #6 0x0808e51e in mbox_sync_update_header_from (ctx=0x80474b0, mail=0x81059c8) at mbox-sync-update.c:458 __PRETTY_FUNCTION__ = "mbox_sync_update_header_from" #7 0x0808d56b in mbox_sync_rewrite (sync_ctx=0x80477f0, mail_ctx=0x0, end_offset=116254496, move_diff=20, extra_space=The value of variable 'extra_space' is distributed across several locations, and GDB cannot access its value.
) at mbox-sync-rewrite.c:362 new_mail_ctx = {sync_ctx = 0x80477f0, mail = {uid = 1, idx_seq = 0, keywords = {buffer = 0x0, element_size = 0}, flags = 8 '\b', uid_broken = 0, from_offset = 0, body_size = 1613, offset = 116250425, space = 0}, seq = 9347, hdr_offset = 116250425, body_offset = 116251545, header_first_change = 4294967295, header_last_change = 0, header = 0x80fa698, hdr_md5_sum = "Ê\020©:Ô\021Ãî*ÉLñ\\\001\217ä", content_length = 18446744073709551615, hdr_pos = {1083, 4294967295, 4294967295, 1096, 1108}, parsed_uid = 1, last_uid_updated_value = 0, last_uid_value_start_pos = 0, have_eoh = 1, need_rewrite = 0, seen_imapbase = 0, pseudo = 0, updated = 0, recent = 0, dirty = 0, imapbase_rewrite = 0, imapbase_updated = 0} offset = The value of variable 'offset' is distributed across several locations, and GDB cannot access its value.
DBX does slightly better:
(dbx) where [1] __lwp_kill(0x1, 0x6), at 0xfee505a7 [2] raise(0x6), at 0xfee06502 [3] abort(0x8047008, 0x80eedd8, 0x8046fd8, 0x80bdb2f, 0x80d7838, 0x8046fe4), at 0xfede4b8d =>[4] i_internal_fatal_handler(status = 135100472, fmt = (nil), args = (nil)), line 413 in "failures.c" [5] i_panic(format = 0x80d7838 "file %s: line %d (%s): assertion failed: (%s)", ...), line 195 in "failures.c" [6] mbox_sync_update_header_from(ctx = (nil), mail = 0x81059c8), line 458 in "mbox-sync-update.c" [7] mbox_sync_rewrite(sync_ctx = 0x80477f0, mail_ctx = (nil), end_offset = 116254496ULL, move_diff = 20LL, extra_space = 0, first_seq = 9347U, last_seq = 0), line 362 in "mbox-sync-rewrite.c" [8] mbox_sync_do(sync_ctx = 0x80477f0, flags = MBOX_SYNC_UNDIRTY), line 854 in "mbox-sync.c" [9] mbox_sync(mbox = (nil), flags = 0), line 1765 in "mbox-sync.c" [10] mbox_storage_sync_init(box = (nil), flags = 0), line 1836 in "mbox-sync.c" [11] mailbox_sync_init(box = 0x80478e8, flags = MAILBOX_SYNC_FLAG_FULL_READ), line 406 in "mail-storage.c" [12] imap_sync_nonselected(box = 0x8101c10, flags = MAILBOX_SYNC_FLAG_FULL_READ), line 196 in "imap-sync.c" [13] _cmd_select_full(cmd = 0x80fbd4c, readonly = 0), line 39 in "cmd-select.c" [14] cmd_select(cmd = 0x80fbd4c), line 92 in "cmd-select.c" [15] client_handle_input(cmd = 0x80fbd4c), line 332 in "client.c" [16] client_handle_input(cmd = 0x80fbd4c), line 389 in "client.c" [17] _client_input(context = 0x80fbd08), line 432 in "client.c" [18] io_loop_handler_run(ioloop = 0x80f9500), line 199 in "ioloop-poll.c" [19] io_loop_run(ioloop = (nil)), line 311 in "ioloop.c" [20] main(argc = 1, argv = 0x8047b18, envp = 0x8047b20), line 287 in "main.c"
(dbx) dump
fmt = (nil)
args = (nil)
status = 135100472
(dbx) up
Current function is i_panic
195 panic_handler(format, args);
(dbx) dump
format = 0x80d7838 "file %s: line %d (%s): assertion failed: (%s)"
args = 0x8047018 "hu^D^Hk\xd5^H^H\xb0t^D^H\xc8Y^P^Hhu^D^H\xd7\xd6^H^HHq^D^H`^N\xfb\xfe\xf8p^D^H\xc0\xa6^O^H\x84w^D^H\x98\xaf\xff\xfe\w^D^H^P^D"
(dbx) up
Current function is mbox_sync_update_header_from
458 i_assert(ctx->mail.uid == 0 || ctx->mail.uid == mail->uid);
(dbx) dump
ctx = (nil)
mail = 0x81059c8
__PRETTY_FUNCTION__ = "mbox_sync_update_header_from"
(dbx) up
Current function is mbox_sync_rewrite
362 mbox_sync_update_header_from(mail_ctx, &mails[idx]);
(dbx) dump
first_nonexpunged = 168U
move_diff = 20LL
ret = 0
mails = 0x81059c8
idx = 0
padding_per_mail = 4U
first_nonexpunged_idx = 0
expunged_space = 0
orig_next_uid = 56593U
sync_ctx = 0x80477f0
extra_space = 0
mail_ctx = (nil)
dest_offset = 0
count = 20U
last_seq = 0
orig_prev_msg_uid = 56592U
next_move_diff = 16ULL
end_offset = 116254496ULL
__PRETTY_FUNCTION__ = "mbox_sync_rewrite"
start_offset = 116250373ULL
offset = 0
first_seq = 9347U
next_end_offset = 116250425ULL
(dbx) up
Current function is mbox_sync_do
854 if (mbox_sync_rewrite(sync_ctx,
(dbx) dump
ret = 134510760
flags = MBOX_SYNC_UNDIRTY
sync_ctx = 0x80477f0
mail_ctx = RECORD
st = (nil)
__PRETTY_FUNCTION__ = "mbox_sync_do"
partial = 0
i = 0
(dbx) up
Current function is mbox_sync
1765 ret = mbox_sync_do(&sync_ctx, flags);
(dbx) dump
leave_dirty = 200U
sync_view = 0x81030d8
ret = 0
changed = 1
mbox = (nil)
flags = 0
sync_ctx = RECORD
delay_writes = 200U
seq = 4294967295U
lock_id = 3U
offset = 18446744073709551615ULL
index_sync_ctx = 0x81030a0
(dbx) up
Current function is mbox_storage_sync_init
1836 ret = mbox_sync(mbox, mbox_sync_flags);
(dbx) dump
ret = 0
mbox = 0x80478e8
flags = 0
mbox_sync_flags = 0
box = (nil)
(dbx) up
Current function is mailbox_sync_init
406 return box->v.sync_init(box, flags);
(dbx) dump
flags = MAILBOX_SYNC_FLAG_FULL_READ
box = 0x80478e8
(dbx) up
Current function is imap_sync_nonselected
196 ctx = mailbox_sync_init(box, flags);
(dbx) dump
ctx = (nil)
flags = MAILBOX_SYNC_FLAG_FULL_READ
box = 0x8101c10
sync_rec = RECORD
status = RECORD
(dbx) up
Current function is _cmd_select_full
39 if (imap_sync_nonselected(box, MAILBOX_SYNC_FLAG_FULL_READ) < 0) {
(dbx) dump
client = 0x80fbd08
storage = 0x80fba20
box = 0x8101c10
cmd = 0x80fbd4c
status = RECORD
readonly = 0
mailbox = 0x80fc020 "Mail/work"
(dbx) up
Current function is cmd_select
92 return _cmd_select_full(cmd, FALSE);
-- Daniel Price - Solaris Kernel Engineering - dp@eng.sun.com - blogs.sun.com/dp
On Fri, 2007-03-09 at 11:23 -0800, Dan Price wrote:
Today I've got another new crash I haven't seen before-- this is badly impacting the user in question-- since we're crashing on their inbox. This is running on our unoptimized -g only instance-- as requested yesterday.
Does it happen every time? If so, getting the mbox anonymized would help fixing this (http://wiki.dovecot.org/MboxProblems)
Should we go back to rc24?
I think that's a bad idea. It probably works even worse, and I wouldn't be surprised if it caused this crash to happen by breaking the mbox a bit.
Error: IMAP(foobar): file mbox-sync-update.c: line 458 (mbox_sync_update_header_from): assertion failed: (ctx->mail.uid == 0 || ctx->mail.uid == mail->uid)
new_mail_ctx = {sync_ctx = 0x80477f0, mail = {uid = 1, idx_seq = 0, keywords = {buffer = 0x0, element_size = 0}, flags = 8 '\b', uid_broken = 0, from_offset = 0, body_size = 1613, offset = 116250425, space = 0}, seq = 9347, hdr_offset = 116250425, body_offset = 116251545,
header_first_change = 4294967295, header_last_change = 0, header = 0x80fa698, hdr_md5_sum = "Ê\020©:Ô\021Ãî*ÉLñ\\\001\217ä", content_length = 18446744073709551615, hdr_pos = {1083, 4294967295, 4294967295, 1096, 1108}, parsed_uid = 1, last_uid_updated_value = 0, last_uid_value_start_pos = 0, have_eoh = 1, need_rewrite = 0, seen_imapbase = 0, pseudo = 0, updated = 0, recent = 0, dirty = 0, imapbase_rewrite = 0, imapbase_updated = 0}
Hmm. It looks like you have "X-UID: 1" header somewhere in the middle of the mbox, but for some reason Dovecot doesn't think it's invalid in there. I'll try to figure this out, but the anonymized mbox would make it easier.
On Fri, 2007-03-09 at 11:23 -0800, Dan Price wrote:
#7 0x0808d56b in mbox_sync_rewrite (sync_ctx=0x80477f0, mail_ctx=0x0, end_offset=116254496, move_diff=20, extra_space=The
5th try at fixing this code: http://dovecot.org/list/dovecot-cvs/2007-March/008017.html
Wonder if I'm still missing something..
On Fri, 2007-03-09 at 22:25 +0200, Timo Sirainen wrote:
On Fri, 2007-03-09 at 11:23 -0800, Dan Price wrote:
#7 0x0808d56b in mbox_sync_rewrite (sync_ctx=0x80477f0, mail_ctx=0x0, end_offset=116254496, move_diff=20, extra_space=The
5th try at fixing this code: http://dovecot.org/list/dovecot-cvs/2007-March/008017.html
Wonder if I'm still missing something..
Once more: http://dovecot.org/list/dovecot-cvs/2007-March/008023.html
On Sat, 2007-03-10 at 13:55 +0200, Timo Sirainen wrote:
On Fri, 2007-03-09 at 22:25 +0200, Timo Sirainen wrote:
On Fri, 2007-03-09 at 11:23 -0800, Dan Price wrote:
#7 0x0808d56b in mbox_sync_rewrite (sync_ctx=0x80477f0, mail_ctx=0x0, end_offset=116254496, move_diff=20, extra_space=The
5th try at fixing this code: http://dovecot.org/list/dovecot-cvs/2007-March/008017.html
Wonder if I'm still missing something..
Once more: http://dovecot.org/list/dovecot-cvs/2007-March/008023.html
Still wrong: http://dovecot.org/list/dovecot-cvs/2007-March/008041.html
There are also several other mbox fixes in CVS. I've been running stress tests for a while now and fixing things whenever they show up. rc27 should be a pretty good mbox-release :)
Timo Sirainen schrieb:
http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz http://dovecot.org/releases/dovecot-1.0.rc26.tar.gz.sig
- Maildir++ quota: We didn't handle NUL bytes in maildirsize files very well. Now the file is rebuilt when they're seen (NFS problem).
These can also happen locally with many of the metadata-only journaling file systems (reiserfs, XFS, ext3fs in data=writeback mode). It shouldn't happen with ordered write patches for reiserfs, ext3fs default mount options, or SOFTDEP or similar file systems.
participants (7)
-
Bill Cole
-
Christian Balzer
-
Dan Price
-
Jim Horner
-
Matthias Andree
-
Stewart Dean
-
Timo Sirainen