'[Dovecot] fts-solr indexer-worker connects to wrong solr host dovecot-2.2.4'

[prev in list] [next in list] [prev in thread] [next in thread] 

List:       dovecot
Subject:    [Dovecot] fts-solr indexer-worker connects to wrong solr host dovecot-2.2.4
From:       Richard Platel <rplatel () tucows ! com>
Date:       2013-09-27 15:46:56
Message-ID: 7064632D-270E-4EA4-B62F-12A5151AC381 () tucows ! com
[Download RAW message or body]

Hello.  
We're setting up fts solr and want to have the solr server host be set per-user via \
UserDB.

It looks like if a user connects and fts indexes mail, and then another user connects \
and indexes mail, indexer-worker is connecting to the first user's fts host:

User1, hammer@rp-auth-test.com connects, does a SEARCH for the first time, \
indexer-worker gets UserDB settings and correctly indexes mail on ftsvs01:

[...]
auth-worker(2195): Debug: dict(hammer@rp-auth-test.com): lookup \
shared/userdb/hammer@rp-auth-test.com auth-worker(2195): Debug: \
dict(hammer@rp-auth-test.com): result: \
{"uid":"8","fts":"solr","quota_rule4":"Spam:ignore","_session":"talk15_590ec6d100042", \
"quota_rule3":"Trash:ignore","quota_rule2":"*:messages=2684354","quota_rule":"*:storag \
e=5242880k","mail":"maildir:/mail/mailstore01/215/573/hammer@rp-auth-test.com/:INDEX=/mail/index01/215/573/hammer@rp-auth-test.com/","fts_solr":"debug \
                url=http://ftsvs01:8080/solr/","gid":"8"}
auth: Debug: userdb out: USER   1       hammer@rp-auth-test.com uid=8   fts=solr      \
quota_rule4=Spam:ignore _session=talk15_590ec6d100042   quota_rule3=Trash:ignore      \
quota_rule2=*:messages=2684354  quota_rule=*:storage=5242880k   \
mail=maildir:/mail/mailstore01/215/573/hammer@rp-auth-test.com/:INDEX=/mail/index01/215/573/hammer@rp-auth-test.com/ \
                fts_solr=debug url=http://ftsvs01:8080/solr/    gid=8
indexer-worker: Debug: auth input: hammer@rp-auth-test.com uid=8 fts=solr \
quota_rule4=Spam:ignore _session=talk15_590ec6d100042 quota_rule3=Trash:ignore \
quota_rule2=*:messages=2684354 quota_rule=*:storage=5242880k \
mail=maildir:/mail/mailstore01/215/573/hammer@rp-auth-test.com/:INDEX=/mail/index01/215/573/hammer@rp-auth-test.com/ \
                fts_solr=debug url=http://ftsvs01:8080/solr/ gid=8
indexer-worker: Debug: Added userdb setting: plugin/_session=talk15_590ec6d100042
indexer-worker: Debug: Added userdb setting: plugin/fts=solr
indexer-worker: Debug: Added userdb setting: plugin/fts_solr=debug \
                url=http://ftsvs01:8080/solr/
indexer-worker: Debug: Added userdb setting: \
mail=maildir:/mail/mailstore01/215/573/hammer@rp-auth-test.com/:INDEX=/mail/index01/215/573/ha
 mmer@rp-auth-test.com/
indexer-worker: Debug: Added userdb setting: plugin/quota_rule=*:storage=5242880k
indexer-worker: Debug: Added userdb setting: plugin/quota_rule2=*:messages=2684354
indexer-worker: Debug: Added userdb setting: plugin/quota_rule3=Trash:ignore
indexer-worker: Debug: Added userdb setting: plugin/quota_rule4=Spam:ignore
indexer-worker(hammer@rp-auth-test.com): Debug: Effective uid=8, gid=8, home=
indexer-worker(hammer@rp-auth-test.com): Debug: Namespace inbox: type=private, \
prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions =yes \
location=maildir:/mail/mailstore01/215/573/hammer@rp-auth-test.com/:INDEX=/mail/index01/215/573/hammer@rp-auth-test.com/
 indexer-worker(hammer@rp-auth-test.com): Debug: maildir++: \
root=/mail/mailstore01/215/573/hammer@rp-auth-test.com, index=/mail/index01/215/ \
573/hammer@rp-auth-test.com, indexpvt=, control=, \
inbox=/mail/mailstore01/215/573/hammer@rp-auth-test.com, alt= \
indexer-worker(hammer@rp-auth-test.com): Debug: Ignoring unknown cache field: \
pop3.order indexer-worker(hammer@rp-auth-test.com): Debug: Ignoring unknown cache \
field: binary.parts indexer-worker(hammer@rp-auth-test.com): Warning: Created dotlock \
file's timestamp is different than current time (1380294685 vs 1380294612 ): \
/mail/index01/215/573/hammer@rp-auth-test.com/.INBOX/dovecot.index.log \
indexer-worker(hammer@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Submitted [...]


User1 index finishes and imap searches against ftsvs01
[...]
imap(hammer@rp-auth-test.com): Debug: http-client: request [GET \
http://ftsvs01:8080/solr/select?fl=uid,score&rows=2&sort=uid+asc&q=(hdr:%22moo%22+OR+b \
ody:%22moo%22)&fq=%2Bbox:42faee1f735b1e52b3210000386e9ade+%2Buser:%22hammer@rp-auth-test.com%22]: \
Submitted [...]


User2 grant@rp-auth-test.com connects and does a SEARCH, index worker gets gets \
UserDB settings, including fts host ftsvs02, but connects to ftsvs01 (also note \
index-worker initially shows wrong user in loglines) [...]
auth-worker(2195): Debug: dict(grant@rp-auth-test.com): lookup \
shared/userdb/grant@rp-auth-test.com auth-worker(2195): Debug: \
dict(grant@rp-auth-test.com): result: \
{"uid":"8","fts":"solr","quota_rule4":"Spam:ignore","_session":"cow80_609fed7600001"," \
quota_rule3":"Trash:ignore","quota_rule2":"*:messages=2684354","quota_rule":"*:storage \
=5242880k","mail":"maildir:/mail/mailstore01/812/023/grant@rp-auth-test.com/:INDEX=/mail/index01/812/023/grant@rp-auth-test.com/","fts_solr":"debug \
                url=http://ftsvs02:8080/solr/","gid":"8"}
auth: Debug: userdb out: USER   2       grant@rp-auth-test.com  uid=8   fts=solr      \
quota_rule4=Spam:ignore _session=cow80_609fed7600001    quota_rule3=Trash:ignore      \
quota_rule2=*:messages=2684354  quota_rule=*:storage=5242880k   \
mail=maildir:/mail/mailstore01/812/023/grant@rp-auth-test.com/:INDEX=/mail/index01/812/023/grant@rp-auth-test.com/ \
fts_solr=debug url=http://ftsvs02:8080/solr/    gid=8 \
indexer-worker(hammer@rp-auth-test.com): Debug: auth input: grant@rp-auth-test.com \
uid=8 fts=solr quota_rule4=Spam:ignore _session=cow80_609fed7600001 \
quota_rule3=Trash:ignore quota_rule2=*:messages=2684354 quota_rule=*:storage=5242880k \
mail=maildir:/mail/mailstore01/812/023/grant@rp-auth-test.com/:INDEX=/mail/index01/812/023/grant@rp-auth-test.com/ \
fts_solr=debug url=http://ftsvs02:8080/solr/ gid=8 \
indexer-worker(hammer@rp-auth-test.com): Debug: Added userdb setting: \
plugin/_session=cow80_609fed7600001 indexer-worker(hammer@rp-auth-test.com): Debug: \
Added userdb setting: plugin/fts=solr indexer-worker(hammer@rp-auth-test.com): Debug: \
Added userdb setting: plugin/fts_solr=debug url=http://ftsvs02:8080/solr/ \
indexer-worker(hammer@rp-auth-test.com): Debug: Added userdb setting: \
mail=maildir:/mail/mailstore01/812/023/grant@rp-auth-test.com/:INDEX=/mail/index01/812/023/grant@rp-auth-test.com/
 indexer-worker(hammer@rp-auth-test.com): Debug: Added userdb setting: \
plugin/quota_rule=*:storage=5242880k indexer-worker(hammer@rp-auth-test.com): Debug: \
Added userdb setting: plugin/quota_rule2=*:messages=2684354 \
indexer-worker(hammer@rp-auth-test.com): Debug: Added userdb setting: \
plugin/quota_rule3=Trash:ignore indexer-worker(hammer@rp-auth-test.com): Debug: Added \
userdb setting: plugin/quota_rule4=Spam:ignore \
indexer-worker(grant@rp-auth-test.com): Debug: Effective uid=8, gid=8, home= \
indexer-worker(grant@rp-auth-test.com): Debug: Namespace inbox: type=private, \
prefix=, sep=, inbox=yes, hidden=no, list=yes, subscriptions=yes \
location=maildir:/mail/mailstore01/812/023/grant@rp-auth-test.com/:INDEX=/mail/index01/812/023/grant@rp-auth-test.com/
 indexer-worker(grant@rp-auth-test.com): Debug: maildir++: \
root=/mail/mailstore01/812/023/grant@rp-auth-test.com, \
index=/mail/index01/812/023/grant@rp-auth-test.com, indexpvt=, control=, \
inbox=/mail/mailstore01/812/023/grant@rp-auth-test.com, alt= \
indexer-worker(grant@rp-auth-test.com): Debug: Ignoring unknown cache field: \
pop3.order indexer-worker(grant@rp-auth-test.com): Debug: Ignoring unknown cache \
field: binary.parts indexer-worker(grant@rp-auth-test.com): Warning: Created dotlock \
file's timestamp is different than current time (1380294736 vs 1380294664): \
/mail/index01/812/023/grant@rp-auth-test.com/.INBOX/dovecot.index.cache \
indexer-worker(grant@rp-auth-test.com): Warning: Created dotlock file's timestamp is \
different than current time (1380294736 vs 1380294664): \
/mail/index01/812/023/grant@rp-auth-test.com/.INBOX/dovecot.index.log \
indexer-worker(grant@rp-auth-test.com): Warning: Created dotlock file's timestamp is \
different than current time (1380294736 vs 1380294664): \
/mail/index01/812/023/grant@rp-auth-test.com/.INBOX/dovecot.index.cache \
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Submitted [...]

indexer-worker indexes User2's mail on wrong fts host:
[...]
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Sent header indexer-worker(grant@rp-auth-test.com): \
Debug: http-client: request [POST http://ftsvs01:8080/solr/update]: Partially sent \
payload indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Partially sent payload \
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Partially sent payload \
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Partially sent payload \
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Partially sent payload \
indexer-worker(grant@rp-auth-test.com): Debug: http-client: request [POST \
http://ftsvs01:8080/solr/update]: Partially sent payload [...]

indexer-worker finishes and imap searches against correct fts host ftsvs02
[...]
imap(grant@rp-auth-test.com): Debug: http-client: request [GET \
http://ftsvs02:8080/solr/select?fl=uid,score&rows=194&sort=uid+asc&q=(hdr:%22Fasdf%22+ \
OR+body:%22Fasdf%22)&fq=%2Bbox:62d61f003b5a1e52af130000386e9ade+%2Buser:%22grant@rp-auth-test.com%22]: \
Submitted [...]


[prev in list] [next in list] [prev in thread] [next in thread]
Configure | About | News | Add a list | Sponsored by KoreLogic