Hello,
I observed a rather weird issue with SolrCloud.
Using Solr 4.0 GA code.
Started with a 3-node Zookeeper ensemble (standalone) and a single Solr
instance running single collection. numShards was set to 1 during collection
creation (don't want sharding, just replication).
Everything worked fine.
Started another Solr instance for the same collection. Properly went through
the steps realizing it needed to sync up (actual url values replaced with
<url>):
12:50:59.152 INFO [o.apache.solr.cloud.RecoveryStrategy] Starting recovery
process. core=users recoveringAfterStartup=true [RecoveryThread]
12:50:59.152 INFO [o.a.solr.servlet.SolrDispatchFilter ] user.dir=/home/seg
[localhost-startStop-1]
12:50:59.153 INFO [o.a.solr.servlet.SolrDispatchFilter ]
SolrDispatchFilter.init() done [localhost-startStop-1]
12:50:59.189 INFO [o.apache.solr.cloud.RecoveryStrategy] ######
startupVersions=[] [RecoveryThread]
12:50:59.198 INFO [o.apache.solr.cloud.RecoveryStrategy] Attempting to
PeerSync from <url> core=users - recoveringAfterStartup=true [RecoveryThread]
12:50:59.201 INFO [o.a.s.c.solrj.impl.HttpClientUtil ] Creating new http
client,
config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[RecoveryThread]
12:50:59.377 INFO [org.apache.solr.update.PeerSync ] PeerSync: core=users
url=<url> START replicas=[<url>] nUpdates=100 [RecoveryThread]
12:50:59.377 DEBUG [org.apache.solr.update.PeerSync ] PeerSync: core=users
url=<url>solr startingVersions=0 [] [RecoveryThread]
12:50:59.390 WARN [org.apache.solr.update.PeerSync ] no frame of reference
to tell of we've missed updates [RecoveryThread]
12:50:59.390 INFO [o.apache.solr.cloud.RecoveryStrategy] PeerSync Recovery was
not successful - trying replication. core=users [RecoveryThread]
12:50:59.390 INFO [o.apache.solr.cloud.RecoveryStrategy] Starting Replication
Recovery. core=users [RecoveryThread]
12:50:59.422 INFO [o.a.solr.common.cloud.ZkStateReader ] A cluster state
change has occurred - updating... [localhost-startStop-1-EventThread]
12:50:59.575 INFO [o.a.s.c.solrj.impl.HttpClientUtil ] Creating new http
client,
config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[RecoveryThread]
12:51:02.742 INFO [o.apache.solr.cloud.RecoveryStrategy] Begin buffering
updates. core=users [RecoveryThread]
12:51:02.742 INFO [org.apache.solr.update.UpdateLog ] Starting to buffer
updates. FSUpdateLog{state=ACTIVE, tlog=null} [RecoveryThread]
12:51:02.743 INFO [o.apache.solr.cloud.RecoveryStrategy] Attempting to
replicate from <url>. core=users [RecoveryThread]
12:51:02.743 INFO [o.a.s.c.solrj.impl.HttpClientUtil ] Creating new http
client,
config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[RecoveryThread]
12:51:02.762 INFO [o.a.s.c.solrj.impl.HttpClientUtil ] Creating new http
client,
config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[RecoveryThread]
12:51:02.774 INFO [org.apache.solr.handler.SnapPuller ] No value set for
'pollInterval'. Timer Task not started. [RecoveryThread]
12:51:02.781 INFO [org.apache.solr.core.SolrCore ]
SolrDeletionPolicy.onInit: commits:num=1
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/solr/users/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e28575;
maxCacheMB=48.0
maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[RecoveryThread]
12:51:02.782 INFO [org.apache.solr.core.SolrCore ] newest commit = 1
[RecoveryThread]
12:51:02.782 DEBUG [o.apache.solr.update.SolrIndexWriter] Opened Writer
DirectUpdateHandler2 [RecoveryThread]
12:51:02.784 INFO [org.apache.solr.update.UpdateHandler] start
commit{flags=0,_version_=0,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false}
[RecoveryThread]
12:51:02.785 DEBUG [org.apache.solr.update.UpdateLog ] TLOG: preCommit
[RecoveryThread]
12:51:02.823 INFO [org.apache.solr.core.SolrCore ]
SolrDeletionPolicy.onCommit: commits:num=2
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/solr/users/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e28575;
maxCacheMB=48.0
maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/solr/users/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e28575;
maxCacheMB=48.0
maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[RecoveryThread]
12:51:02.824 INFO [org.apache.solr.core.SolrCore ] newest commit = 2
[RecoveryThread]
12:51:02.828 INFO [o.a.solr.search.SolrIndexSearcher ] Opening
Searcher@5947fe65 main [RecoveryThread]
........
12:51:02.837 DEBUG [org.apache.solr.update.UpdateLog ] TLOG: postCommit
[RecoveryThread]
12:51:02.837 INFO [org.apache.solr.update.UpdateHandler] end_commit_flush
[RecoveryThread]
12:51:02.838 DEBUG [o.a.solr.search.SolrIndexSearcher ] Closing
Searcher@72795dbb main
fieldValueCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
filterCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
queryResultCache{lookups=0,hits=0,hitratio=0.00,inserts=1,evictions=0,size=1,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
documentCache{lookups=0,hits=0,hitratio=0.00,inserts=0,evictions=0,size=0,warmupTime=0,cumulative_lookups=0,cumulative_hits=0,cumulative_hitratio=0.00,cumulative_inserts=0,cumulative_evictions=0}
[searcherExecutor-4-thread-1]
12:51:02.839 DEBUG [o.a.s.core.CachingDirectoryFactory ] Closing:
CachedDir<<NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/solr/users/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e28575;
maxCacheMB=48.0
maxMergeSizeMB=4.0);refCount=3;path=/solr/users/data/index;done=false>>
[searcherExecutor-4-thread-1]
12:51:02.839 INFO [o.apache.solr.cloud.RecoveryStrategy] No replay needed.
core=users [RecoveryThread]
12:51:02.840 INFO [o.apache.solr.cloud.RecoveryStrategy] Replication Recovery
was successful - registering as Active. core=users [RecoveryThread]
12:51:02.847 INFO [o.apache.solr.cloud.RecoveryStrategy] Finished recovery
process. core=users [RecoveryThread]
However the local index on the replica machine has not been updated. I tried
and failed to find an explanation.
Eventually I stopped the replica, stopped the leader, brought up the leader,
and brought up replica again - and this time it did in fact pull the index data.
Any clues? Any additional information I can supply? I'm going to try to
recreate the problem with a fresh set of instances documenting all the steps,
but perhaps someone on the list will recognize this behavior.
Thank you!
--Ernest
________________________________
The information contained in this message is intended only for the recipient,
and may be a confidential attorney-client communication or may otherwise be
privileged and confidential and protected from disclosure. If the reader of
this message is not the intended recipient, or an employee or agent responsible
for delivering this message to the intended recipient, please be aware that any
dissemination or copying of this communication is strictly prohibited. If you
have received this communication in error, please immediately notify us by
replying to the message and deleting it from your computer. The McGraw-Hill
Companies, Inc. reserves the right, subject to applicable local law, to
monitor, review and process the content of any electronic message or
information sent to or from McGraw-Hill e-mail addresses without informing the
sender or recipient of the message. By sending electronic message or
information to McGraw-Hill e-mail addresses you, as the sender, are consenting
to McGraw-Hill processing any of your personal data therein.
