dovecot fts hangs on search
André Rodier
andre at rodier.me
Wed May 2 13:45:44 EEST 2018
On 2018-05-01 21:29, André Rodier wrote:
> On 2018-05-01 07:22, André Rodier wrote:
>> Hello,
>>
>> I am trying to use Doevecot fts, with solr the script provided.
>>
>> To rebuild the index, I use the command:
>> doveadm -D index -u mirina 'inbox'
>>
>> To rescan, I use: doveadm -D fts rescan -u mirina
>>
>> But when I do a search, with doveadm, the program hangs:
>>
>> doveadm -D search -u mirina text Madagascar
>>
>>> Debug: Loading modules from directory: /usr/lib/dovecot/modules
>>> Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
>>> Debug: Module loaded: /usr/lib/dovecot/modules/lib20_fts_plugin.so
>>> Debug: Module loaded:
>>> /usr/lib/dovecot/modules/lib21_fts_solr_plugin.so
>>> Debug: Loading modules from directory:
>>> /usr/lib/dovecot/modules/doveadm
>>> Debug: Skipping module doveadm_acl_plugin, because dlopen() failed:
>>> /usr/lib/dovecot/modules/doveadm/lib10_doveadm_acl_plugin.so:
>>> undefined symbol: acl_lookup_dict_iterate_visible_next (this is
>>> usually intentional, so just ignore this message)
>>> Debug: Skipping module doveadm_expire_plugin, because dlopen()
>>> failed:
>>> /usr/lib/dovecot/modules/doveadm/lib10_doveadm_expire_plugin.so:
>>> undefined symbol: expire_set_deinit (this is usually intentional, so
>>> just ignore this message)
>>> Debug: Module loaded:
>>> /usr/lib/dovecot/modules/doveadm/lib10_doveadm_quota_plugin.so
>>> Debug: Module loaded:
>>> /usr/lib/dovecot/modules/doveadm/lib10_doveadm_sieve_plugin.so
>>> Debug: Skipping module doveadm_fts_lucene_plugin, because dlopen()
>>> failed:
>>> /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_lucene_plugin.so:
>>> undefined symbol: lucene_index_iter_deinit (this is usually
>>> intentional, so just ignore this m$
>>> ssage)
>>> Debug: Module loaded:
>>> /usr/lib/dovecot/modules/doveadm/lib20_doveadm_fts_plugin.so
>>> Debug: Skipping module doveadm_mail_crypt_plugin, because dlopen()
>>> failed:
>>> /usr/lib/dovecot/modules/doveadm/libdoveadm_mail_crypt_plugin.so:
>>> undefined symbol: mail_crypt_box_get_pvt_digests (this is usually
>>> intentional, so just ignore thi$ message)
>>> doveadm(mirina): Debug: auth USER input: mirina
>>> home=/home/users/mirina uid=1002 gid=1001 mail=mirina at homebox.space
>>> doveadm(mirina): Debug: Added userdb setting:
>>> mail=mirina at homebox.space doveadm(mirina): Debug: Effective uid=1002,
>>> gid=1001, home=/home/users/mirina
>>> doveadm(mirina): Debug: Quota root: name=User quota backend=maildir
>>> args=
>>> doveadm(mirina): Debug: Quota rule: root=User quota mailbox=*
>>> bytes=2147483648 messages=0
>>> doveadm(mirina): Debug: Quota grace: root=User quota bytes=214748364
>>> (10%)
>>> doveadm(mirina): Debug: Namespace inbox: type=private, prefix=,
>>> sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes
>>> location=maildir:~/mails/maildir:INDEX=~/mails/indexes/
>>> doveadm(mirina): Debug: maildir++:
>>> root=/home/users/mirina/mails/maildir,
>>> index=/home/users/mirina/mails/indexes, indexpvt=, control=,
>>> inbox=/home/users/mirina/mails/maildir, alt=
>>> doveadm(mirina): Debug: quota: quota_over_flag check: STORAGE ret=1
>>> value=134 limit=2097152
>>> doveadm(mirina): Debug: quota: quota_over_flag check: MESSAGE ret=0
>>> value=3 limit=0
>>> doveadm(mirina): Debug: quota: quota_over_flag=0((null)) vs currently
>>> overquota=0
>>> doveadm(mirina): Debug: Namespace : Using permissions from
>>> /home/users/mirina/mails/maildir: mode=0700 gid=default
>>> doveadm(mirina): Debug: http-client: host localhost: Host created
>>> doveadm(mirina): Debug: http-client: host localhost: DNS lookup
>>> successful; got 2 IPs
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Peer created
>>> doveadm(mirina): Debug: http-client: queue http://localhost:8080:
>>> Setting up connection to [::1]:8080 (1 requests pending)
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Linked queue
>>> http://localhost:8080 (1 queues linked)
>>> doveadm(mirina): Debug: http-client: queue http://localhost:8080:
>>> Started new connection to [::1]:8080
>>> doveadm(mirina): Debug: http-client: request [Req1: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:838a1701af1ae65a3e12000032c62018+%2Buser:mi$
>>> ina]: Submitted
>>> doveadm(mirina): Debug: http-client: Waiting for 1 requests to finish
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Creating 1 new
>>> connections to handle requests (already 0 usable, connecting to 0,
>>> closing 0)
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Making new
>>> connection 1 of 1
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: HTTP
>>> connection created (1 parallel connections exist)
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: Connected
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: Ready for
>>> requests
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Successfully
>>> connected (connections=1)
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: Using 1 idle
>>> connections to handle 1 requests (1 total connections ready)
>>> doveadm(mirina): Debug: http-client: queue http://localhost:8080:
>>> Connection to peer [::1]:8080 claimed request [Req1: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+bod$
>>> :Madagascar)&fq=%2Bbox:838a1701af1ae65a3e12000032c62018+%2Buser:mirina]
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: Claimed
>>> request [Req1: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:838a1701af1ae6$
>>> a3e12000032c62018+%2Buser:mirina]
>>> [...]
>>> doveadm(mirina): Debug: http-client: request [Req5: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:6dd14d3aae1ae65a3e12000032c62018+%2Buser:mirina]:
>>> Sent header
>>> doveadm(mirina): Debug: http-client: peer [::1]:8080: No more
>>> requests to service for this peer (1 connections exist)
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: Got 200
>>> response for request [Req5: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:6dd14d3aae1ae65a3e12000032c62018+%2Buser:mirina]
>>> (took 2 ms + 0 ms in queue)
>>> doveadm(mirina): Debug: http-client: conn [::1]:8080 [0]: Response
>>> payload stream destroyed (0 ms after initial response)
>>> doveadm(mirina): Debug: http-client: request [Req5: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:6dd14d3aae1ae65a3e12000032c62018+%2Buser:mirina]:
>>> Finished
>>> doveadm(mirina): Debug: http-client: queue http://localhost:8080:
>>> Dropping request [Req5: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:6dd14d3aae1ae65a3e12000032c62018+%2Buser:mirina]
>>> doveadm(mirina): Debug: http-client: host localhost: Host is idle
>>> (timeout = 1799974 msecs)
>>> doveadm(mirina): Debug: http-client: request [Req5: GET
>>> http://localhost:8080/solr/select?fl=uid,score&rows=1&sort=uid+asc&q=%7b!lucene+q.op%3dAND%7d(hdr:Madagascar+OR+body:Madagascar)&fq=%2Bbox:6dd14d3aae1ae65a3e12000032c62018+%2Buser:mirina]:
>>> Free (requests left=1)
>>> doveadm(mirina): Debug: http-client: All requests finished
>>
>> When I do the search with an imap client, I have this error after a
>> long timeout:
>>
>>> May 01 07:08:58 homebox dovecot[5683]: imap(mirina): Panic: file
>>> imap-client.c: line 854 (client_check_command_hangs): assertion
>>> failed: (client->io != NULL || (client->output_cmd_lock != NULL &&
>>> client->output_cmd_lock != client->input_lock))
>>> May 01 07:08:58 homebox dovecot[5683]: imap(mirina): Error: Raw
>>> backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x95e92)
>>> [0x7f216b6f6e92] -> /usr/lib/dovecot/libdovecot.so.0(+0x95f8d)
>>> [0x7f216b6f6f8d] -> /usr/lib/dovecot/libdovecot.so.0(i_fatal+0)
>>> [0x7f216b68ca91] -> dovecot/imap(client_continue_pending_input+0x1fc)
>>> [0x55f44a7eb15c] -> dovecot/imap(client_input+0x120) [0x55f44a7eb460]
>>> -> /usr/lib/dovecot/libdovecot.so.0(io_loop_call_io+0x52)
>>> [0x7f216b70b9f2] ->
>>> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run_internal+0x109)
>>> [0x7f216b70d029] ->
>>> /usr/lib/dovecot/libdovecot.so.0(io_loop_handler_run+0x3c)
>>> [0x7f216b70ba8c] ->
>>> /usr/lib/dovecot/libdovecot.so.0(io_loop_run+0x38) [0x7f216b70bc38]
>>> -> /usr/lib/dovecot/libdovecot.so.0(master_service_run+0x13)
>>> [0x7f216b692fd3] -> dovecot/imap(main+0x328) [0x55f44a7dde68] ->
>>> /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xf1)
>>> [0x7f216b2e22e1] -> dovecot/imap(_start+0x2a) [0x55f44a7ddfea]
>>> May 01 07:08:58 homebox dovecot[5683]: imap(mirina): Fatal: master:
>>> service(imap): child 6149 killed with signal 6 (core dumps disabled)
>>> May 01 07:08:58 homebox in.imapproxyd[20305]: Raw_Proxy(): IMAP
>>> server unexpectedly closed the connection on sd 11
>>
>> My 10-master.conf:
>>
>> service decode2text {
>> executable = script /usr/local/bin/decode2text.sh
>> user = dovecot
>> unix_listener decode2text {
>> mode = 0666
>> }
>> }
>>
>> And my 90-plugins.cof:
>> # Add dovecot fts config
>> fts = solr
>> fts_autoindex = no
>> fts_solr = url=http://localhost:8080/solr/ debug
>> fts_decoder = decode2text
>>
>> Am I doing anything wrong?
>>
>> Thanks for your help.
>>
>> André
>
> hello again,
>
> The issue is not solved, but I have been able to see an error message:
> indexer-worker(andre): Error: parser script didn't send any data
>
> This is weird, because 1) this error is intermittent, 2) I explicitly
> modified the script to echo a specific word in al the cases.
>
> Any idea, someone?
>
> Thanks
Hello again,
I am still having this issue.
The inbox I am testing has only three emails, with three attachments.
The same document in doc, pdf and odt...
Thanks for your help and advice, if you have any.
Kind regards,
André
More information about the dovecot
mailing list