slusarz / dovecot-fts-flatcurve

Dovecot FTS Flatcurve plugin (Xapian)
https://slusarz.github.io/dovecot-fts-flatcurve/
GNU Lesser General Public License v2.1
40 stars 8 forks source link

backtrace during indexing #37

Closed edvil closed 1 year ago

edvil commented 1 year ago

I am currently testing dovecot-fts-flatcurve with dovecot 2.3.19.

I encountered the following error indexing my INBOX:


doveadm -D index -u user@domain.tld INBOX
<snip>
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: Mailbox opened
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve: Xapian library version: 1.4.18
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Opened DB (RO) messages=0 version=1 shards=1
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Last UID uid=0
Nov 17 14:02:07 doveadm(user@domain.tld): Info: INBOX: Caching mails seq=1..8020
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Last UID uid=0
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 912: Opened mail because: fts indexing
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Opened DB (RW; current.1668686821134633) messages=0 version=1
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=912
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 913: Opened mail because: fts indexing
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=913
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 914: Opened mail because: fts indexing
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=914
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 915: Opened mail because: fts indexing
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=915
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 916: Opened mail because: fts indexing
Nov 17 14:02:07 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=916
<snip>
Nov 17 14:02:09 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=1515
Nov 17 14:02:09 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 1516: Opened mail because: fts indexing
Nov 17 14:02:09 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=1516
Nov 17 14:02:09 doveadm(user@domain.tld): Debug: Mailbox INBOX: UID 1517: Opened mail because: fts indexing
Nov 17 14:02:09 doveadm(user@domain.tld): Debug: fts-flatcurve(INBOX): Indexing uid=1517
Nov 17 13:48:18 doveadm(user@domain.tld): Panic: file fts-filter.c: line 137 (fts_filter_filter): assertion failed: ((*token)[0] != '\0')
Nov 17 13:48:18 doveadm(user@domain.tld): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x42) [0x7f0ab16ba582] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f0ab16ba69e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1022fb) [0x7f0ab16c72fb] -> /usr/lib/dovecot/libdovecot.so.0(+0x102331) [0x7f0ab16c7331] -> /usr/lib/dovecot/libdovecot.so.0(+0x55589) [0x7f0ab161a589] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xa40a) [0x7f0ab0f1440a] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(fts_filter_filter+0x27) [0x7f0ab0f1f447] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xbc5b) [0x7f0ab0f15c5b] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xbef5) [0x7f0ab0f15ef5] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(fts_build_mail+0x5df) [0x7f0ab0f167af] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0x126c8) [0x7f0ab0f1c6c8] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_precache+0x30) [0x7f0ab17e9fb0] -> doveadm(+0x39df7) [0x557302f5cdf7] -> doveadm(+0x34a45) [0x557302f57a45] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x2ca) [0x557302f58afa] -> doveadm(doveadm_cmd_run_ver2+0x501) [0x557302f691b1] -> doveadm(doveadm_cmd_try_run_ver2+0x3a) [0x557302f6922a] -> doveadm(main+0x1d4) [0x557302f47e24] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xea) [0x7f0ab1275d0a] -> doveadm(_start+0x2a) [0x557302f4808a]

Dovecot configuration:

ii  dovecot-core                           2:2.3.19.1-2+debian11          amd64        secure POP3/IMAP server - core files
ii  dovecot-fts-flatcurve                  0.3.3-2                        amd64        FTS plugin for dovecot based on Xapian
doveconf -n:
base_dir = /var/run/dovecot/
deliver_log_format = msgid=%m: from_envelope=%e from=%f subject=%s size=%w %$ delivery_time=%{delivery_time} session_time=%{session_time} storage_id=%{storage_id}
imap_client_workarounds = delay-newmail tb-extra-mailbox-sep tb-lsub-flags
imap_id_log = *
imap_id_retain = yes
imap_id_send = *
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
listen = x.x.x.x
lmtp_rcpt_check_quota = yes
lmtp_save_to_detail_mailbox = yes
login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c %k session=<%{session}>
mail_gid = vmail
mail_location = mbox:~/mail:INBOX=/var/mail/%u
mail_plugins = lazy_expunge acl quota fts fts_flatcurve
mail_uid = vmail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext
namespace inbox {
  inbox = yes
  location = 
  mailbox .EXPUNGED {
    autoexpunge = 1 weeks
    autoexpunge_max_mails = 100000
  }
  mailbox Drafts {
    special_use = \Drafts
  }
  mailbox Junk {
    special_use = \Junk
  }
  mailbox Sent {
    special_use = \Sent
  }
  mailbox "Sent Messages" {
    special_use = \Sent
  }
  mailbox Trash {
    special_use = \Trash
  }
  prefix = 
}
passdb {
  args = /etc/dovecot/dovecot-sql.conf.ext
  driver = sql
}
plugin {
  fts = flatcurve
  fts_autoindex = no
  fts_enforced = yes
  fts_filters = snowball stopwords
  fts_filters_en = lowercase snowball english-possessive stopwords
  fts_flatcurve_commit_limit = 500
  fts_flatcurve_max_term_size = 30
  fts_flatcurve_min_term_size = 2
  fts_flatcurve_optimize_limit = 10
  fts_flatcurve_rotate_size = 5000
  fts_flatcurve_rotate_time = 5000
  fts_flatcurve_substring_search = no
  fts_index_timeout = 60s
  fts_languages = en es de fr
  fts_tokenizer_generic = algorithm=simple
  fts_tokenizers = generic email-address
  mail_log_events = delete undelete expunge copy mailbox_delete mailbox_rename flag_change append
  mail_log_fields = uid box msgid from subject size vsize flags
  sieve = file:~/sieve;active=~/.dovecot.sieve
}
protocols = pop3 imap sieve lmtp sieve
service auth {
  unix_listener /var/spool/postfix/private/auth {
    group = postfix
    mode = 0666
    user = postfix
  }
}
service imap-login {
  inet_listener imap {
    port = 143
  }
  inet_listener imaps {
    port = 993
    ssl = yes
  }
}
service lmtp {
  unix_listener /var/spool/postfix/private/dovecot-lmtp {
    group = postfix
    mode = 0600
    user = postfix
  }
}
service managesieve-login {
  inet_listener sieve {
    port = 4190
  }
}
service pop3-login {
  inet_listener pop3 {
    port = 110
  }
  inet_listener pop3s {
    port = 995
    ssl = yes
  }
}
service stats {
  unix_listener stats-reader {
    group = vmail
    mode = 0660
    user = vmail
  }
  unix_listener stats-writer {
    group = vmail
    mode = 0660
    user = vmail
  }
}
ssl_cert = </etc/letsencrypt/live/xxxx/fullchain.pem
ssl_client_ca_dir = /etc/ssl/certs
ssl_dh = # hidden, use -P to show it
ssl_key = # hidden, use -P to show it
submission_host = x.x.x.x
submission_relay_host = 127.0.0.1
submission_relay_trusted = yes
userdb {
  args = /etc/dovecot/dovecot-sql.conf.ext
  driver = sql
}
protocol lmtp {
  mail_plugins = lazy_expunge acl sieve
}
protocol lda {
  mail_plugins = lazy_expunge acl sieve
}
protocol imap {
  mail_max_userip_connections = 30
  mail_plugins = lazy_expunge acl imap_sieve imap_filter_sieve
}
protocol sieve {
  managesieve_logout_format = bytes=%i/%o
  managesieve_max_compile_errors = 5
  managesieve_max_line_length = 64 k
}
}

User configuration in sql:

+----------+------------+-----------------------------------------------------------------------------------------------------------+------------+-------+-------+--------+------------------+---------------------+
| username | domain     | password                                                                                                  | home       | uid   | gid   | active | mail             | email               |
+----------+------------+-----------------------------------------------------------------------------------------------------------+------------+-------+-------+--------+------------------+---------------------+
| user | domain.tld | xxxxx| /var/vmail | vmail | vmail | Y      | mdbox:/var/vmail | user@domain.tld |
+----------+------------+-----------------------------------------------------------------------------------------------------------+------------+-------+-------+--------+------------------+---------------------+

I am using mdbox mailbox format.

Thanks

slusarz commented 1 year ago

Thank you for your report.

Key portion of your log:

Nov 17 13:48:18 doveadm(user@domain.tld): Panic: file fts-filter.c: line 137 (fts_filter_filter): assertion failed: ((*token)[0] != '\0') Nov 17 13:48:18 doveadm(user@domain.tld): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(backtrace_append+0x42) [0x7f0ab16ba582] -> /usr/lib/dovecot/libdovecot.so.0(backtrace_get+0x1e) [0x7f0ab16ba69e] -> /usr/lib/dovecot/libdovecot.so.0(+0x1022fb) [0x7f0ab16c72fb] -> /usr/lib/dovecot/libdovecot.so.0(+0x102331) [0x7f0ab16c7331] -> /usr/lib/dovecot/libdovecot.so.0(+0x55589) [0x7f0ab161a589] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xa40a) [0x7f0ab0f1440a] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(fts_filter_filter+0x27) [0x7f0ab0f1f447] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xbc5b) [0x7f0ab0f15c5b] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0xbef5) [0x7f0ab0f15ef5] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(fts_build_mail+0x5df) [0x7f0ab0f167af] -> /usr/lib/dovecot/modules/lib20_fts_plugin.so(+0x126c8) [0x7f0ab0f1c6c8] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_precache+0x30) [0x7f0ab17e9fb0] -> doveadm(+0x39df7) [0x557302f5cdf7] -> doveadm(+0x34a45) [0x557302f57a45] -> doveadm(doveadm_cmd_ver2_to_mail_cmd_wrapper+0x2ca) [0x557302f58afa] -> doveadm(doveadm_cmd_run_ver2+0x501) [0x557302f691b1] -> doveadm(doveadm_cmd_try_run_ver2+0x3a) [0x557302f6922a] -> doveadm(main+0x1d4) [0x557302f47e24] -> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xea) [0x7f0ab1275d0a] -> doveadm(_start+0x2a) [0x557302f4808a]

As indicated by these two lines, the program is crashing in the FTS filtering code (lib-fts, specifically). This is the core Dovecot code that filters/tokenizes terms before it is passed to a FTS backend driver, such as flatcurve. Specifically, this is erroring out in an assert for a non-empty string that has a NULL as the first character.

Thus, this is not an issue with flatcurve but is instead an issue with core Dovecot and should be reported there. If possible, isolate the problem message (it appears to be either UID 1517 or maybe UID 1518 in the mailbox) to make reporting and debugging easier. You could also try to play with your list of configured fts_filters to see if you can isolate which filter, or combo of filters, is causing the issue.

slusarz commented 1 year ago

Confirmed with team that this is an issue with Dovecot core snowball filtering (not flatcurve). Fix/patch will appear in core soon. Closing.