[Dovecot] problems with sieve under 2.0...
I'm experimenting with a 2.0 setup, using the sieve plugin for 2.0 from mercurial.
Without sieve, everything seems to work fine. Once I put in a .dovecot.sieve file, though, nothing gets delivered, with the only hint of what's going wrong being this mess in syslog:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
Ideas?
-- Perry E. Metzger perry@piermont.com
On Wed, 2010-07-07 at 13:23 -0400, Perry E. Metzger wrote:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
I think this is related to the change I did recently. Or maybe it existed before that too.. I find the code a bit difficult to understand.
So trans->box is allocated and then tried to be opened. If opening fails, the trans->box is still left there (because some other code still wants to use it). But nothing remembers that opening it failed, so I guess the code goes to act_store_execute() with trans->box != NULL, but also not opened. Then it fails when it tries to create a transaction.
On 2010-07-07 3:33 PM, Timo Sirainen wrote:
On Wed, 2010-07-07 at 13:23 -0400, Perry E. Metzger wrote:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692 ) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
I think this is related to the change I did recently. Or maybe it existed before that too.. I find the code a bit difficult to understand.
So trans->box is allocated and then tried to be opened. If opening fails, the trans->box is still left there (because some other code still wants to use it). But nothing remembers that opening it failed, so I guess the code goes to act_store_execute() with trans->box != NULL, but also not opened. Then it fails when it tries to create a transaction.
Ah, so, obviously, the answer is: 42.
;)
Timo Sirainen <tss@iki.fi> writes:
On Wed, 2010-07-07 at 13:23 -0400, Perry E. Metzger wrote:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
I think this is related to the change I did recently. Or maybe it existed before that too.. I find the code a bit difficult to understand.
So trans->box is allocated and then tried to be opened. If opening fails, the trans->box is still left there (because some other code still wants to use it). But nothing remembers that opening it failed, so I guess the code goes to act_store_execute() with trans->box != NULL, but also not opened. Then it fails when it tries to create a transaction.
A datapoint: I poked around, made a guess, added:
lda_mailbox_autocreate = yes lda_mailbox_autosubscribe = yes
and the crash went away.
It may be that this was a very very bad way of the lda indicating that it could not create the mailbox.
Perry
Perry E. Metzger perry@piermont.com
Timo Sirainen wrote:
On Wed, 2010-07-07 at 13:23 -0400, Perry E. Metzger wrote:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692 ) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
I think this is related to the change I did recently. Or maybe it existed before that too.. I find the code a bit difficult to understand.
It is related to that change, yes. I fixed the problem, but I am still not entirely happy with the error handling of the store action.
So trans->box is allocated and then tried to be opened. If opening fails, the trans->box is still left there (because some other code still wants to use it). But nothing remembers that opening it failed, so I guess the code goes to act_store_execute() with trans->box != NULL, but also not opened. Then it fails when it tries to create a transaction.
Exactly.
Regards,
Stephan.
Stephan Bosch <stephan@rename-it.nl> writes:
It is related to that change, yes. I fixed the problem, but I am still not entirely happy with the error handling of the store action.
It would be best, I think, if the system failed safe (i.e. if it did not lose the user's mail in case of error, but rather stored it in the main mailbox or in some sort of last ditch error mailbox.)
It should also report a reasonably sane error in syslog...
Perry
Perry E. Metzger wrote:
Stephan Bosch <stephan@rename-it.nl> writes:
It is related to that change, yes. I fixed the problem, but I am still not entirely happy with the error handling of the store action.
It would be best, I think, if the system failed safe (i.e. if it did not lose the user's mail in case of error, but rather stored it in the main mailbox or in some sort of last ditch error mailbox.)
That's exactly what it does now and if the Sieve engine is to blame for losing e-mail, it is always a bug.
Anyway, that kind of error handling is not what I meant. It pertains to the problem that Timo described and the passing of error codes and error strings between the Dovecot API and the Sieve engine in general. That is all a bit ugly right now.
It should also report a reasonably sane error in syslog...
This type of error is mainly useful for developers, much like a Segfault. Occurences of this kind are always a bug and are fixed as soon as possible. Considering the fact that I've added a test for this case in the test suite, it should not surface again in the future.
Regards,
Stephan.
Perry E. Metzger wrote:
I'm experimenting with a 2.0 setup, using the sieve plugin for 2.0 from mercurial.
Without sieve, everything seems to work fine. Once I put in a .dovecot.sieve file, though, nothing gets delivered, with the only hint of what's going wrong being this mess in syslog:
Jul 7 13:18:00 bellman dovecot: lda(perry): Panic: file index-transaction.c: line 70 (index_transaction_init): assertion failed: (box->opened) Jul 7 13:18:00 bellman dovecot: lda(perry): Error: Raw backtrace: /usr/local/lib/dovecot/libdovecot.so.0 [0x7f55e07fedd2] -> /usr/local/lib/dovecot/libdovecot.so.0(i_syslog_fatal_handler+0x2b) [0x7f55e07fee7b] -> /usr/local/lib/dovecot/libdovecot.so.0(i_error+0) [0x7f55e07ff1e3] -> /usr/local/lib/dovecot/libdovecot-storage.so.0 [0x7f55e0cbdc31] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(index_transaction_begin+0x3f) [0x7f55e0cbdc7f] -> /usr/local/lib/dovecot/libdovecot-storage.so.0(mailbox_transaction_begin+0x13) [0x7f55e0c750d3] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0 [0x7f55df800724] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_result_execute+0x173) [0x7f55df7f9183] -> /usr/local/lib/dovecot/libdovecot-sieve.so.0(sieve_execute+0x7d) [0x7f55df807b5d] -> /usr/local/lib/dovecot/lib90_sieve_plugin.so [0x7f55dfa3bbed] -> /usr/local/lib/dovecot/libdovecot-lda.so.0(mail_deliver+0x44) [0x7f55e0a41e84] -> /usr/local/libexec/dovecot/dovecot-lda(main+0x692) [0x402f72] -> /lib/libc.so.6(__libc_start_main+0xe6) [0x7f55e00831a6] -> /usr/local/libexec/dovecot/dovecot-lda [0x402819]
Fixed:
http://hg.rename-it.nl/dovecot-2.0-pigeonhole/rev/703f82bb2b09
Regards,
Stephan.
participants (4)
-
Charles Marcus
-
Perry E. Metzger
-
Stephan Bosch
-
Timo Sirainen