[
https://issues.apache.org/jira/browse/SOLR-4923?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13682873#comment-13682873
]
Hoss Man commented on SOLR-4923:
--------------------------------
Sample logs from the replica during my manual testing...
{noformat:title=replica @ moment of update}
580025 [qtp541763983-15] INFO org.apache.solr.update.UpdateHandler – start
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
580142 [qtp541763983-15] INFO org.apache.solr.core.SolrCore –
SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/home/hossman/lucene/dev/solr/example2/solr/collection1/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d508aed;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_b,generation=11}
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/home/hossman/lucene/dev/solr/example2/solr/collection1/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d508aed;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_c,generation=12}
580143 [qtp541763983-15] INFO org.apache.solr.core.SolrCore – newest commit
generation = 12
580144 [qtp541763983-15] INFO org.apache.solr.search.SolrIndexSearcher –
Opening Searcher@60d2cd99 main
580145 [qtp541763983-15] INFO org.apache.solr.update.UpdateHandler –
end_commit_flush
580145 [searcherExecutor-5-thread-1] INFO org.apache.solr.core.SolrCore –
QuerySenderListener sending requests to Searcher@60d2cd99
main{StandardDirectoryReader(segments_b:15:nrt _3(5.0):c1)}
580146 [searcherExecutor-5-thread-1] INFO org.apache.solr.core.SolrCore –
QuerySenderListener done.
580151 [searcherExecutor-5-thread-1] INFO org.apache.solr.core.SolrCore –
[collection1] Registered new searcher Searcher@60d2cd99
main{StandardDirectoryReader(segments_b:15:nrt _3(5.0):c1)}
580170 [qtp541763983-18] INFO
org.apache.solr.update.processor.LogUpdateProcessor – [collection1]
webapp=/solr path=/update
params={distrib.from=http://127.0.1.1:8983/solr/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2}
{add=[HOSS (1437769792183336960)]} 0 4
580173 [qtp541763983-15] INFO org.apache.solr.update.SolrCmdDistributor –
Distrib commit to:[StdNode: http://127.0.1.1:8983/solr/collection1/]
params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
580426 [qtp541763983-15] INFO
org.apache.solr.update.processor.LogUpdateProcessor – [collection1]
webapp=/solr path=/update params={omitHeader=true&commit=true&wt=json}
{add=[HOSS],commit=} 0 402
{noformat}
{noformat:title=replica a few seconds later}
595170 [commitScheduler-7-thread-1] INFO org.apache.solr.update.UpdateHandler
– start
commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
595355 [commitScheduler-7-thread-1] INFO org.apache.solr.core.SolrCore –
SolrDeletionPolicy.onCommit: commits: num=2
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/home/hossman/lucene/dev/solr/example2/solr/collection1/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d508aed;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_c,generation=12}
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/home/hossman/lucene/dev/solr/example2/solr/collection1/data/index
lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d508aed;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_d,generation=13}
595355 [commitScheduler-7-thread-1] INFO org.apache.solr.core.SolrCore –
newest commit generation = 13
595359 [commitScheduler-7-thread-1] INFO
org.apache.solr.search.SolrIndexSearcher – Opening Searcher@140ffc1 realtime
595360 [commitScheduler-7-thread-1] INFO org.apache.solr.update.UpdateHandler
– end_commit_flush
{noformat}
You can see that the "explicit" commit (with "openSearcher=true") seems to be
happening first, then the replica recieves the distrib update back from the
leader, then a "Distrib commit to: <leader>" (that i'm not familiar with) is
logged by the replica. A few seconds later, the autoCommit on the replica
kicks in, but this uses openSearcher=false since that's what's in solrconfig.xml
> Replica index is one version behind sending the commit to non-leader instance
> -----------------------------------------------------------------------------
>
> Key: SOLR-4923
> URL: https://issues.apache.org/jira/browse/SOLR-4923
> Project: Solr
> Issue Type: Bug
> Components: replication (java)
> Affects Versions: 4.2
> Environment: Solr 4.2.1
> OS X 10.8.3
> Reporter: Ricardo Merizalde
> Priority: Critical
> Fix For: 5.0, 4.4
>
>
> I was actually trying to debug an issue we experiencing in production where
> the replica version is ahead from the leader when I noticed this problem.
> For my tests I'm running two Solr instances with distributed updates
> (SolrCloud). ZK runs embedded within one of the instances.
> The test consists on updating one field in single document. If I send an
> update to the leader the index is replicated correctly. However, if I run the
> update against the follower replica only the leader is updated correctly. I
> can reproduce this using both hard and soft commits. Here is the command I'm
> running:
> curl
> "http://localhost:8999/solr/rulePreview/update?commit=true&softCommit=true";
> -H "Content-Type: text/xml" --data-binary '<add>...</add>
> If I execute a second commit against the follower the leader will have the
> most recent update and the follower will be update from the first commit.
> For example, my field is named category and initially it contains the value
> cat_1. If update the value to cat_2 the leader sees the change but the
> follower doesn't. If a second commit updates the field to cat_3 the leader
> will return cat_3 but the follower return cat_2.
> Reloading the core in the follower fixes the problem.
> The logs seem to confirm the follower gets the latest index version. However,
> the version in the logs doesn't matches the on in the Core Admin UI nor Luke.
> Here are some logs from the leader:
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.processor.LogUpdateProcessor
> finish
> INFO: [rulePreview_en] webapp=/solr path=/update
> params={distrib.from=http://192.168.1.106:8998/solr/rulePreview_en/&update.distrib=TOLEADER&wt=javabin&version=2}
> {add=[importedRedirect1 (1437700518392627200)]} 0 11
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.DirectUpdateHandler2 commit
> INFO: start
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
> Jun 12, 2013 10:34:19 PM org.apache.solr.search.SolrIndexSearcher <init>
> INFO: Opening Searcher@47e4e06c main
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.DirectUpdateHandler2 commit
> INFO: end_commit_flush
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.QuerySenderListener newSearcher
> INFO: QuerySenderListener sending requests to Searcher@47e4e06c
> main{StandardDirectoryReader(segments_3g:467:nrt _2a(4.2.1):C134/1
> _3c(4.2.1):C1)}
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.QuerySenderListener newSearcher
> INFO: QuerySenderListener done.
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [rulePreview_en] Registered new searcher Searcher@47e4e06c
> main{StandardDirectoryReader(segments_3g:467:nrt _2a(4.2.1):C134/1
> _3c(4.2.1):C1)}
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.processor.LogUpdateProcessor
> finish
> INFO: [rulePreview_en] webapp=/solr path=/update
> params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=true}
> {commit=} 0 12
> And the logs from the follower:
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.DirectUpdateHandler2 commit
> INFO: start
> commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
> Jun 12, 2013 10:34:19 PM org.apache.solr.search.SolrIndexSearcher <init>
> INFO: Opening Searcher@1e23cfc main
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.DirectUpdateHandler2 commit
> INFO: end_commit_flush
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.QuerySenderListener newSearcher
> INFO: QuerySenderListener sending requests to Searcher@1e23cfc
> main{StandardDirectoryReader(segments_3i:463:nrt _2a(4.2.1):C134/1
> _3b(4.2.1):C1)}
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.QuerySenderListener newSearcher
> INFO: QuerySenderListener done.
> Jun 12, 2013 10:34:19 PM org.apache.solr.core.SolrCore registerSearcher
> INFO: [rulePreview_en] Registered new searcher Searcher@1e23cfc
> main{StandardDirectoryReader(segments_3i:463:nrt _2a(4.2.1):C134/1
> _3b(4.2.1):C1)}
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.processor.LogUpdateProcessor
> finish
> INFO: [rulePreview_en] webapp=/solr path=/update
> params={distrib.from=http://192.168.1.106:8999/solr/rulePreview_en/&update.distrib=FROMLEADER&wt=javabin&version=2}
> {add=[importedRedirect1 (1437700518392627200)]} 0 4
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.SolrCmdDistributor
> distribCommit
> INFO: Distrib commit to:[StdNode:
> http://192.168.1.106:8999/solr/rulePreview_en/]
> params:commit_end_point=true&commit=true&softCommit=true&waitSearcher=true&expungeDeletes=false
> Jun 12, 2013 10:34:19 PM org.apache.solr.update.processor.LogUpdateProcessor
> finish
> INFO: [rulePreview_en] webapp=/solr path=/update params={softCommit=true}
> {add=[importedRedirect1],commit=} 0 41
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
