Solr FTS - message deletes not working as expected
I have Solr FTS enabled in dovecot. It is behaving differently than I would expect.
When I delete messages in Thunderbird normally, using IMAP to talk to dovecot, the deletion hits Solr right away. If I then ask Thunderbird to empty the trash, that delete also hits Solr immediately.
But if I use shift-delete in Thunderbird, which deletes the message immediately without going through Trash, things are different. One delete that I did (6 messages) took at least a minute before Solr saw the request. And on other tests that I ran, deleting one message, I never did see the delete request hit Solr. I waited for several minutes.
I use the shift-delete mechanism a lot more than the method that sends to trash. That way I do not need to remember to empty the trash.
Dovecot version is 2:2.3.16-2+ubuntu20.04 installed from the dovecot repo, not from distro packages. I don't think the Solr version matters, but just in case I am wrong, that is 8.10.1. I don't recall exactly what I changed in the solrconfig.xml and managed-schema files, but it should not be anything that affects how Solr FTS works. The problem seems to be that Solr FTS isn't sending deletes, not that Solr is behaving incorrectly.
I just discovered that trying to get the dovecot config failed:
root@bilbo:~# doveconf -n # 2.3.16 (7e2e900c1a): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.16 (09c29328) doveconf: Fatal: Error in configuration file /etc/dovecot/conf.d/10-master.conf line 64: Invalid size: $default_vsz_limit
After fixing that, this is what I get for the config:
root@bilbo:/etc/dovecot# doveconf -n # 2.3.16 (7e2e900c1a): /etc/dovecot/dovecot.conf # Pigeonhole version 0.5.16 (09c29328) # OS: Linux 5.11.0-1020-aws x86_64 Ubuntu 20.04.3 LTS ext4 # Hostname: REDACTED default_vsz_limit = 1 G dict { quota = mysql:/etc/dovecot/dovecot-dict-sql.conf.ext } first_valid_uid = 150 last_valid_uid = 150 listen = * mail_gid = mail mail_location = maildir:/var/vmail/%d/%u mail_plugins = " quota fts fts_solr" mail_privileged_group = mail 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 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 = solr fts_autoindex = yes fts_solr = url=http://localhost:8983/solr/dovecot/ quota = dict:User quota::proxy::quota quota_grace = 10%% quota_max_mail_size = 100M quota_status_nouser = DUNNO quota_status_overquota = 552 5.2.2 Mailbox is full quota_status_success = DUNNO sieve = file:/var/vmail/sieve/%d/%u/sieve;active=/var/vmail/sieve/%d/%u/.dovecot.sieve sieve_default = file:/var/vmail/global.sieve } postmaster_address = postmaster@REDACTED protocols = " imap lmtp sieve pop3" service auth { unix_listener /var/spool/postfix/private/auth { group = postfix mode = 0666 user = postfix } unix_listener auth-userdb { group = mail mode = 0666 user = vmail } } service dict { unix_listener dict { group = postfix mode = 0660 user = vmail } } service imap { vsz_limit = 1 G } service stats { unix_listener stats-reader { group = vmail mode = 0660 user = vmail } unix_listener stats-writer { group = vmail mode = 0660 user = vmail } } ssl_cert =
I repeated the delete test after fixing the config and there was no change -- the delete request never made it to Solr.
Reindexing completely for my dovecot install takes about 8 minutes. I have less than 150K messages. Reindexing for some could take hours or days. This is what I use to initiate a full reindex:
root@bilbo:~# cat /usr/local/sbin/reindexsolr #!/bin/sh DOVECOT_SOLR_URL_BASE="http://localhost:8983/solr/dovecot" DEL_ALL_QUERY_XML="<delete><query>*:*</query></delete>" MAIL_ROOT=/var/vmail
service dovecot stop
curl
"${DOVECOT_SOLR_URL_BASE}/update?commit=true&optimize=true"
-H "Content-Type: text/xml"
--data-binary "${DEL_ALL_QUERY_XML}"
find ${MAIL_ROOT} -name "dovecot.index*" -print0 | xargs -0 rm -f
service dovecot start
doveadm index -A -q '*'
On 10/26/21 12:18 PM, Shawn Heisey wrote:
But if I use shift-delete in Thunderbird, which deletes the message immediately without going through Trash, things are different.
Also, when I send a message with Thunderbird, which deletes the message in Drafts and adds one to Sent, I am not seeing a delete request in the Solr log. I do see the add. So this isn't limited to just the shift-delete workflow.
Thanks, Shawn
On 10/28/21 8:00 AM, Shawn Heisey wrote:
Also, when I send a message with Thunderbird, which deletes the message in Drafts and adds one to Sent, I am not seeing a delete request in the Solr log. I do see the add. So this isn't limited to just the shift-delete workflow.
I have confirmed this with multiple attempts.
I start a new message in Thunderbird. Then I wait around for that message to be auto-saved to Drafts. When that happens, I see an "add" request in the solr log.
Then I send the message. At that point, I see another add in Solr's log. Based on the message number in the add request, I know that this time the add happens in the Sent folder. But despite the fact that Thunderbird deletes the message from Drafts, Solr never sees a delete request. My dovecot version has been updated since the last time I indicated what version it is. Now it is "2:2.3.17-3+ubuntu20.04" from the dovecot repo, not the ubuntu repo. The same thing happened with 2.3.16.
As I mentioned in the first message on this thread, when shift-delete is used in Thunderbird to delete messages, that also never sends a delete to Solr.
Something somewhere is misbehaving. Is it Thunderbird accessing IMAP incorrectly, or is it Dovecot?
I will do a packet capture to see if maybe dovecot is sending requests that are not logged by Solr. That seems unlikely -- even bad requests should result in some kind of entry in the solr log.
Thanks, Shawn
Have you tried another client?
Thunderbird does NOT necessarily process expunges immediately. Depends on what else it is doing in the background. So you can't click delete in the UI and not immediately see anything on the backend and definitively correlate the two.
Another option is to ensure debug logging is enabled for Dovecot so you can see what the FTS code is doing. "log_debug = category=fts" and/or "mail_debug = yes" will help in that regard.
michael
On 11/02/2021 9:16 AM Shawn Heisey elyograg@elyograg.org wrote:
On 10/28/21 8:00 AM, Shawn Heisey wrote:
Also, when I send a message with Thunderbird, which deletes the message in Drafts and adds one to Sent, I am not seeing a delete request in the Solr log. I do see the add. So this isn't limited to just the shift-delete workflow.
I have confirmed this with multiple attempts.
I start a new message in Thunderbird. Then I wait around for that message to be auto-saved to Drafts. When that happens, I see an "add" request in the solr log.
Then I send the message. At that point, I see another add in Solr's log. Based on the message number in the add request, I know that this time the add happens in the Sent folder. But despite the fact that Thunderbird deletes the message from Drafts, Solr never sees a delete request. My dovecot version has been updated since the last time I indicated what version it is. Now it is "2:2.3.17-3+ubuntu20.04" from the dovecot repo, not the ubuntu repo. The same thing happened with 2.3.16.
As I mentioned in the first message on this thread, when shift-delete is used in Thunderbird to delete messages, that also never sends a delete to Solr.
Something somewhere is misbehaving. Is it Thunderbird accessing IMAP incorrectly, or is it Dovecot?
I will do a packet capture to see if maybe dovecot is sending requests that are not logged by Solr. That seems unlikely -- even bad requests should result in some kind of entry in the solr log.
Thanks, Shawn
On 11/3/21 12:38 PM, Michael Slusarz wrote:
Have you tried another client?
I only have two clients configured: Thunderbird 78.13.0 on Linux and Thunderbird 91.2.1 on Windows. Behavior is the same on both.
I will see if I can get another client configured. Windows Mail is included on Windows 10, so I can try that. I have a client system running Ubuntu, and I bet that there are a LOT of mail clients available there.
Thunderbird does NOT necessarily process expunges immediately. Depends on what else it is doing in the background. So you can't click delete in the UI and not immediately see anything on the backend and definitively correlate the two.
The message is deleted by dovecot immediately. I double checked this by purging a message on my Linux client and saw the message immediately disappear on my Windows client. It happened even faster than I would have expected. IMAP seems to be a very good protocol! I can't say it definitively without more evidence, but the problem *seems* to be in FTS, not imap or core dovecot.
Another option is to ensure debug logging is enabled for Dovecot so you can see what the FTS code is doing. "log_debug = category=fts" and/or "mail_debug = yes" will help in that regard.
When I have some real time available, I will look into debug logging. I'm going to have to research exactly where to put those config options.
Thanks, Shawn
On 11/03/2021 12:56 PM Shawn Heisey elyograg@elyograg.org wrote:
Thunderbird does NOT necessarily process expunges immediately. Depends on what else it is doing in the background. So you can't click delete in the UI and not immediately see anything on the backend and definitively correlate the two.
The message is deleted by dovecot immediately. I double checked this by purging a message on my Linux client and saw the message immediately disappear on my Windows client. It happened even faster than I would have expected. IMAP seems to be a very good protocol! I can't say it definitively without more evidence, but the problem *seems* to be in FTS, not imap or core dovecot.
For Solr, there's a code path in the FTS expunge code that will silently toss expunge requests:
if (ctx->last_indexed_uid == 0 ||
uid > ctx->last_indexed_uid + 100) {
/* don't waste time asking Solr to expunge a message that is
highly unlikely to be indexed at this time. */
return;
}So it's possible you are running into that.
michael
On 11/3/21 1:09 PM, Michael Slusarz wrote:
For Solr, there's a code path in the FTS expunge code that will silently toss expunge requests:
if (ctx->last_indexed_uid == 0 || uid > ctx->last_indexed_uid + 100) { /* don't waste time asking Solr to expunge a message that is highly unlikely to be indexed at this time. */ return; }So it's possible you are running into that.
Interesting. I don't know dovecot code well enough to figure out if maybe *every* expunge that happens is classified by that code as "unlikely to be indexed at this time." For the situations I have tried, I know that the message HAS been indexed and should be deleted from the index.
I was going to try removing that whole code construct and running it to see what happens, but it looks like the dovecot apt repo does not have source packages. When I add a deb-src line to the dovecot repo config, then do "apt update" (which works without complaint) followed by "apt-get source dovecot-solr" it pulls source packages from the Ubuntu repo, not the dovecot repo, so the source I end up with is for version 2.3.7, not the 2.3.17 that I am running.
Maybe I can do a custom compile of the source code and replace the /usr/lib/dovecot/modules/lib21_fts_solr_plugin.so file with what the compile produces. I'm going to try that, and see if it explodes. :)
Thanks, Shawn
On 11/3/2021 10:12 PM, Shawn Heisey wrote:
Maybe I can do a custom compile of the source code and replace the /usr/lib/dovecot/modules/lib21_fts_solr_plugin.so file with what the compile produces. I'm going to try that, and see if it explodes. :)
Bit of a problem trying to do this. I pulled the source code from github, switched to the release-2.3.17 branch, edited the source code file you referenced, and found that the "configure" script that is mentioned as the first step in the INSTALL.md file is not present. It's not present in any of the other branches I looked at either.
Then I downloaded the source archive from the main site, extracted it, and the configure script was included in that. After compiling, I found the .so file and moved it into place, and I will be testing it.
There should maybe be something in the README that describes what is needed to go from 'git clone' to the point where the instructions in INSTALL will work.
Thanks, Shawn
On 11/3/2021 11:10 PM, Shawn Heisey wrote:
Then I downloaded the source archive from the main site, extracted it, and the configure script was included in that. After compiling, I found the .so file and moved it into place, and I will be testing it.
The new library is significantly larger than the one it replaced, 332 KB versus 55KB. I'm guessing it has things like debug symbols that get stripped when it's packaged.
I see no change in behavior even with that section of code removed. I included some unique text in the body of the message I wrote and sent, and after sending I find both the copy in Drafts and the copy in Sent when I do a manual Solr query for that unique text. I waited several minutes ... I didn't hit Send and then immediately do the query.
Manual expunges of existing messages also are not sending a delete request to Solr. I waited several minutes for that too.
Thanks, Shawn
On 11/3/21 11:45 PM, Shawn Heisey wrote:
Manual expunges of existing messages also are not sending a delete request to Solr. I waited several minutes for that too.
Update on this, since you're all on the edge of your seat waiting. :)
I did a Send test with TypeApp, a mail client for Android. It behaved completely as expected: Dovecot immediately sent a delete request to Solr for the temporary message in Drafts.
So I went to Mozilla forums and started a discussion about what I am seeing with Thunderbird.
I did another test run with sending a message with unique text, and doing a manual Solr query for that unique text, I saw one result before sending and two results after sending. Watching the Solr log, no delete request was sent.
Then something completely unexpected: I needed to reboot the laptop, so I quit Thunderbird, and I hadn't yet closed my ssh session to the mail server, which was still tailing the solr log with a grep for delete messages. As soon as I did the quit, Solr got a delete request for the Drafts message. I did another test -- shift-delete a message, see that Solr did not see the delete request. And then after I waited a while, I quit Thunderbird again. Instantly got a delete request in Solr's log.
Definitely a Thunderbird problem, not dovecot. Thanks for your patience, everyone. I will pursue it with Mozilla now.
Thanks, Shawn
Op 18 nov. 2021 om 17:15 heeft Shawn Heisey elyograg@elyograg.org het volgende geschreven:
On 11/3/21 11:45 PM, Shawn Heisey wrote:
Manual expunges of existing messages also are not sending a delete request to Solr. I waited several minutes for that too.
Update on this, since you're all on the edge of your seat waiting. :)
Thanks for reporting back to the list.
I did a Send test with TypeApp, a mail client for Android. It behaved completely as expected: Dovecot immediately sent a delete request to Solr for the temporary message in Drafts.
So I went to Mozilla forums and started a discussion about what I am seeing with Thunderbird.
I did another test run with sending a message with unique text, and doing a manual Solr query for that unique text, I saw one result before sending and two results after sending. Watching the Solr log, no delete request was sent.
Then something completely unexpected: I needed to reboot the laptop, so I quit Thunderbird, and I hadn't yet closed my ssh session to the mail server, which was still tailing the solr log with a grep for delete messages. As soon as I did the quit, Solr got a delete request for the Drafts message. I did another test -- shift-delete a message, see that Solr did not see the delete request. And then after I waited a while, I quit Thunderbird again. Instantly got a delete request in Solr's log.
Definitely a Thunderbird problem, not dovecot. Thanks for your patience, everyone. I will pursue it with Mozilla now.
Thanks, Shawn
On 11/3/21 12:38 PM, Michael Slusarz wrote:
Have you tried another client?
I tried evolution on Linux.
I can't work out how to do an expunge in evolution. I'm not sure that it CAN do it. Whenever I delete a message, even with shift-delete, it is moved to the Trash folder (with delete and add sent to Solr), and then emptying the trash does delete from Solr. This is exactly how Thunderbird works with "normal" deletes.
I use shift-delete in Thunderbird a lot. Because when I delete a message, I really want it gone, I do not want another step to remember later -- emptying the trash folder.
The FTS behavior on sending a message with Thunderbird seems completely wrong. When I send a message with evolution, I do see a delete in the solr log, but there are still two results in a query for the special text I included in the message, so something is still not quite right.
I couldn't get Windows Mail to connect to my email account. Even with their advanced settings. I enter all the right information, and it just fails to connect. There are only "Use SSL" checkboxes, and I have no idea what port/security settings it's using. I can't tell it to use STARTTLS instead of mandatory TLS, or to use port 143 for imap and 587 for submission. I think that I did see a successful imap login in the mail.log from the attempt to add the account, but I had other clients running so it is difficult to be sure about that. I will have to close all my other clients (which includes an Android client) and try the connect again. When the account setup fails to connect, it doesn't have an option to add the account anyway (which Thunderbird does have), so I can't edit the account settings.
The android client seems to not have an expunge option for deleting messages either. It goes through Trash.
Thanks, Shawn
participants (3)
-
Michael Slusarz
-
Shawn Heisey
-
William Edwards