grosjo / fts-xapian

Dovecot FTS plugin based on Xapian
GNU Lesser General Public License v2.1
91 stars 19 forks source link

Ubuntu 22.04 dovecot-fts-xapian package unusable #145

Closed an0nz closed 1 month ago

an0nz commented 7 months ago

fts-xapian is effectively broken on Ubuntu 22.04 due to bugs in the old packaged version (dovecot-fts-xapian v1.5.2-1build1)

After installation, configuration, and indexing on a live mail server with around 500GB of mail and users with up to 70GB mailboxes, users are unable to search their INBOX. Searching smaller folders such as Sent work correctly.

Compiling v1.5.7 from source resolved the below issue. Would be great if the latest version could be pushed to Ubuntu repo's for current LTS branches.

Server

Mailbox

FTS config

plugin {
    fts = xapian
    fts_xapian = partial=3 full=18 verbose=1

    fts_autoindex = yes
    fts_enforced = yes
    fts_tokenizers = generic email-address

    # Exclude folders.
    fts_autoindex_exclude = \Trash
    fts_autoindex_exclude2 = \Junk
    fts_autoindex_exclude3 = \INBOX.spam
    fts_autoindex_exclude4 = \INBOX.Trash
    fts_autoindex_exclude5 = \spam
    fts_autoindex_exclude6 = \INBOX.Junk
}
service indexer-worker {
    vsz_limit = 2G
}

Logs when searching INBOX (Fails and time out after 5 minutes)

Jan 5 20:40:33 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=512 MB Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:40:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Get last UID of INBOX (79704f04f3940863160a0900b1498442) = 13596 ... Wait 5 minutes with no logs Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: Disconnected: Connection closed (UID SORT running for 300.333 + waiting input for 0.021 secs, 57 B in + 0 B out, state=wait-external) in=172 out=1756 deleted=0 expun ged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Deinit /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes) Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Unset box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: fts_backend_xapian_release (unset_box) Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248514><+8Uauj4OqJx/AAAB>: FTS Xapian: Committed 'unset_box' in 0 ms Jan 5 20:45:33 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured Jan 5 20:45:33 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=512 MB Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248920><jbgDzD4OINJ/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248920><jbgDzD4OINJ/AAAB>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=512 MB Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:45:33 mail dovecot: imap(user@domain.com)<2248919><15wDzD4OFtJ/AAAB>: FTS Xapian: Get last UID of INBOX (79704f04f3940863160a0900b1498442) = 13596 Jan 5 20:46:45 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured

Logs when searching Sent (Works correctly)

Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Set box 'Sent' (5d1e693bf2940863160a0900b1498442) Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Get last UID of Sent (5d1e693bf2940863160a0900b1498442) = 1357 Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_refresh Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_release (refresh) Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Committed 'refresh' in 0 ms Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Set box 'Sent' (5d1e693bf2940863160a0900b1498442) Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Get last UID of Sent (5d1e693bf2940863160a0900b1498442) = 1357 Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_lookup Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Set box 'Sent' (5d1e693bf2940863160a0900b1498442) Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: QUery '' -> 0 results Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: 0 results in 0 ms Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: fts_backend_xapian_lookup Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: Set box 'Sent' (5d1e693bf2940863160a0900b1498442) Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: QUery '(subject:"css" AND subject:"spamhaus") OR (from:"css" AND from:"spamhaus")' -> 0 results Jan 5 20:30:53 mail dovecot: imap(user@domain.com)<2246757><5zhPlj4ORJ5/AAAB>: FTS Xapian: 0 results in 18 ms

Solution Compile from source (v1.5.7) and restart dovecot

Logs when searching INBOX (Works as expected) on fts-xapian v1.5.7 compiled from source, my main concern is if the Ubuntu package is updated to an older version and replaces the updated files

Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Get last UID of INBOX (79704f04f3940863160a0900b1498442) = 13617 Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_refresh Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_release (refresh) Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Committed 'refresh' in 0 ms Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_release (refresh) - done Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Get last UID of INBOX (79704f04f3940863160a0900b1498442) = 13617 Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: fts_backend_xapian_lookup Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: QUery '(body:"css" AND body:"spamhaus")' -> 2 results Jan 5 21:05:11 mail dovecot: imap(user@domain.com)<2257610><lHN2ET8OTNZ/AAAB>: FTS Xapian: 2 results in 1 ms Jan 5 21:07:59 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured Jan 5 21:07:59 mail dovecot: imap(user@domain.com)<2258179><Yck1HD8OLI1/AAAB>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 21:07:59 mail dovecot: imap(user@domain.com)<2258179><Yck1HD8OLI1/AAAB>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=208 MB Jan 5 21:08:21 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 5 21:08:21 mail dovecot: imap(user@domain.com)<2258252><6AiGHT8OatfOUGCq>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 5 21:08:21 mail dovecot: imap(user@domain.com)<2258252><6AiGHT8OatfOUGCq>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=259 MB Jan 5 21:08:21 mail dovecot: imap(user@domain.com)<2258252><6AiGHT8OatfOUGCq>: Disconnected: Logged out in=28 out=1068 deleted=0 expunged=0 trashed=0 hdr_count=0 hdr_bytes=0 body_count=0 body_bytes=0 Jan 5 21:08:21 mail dovecot: imap(user@domain.com)<2258252><6AiGHT8OatfOUGCq>: FTS Xapian: Deinit /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes)

grosjo commented 7 months ago

Hi

Ubuntu Package is maintained by Joe Nahmias @jnahmias can you help ? Thank you

an0nz commented 7 months ago

Hi @grosjo,

Interestingly after upgrade I also ran into the same error a day later on multiple mailboxes, the solution was a rescan then index for the 2 I had access to, I did not try just running an index without the rescan.

For all other mailboxes I have run doveadm index without the rescan in case it was a compatibility issue with the index DB from the previous version. I will monitor and see if that fixes it permanently or not.

Hopefully the Ubuntu packages can be updated by @jnahmias to address all the other bugs you have already fixed.

an0nz commented 7 months ago

Interestingly this time there is no 5 minute timeout but it does hang at the same point (Get last UID of INBOX), maybe fts-xapian is crashing here but I see no log entries that would indicate this

Jan 8 02:19:43 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 8 02:19:43 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 8 02:19:43 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=232 MB Jan 8 02:19:44 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: fts_backend_xapian_get_last_uid Jan 8 02:19:44 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: Set box 'INBOX' (79704f04f3940863160a0900b1498442) Jan 8 02:19:44 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 8 02:19:44 mail dovecot: imap(user@domain.com)<2966264>: FTS Xapian: Get last UID of INBOX (79704f04f3940863160a0900b1498442) = 13625 Jan 8 02:21:34 mail dovecot: imap-login: Login: user=user@domain.com, method=PLAIN, rip=yyy.yyy.yyy.yyy, lip=xxx.xxx.xxx.xxx, TLS, TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) Jan 8 02:21:34 mail dovecot: imap(user@domain.com)<2966866>: FTS Xapian: Index path = /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes Jan 8 02:21:34 mail dovecot: imap(user@domain.com)<2966866>: FTS Xapian: Starting with partial=3 full=18 verbose=1 lowmemory=250 MB vs freemem=512 MB Jan 8 02:21:35 mail dovecot: imap(user@domain.com)<2966866>: Disconnected: Logged out in=933 out=97495 deleted=0 expunged=0 trashed=0 hdr_count=35 hdr_bytes=61913 body_count=0 body_bytes=0 Jan 8 02:21:35 mail dovecot: imap(user@domain.com)<2966866>: FTS Xapian: Deinit /var/vmail/vmail1/domain.com/user//Maildir/xapian-indexes)

grosjo commented 7 months ago

@jnahmias Can you push Version 1.5.8 ? Thank you

grosjo commented 6 months ago

https://tracker.debian.org/pkg/dovecot-fts-xapian

Getting updated

grosjo commented 1 month ago

debian/Ubuntu upodated