lmtp-Eroor

[Aki Tuomi]

On 27.11.2017 08:37, Jakob Schürz wrote:
> Hi!
>
>
> Am 2017-11-27 um 01:35 schrieb Stephan Bosch:
>> Op 11/27/2017 om 12:53 AM schreef Jakob Schürz:
>>> Hi There!
>>>
>>> I can not find anything about this message:
>>>
>>> dovecot[23202]: lmtp(jakob): Debug: Mailbox <lmtp DATA>: Opened mail
>>> UID=1 because: header Message-ID (Cache file is unusable)
>>> dovecot[23202]: lmtp(jakob): Debug: Mailbox <lmtp DATA>: Opened mail
>>> UID=1 because: virtual size (Cache file is unusable)
>> These are debug messages. The incoming LMTP DATA stream is a raw
>> message, which has no cache (hence 'Cache file is unusable'). This is
>> normal.
> Ok. I did a lot of debugging the last weeks for another bug. But I've
> never seen this message before. So i thought it is new. But obviously I
> haven't seen this, but it was there.

It just means that the cache file wasn't available, because it had been
removed. It's not a serious problem.

>>> And the next is:
>>> dovecot[23202]: lmtp(jakob): rphlK01SG1qiWgAAk1Mx3g: sieve:
>>> msgid=<E1eJ6cv-000624-Je at xxx.xxxxxxx.xxx>: stored mail into mailbox
>>> 'INBOX/TESTORDNER'
>> Your Sieve script stored the message in INBOX/TESTORDNER. Also not strange>
>>> It happens when a mail gets delivered through lmtp.
>> Any particular problem you're facing?
> I don't know, if this is another or the same problem.
> Since i tried to find out, what is this unusable cache-file, I realized
> this error-Message, sending an Email with Thunderbird (not from
> commandline with mail):
>
>
> Nov 27 07:35:42 aldebaran dovecot[706]: imap(jakob): Debug: Mailbox
> INBOX/Sent: Opened mail UID=0 because: mail stream
> Nov 27 07:35:42 aldebaran spamd[1258]: prefork: child states: II
> Nov 27 07:35:42 aldebaran dovecot[706]: imap(jakob): Error: Log
> synchronization error at seq=5,offset=25508 for
> /var/lib/dovecot/db/indexes/Maildir/jakob/Sent/dovecot.index: Append
> with UID 2431, but next_uid = 2432
> Nov 27 07:35:42 aldebaran dovecot[706]: imap(jakob): Warning: fscking
> index file /var/lib/dovecot/db/indexes/Maildir/jakob/Sent/dovecot.index
> Nov 27 07:35:42 aldebaran dovecot[706]: imap(jakob): save:
> box=INBOX/Sent, uid=2431,
> msgid=<010ba14b-3791-11af-ac3a-6fd574f6a852 at xxxxxxxx.xxx>, size=2693

This is caused by the following

> And then i got this many times:
>
> Nov 27 07:28:43 aldebaran dovecot[706]: imap(jakob): Debug: Mailbox
> INBOX/Sent: Opened mail UID=2427 because: access
> Nov 27 07:28:43 aldebaran dovecot[706]: imap(jakob): Debug: Mailbox
> INBOX/Sent: Opened mail UID=2427 because: mail stream
> Nov 27 07:28:43 aldebaran dovecot[706]: imap(jakob): Panic: file
> mail-index.c: line 679 (mail_index_close): assertion failed:
> (index->open_count > 0)
> Nov 27 07:28:43 aldebaran dovecot[706]: imap(jakob): Error: Raw
> backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x95272) [0x7f4e03f4b272]
> -> /usr/lib/dovecot/libdovecot.so.0(+0x9536d) [0x7f4e03f4b36d] ->
> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f4e03ee1951] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(+0xe0d18) [0x7f4e042b7d18] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(+0xc6f91) [0x7f4e0429df91] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(+0xc7023) [0x7f4e0429e023] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(+0xbe6c4) [0x7f4e042956c4] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_free+0x19)
> [0x7f4e042176b9] ->
> /usr/lib/dovecot/modules/lib20_virtual_plugin.so(+0x9dac)
> [0x7f4e028cddac] ->
> /usr/lib/dovecot/modules/lib20_virtual_plugin.so(+0x9e59)
> [0x7f4e028cde59] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_close+0x1a)
> [0x7f4e0421762a] ->
> /usr/lib/dovecot/modules/lib20_virtual_plugin.so(+0x9e0c)
> [0x7f4e028cde0c] ->
> /usr/lib/dovecot/modules/lib20_virtual_plugin.so(+0x9e59)
> [0x7f4e028cde59] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_close+0x1a)
> [0x7f4e0421762a] ->
> /usr/lib/dovecot/libdovecot-storage.so.0(mailbox_free+0x13)
> [0x7f4e042176b3] -> dovecot/imap [jakob 192.168.0.14 select](+0x142eb)
> [0x560e9dc052eb] -> dovecot/imap [jakob 192.168.0.14
> select](cmd_select_full+0x129) [0x560e9dc05449] -> dovecot/imap [jakob
> 192.168.0.14 select](command_exec+0xa5) [0x560e9dc0c735] -> dovecot/imap
> [jakob 192.168.0.14 select](+0x199c2) [0x560e9dc0a9c2] -> dovecot/imap
> [jakob 192.168.0.14 select](+0x19a4c) [0x560e9dc0aa4c] -> dovecot/imap
> [jakob 192.168.0.14 select](client_handle_input+0x1b5) [0x560e9dc0ae55]
> -> dovecot/imap [jakob 192.168.0.14 select](client_input+0x86)
> [0x560e9dc0b3c6] ->
> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x52) [0x7f4e03f5fdd2]
> -> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x109)
> [0x7f4e03f61409] ->
> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x3c)
> [0x7f4e03f5fe6c] -> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38)
> [0x7f4e03f60018] ->
> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13)
> [0x7f4e03ee7e93] -> dovecot/imap [jakob 192.168.0.14 select](main+0x328)
> [0x560e9dbfde68]
> Nov 27 07:28:43 aldebaran dovecot[706]: imap(jakob): Fatal: master:
> service(imap): child 6631 killed with signal 6 (core dumps disabled)
>
> What is this?
>
> jakob
>
There has been significant amount of fixes to virtual plugin after
2.2.27. It's possible it's fixed, I was not able to directly confirm
this, would need to have your virtual folder configuration to try.

Aki