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 at 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. ;)
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.
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
2010-Jul-08 15:16 UTC
[Dovecot] Sieve user info log (was: problems with sieve under 2.0)
Hi Perry, Perry E. Metzger wrote:> By the way, I've noticed that there doesn't seem to be a good way for > the user to get information on what email message gets filed where by > sieve -- syslog information seems to be the sole data source > available. >Right. There is a per-user <main-script>.log file (e.g. .dovecot.sieve.log), but that will only be written when there are any errors. Info logging is indeed only available in the syslogs.> procmail has a facility where you can ask it to log every action it > takes. I looked around for a similar facility for sieve and I didn't > seem to see it. Did I miss something, or is it absent? >I DO see the merit of this. However, configuring this behavior is an interesting issue. If the user log verbosity is configured in the Dovecot userdb, it may in many cases still only be configurable by the administrator. An alternative solution would be to provide the logging configuration directly in the Sieve script; analogous to the way Procmail handles this. This would give users direct control. However, the Sieve specification and its extensions currently define no such facility. In fact, both Sieve and ManageSieve don't provide any means for the user to control what is logged during script execution. This would require some new or custom (vnd.dovecot.) Sieve or ManageSieve extension. However, defining a new extension like that is rarely useful unless clients implement support for it. Another problem is that users need filesystem access or some other custom (HTTP) interface to read the logs. This can be problematic when virtual users are involved. This too could be mended with an extension to the ManageSieve protocol. Alternatively, the Pigeonhole TODO list mentions a solution that writes logs as messages in a special IMAP-accessible folder, but I'm still not sure how practical that is. The above considerations may warrant starting a draft RFC on controlling and accessing Sieve runtime logs. But, I'm deviating from the original issue... what is it that you truly need right now? And for the Dovecot list, any other ideas on the above? Regards, Stephan.