I've attached the log of the downed node (truffle-solr-4).
This is the relevant log entry from the node it should replicate from
(truffle-solr-5):
[29 Jan 2014 19:31:29] [qtp1614415528-74] ERROR
(org.apache.solr.common.SolrException) -
org.apache.solr.common.SolrException: I was asked to wait on state
recovering for truffle-solr-4:8983_solr but I still do not see the
requested state. I see state: active live:true
at
org.apache.solr.handler.admin.CoreAdminHandler.handleWaitForStateAction(CoreAdminHandler.java:966)
at
org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:191)
at
org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
at
org.apache.solr.servlet.SolrDispatchFilter.handleAdminRequest(SolrDispatchFilter.java:611)
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:209)
at
org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:158)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557)
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1075)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384)
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
at
org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255)
at
org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
at org.eclipse.jetty.server.Server.handle(Server.java:368)
You can see that 4 is serving queries. It appears that 4 tries to recover
from 5, but 5 is confused about the state of 4? 4 had an empty index and
tlog when it was started.
We will eventually upgrade to 4.6.x or 4.7.x, but we've got a pretty
extensive regression testing cycle, so there is some delay in upgrading
versions.
-Greg
On Wed, Jan 29, 2014 at 9:08 AM, Mark Miller <markrmil...@gmail.com> wrote:
> What's in the logs of the node that won't recover on restart after
> clearing the index and tlog
>
> - Mark
>
> On Jan 29, 2014, at 11:41 AM, Greg Preston <gpres...@marinsoftware.com>
> wrote:
>
> >> If you removed the tlog and index and restart it should resync, or
> > something is really crazy.
> >
> > It doesn't, or at least if it tries, it's somehow failing. I'd be ok
> with
> > the sync failing for some reason if the node wasn't also serving queries.
> >
> >
> > -Greg
> >
> >
> >> On Tue, Jan 28, 2014 at 11:10 AM, Mark Miller <markrmil...@gmail.com>
> wrote:
> >>
> >> Sounds like a bug. 4.6.1 is out any minute - you might try that. There
> was
> >> a replication bug that may be involved.
> >>
> >> If you removed the tlog and index and restart it should resync, or
> >> something is really crazy.
> >>
> >> The clusterstate.json is a red herring. You have to merge the live nodes
> >> info with the state to know the real state.
> >>
> >> - Mark
> >>
> >> http://www.about.me/markrmiller
> >>
> >>>> On Jan 28, 2014, at 12:31 PM, Greg Preston <
> gpres...@marinsoftware.com>
> >>> wrote:
> >>>
> >>> ** Using solrcloud 4.4.0 **
> >>>
> >>> I had to kill a running solrcloud node. There is still a replica for
> >> that
> >>> shard, so everything is functional. We've done some indexing while the
> >>> node was killed.
> >>>
> >>> I'd like to bring back up the downed node and have it resync from the
> >> other
> >>> replica. But when I restart the downed node, it joins back up as
> active
> >>> immediately, and doesn't resync. I even wiped the data directory on
> the
> >>> downed node, hoping that would force it to sync on restart, but it
> >> doesn't.
> >>>
> >>> I'm assuming this is related to the state still being listed as active
> in
> >>> clusterstate.json for the downed node? Since it comes back as active,
> >> it's
> >>> serving queries and giving old results.
> >>>
> >>> How can I force this node to do a recovery on restart?
> >>>
> >>> Thanks.
> >>>
> >>>
> >>> -Greg
> >>
>
[29 Jan 2014 19:28:57] [main] INFO (org.eclipse.jetty.server.Server) - jetty-8.1.10.v20130312
[29 Jan 2014 19:28:57] [main] INFO (org.eclipse.jetty.deploy.providers.ScanningAppProvider) - Deployment monitor /home/solr/solr/solr-4.4.0/example/contexts at interval 0
[29 Jan 2014 19:28:57] [main] INFO (org.eclipse.jetty.deploy.DeploymentManager) - Deployable added: /home/solr/solr/solr-4.4.0/example/contexts/solr-jetty-context.xml
[29 Jan 2014 19:28:58] [main] INFO (org.eclipse.jetty.webapp.StandardDescriptorProcessor) - NO JSP Support for /solr, did not find org.apache.jasper.servlet.JspServlet
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.servlet.SolrDispatchFilter) - SolrDispatchFilter.init()
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.SolrResourceLoader) - JNDI not configured for solr (NoInitialContextEx)
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.SolrResourceLoader) - using system property solr.solr.home: /home/solr/solr/bin/../config
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.SolrResourceLoader) - new SolrResourceLoader for directory: '/home/solr/solr/bin/../config/'
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.ConfigSolr) - Loading container configuration from /home/solr/solr/bin/../config/solr.xml
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.CoreContainer) - New CoreContainer 834601898
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.CoreContainer) - Loading cores into CoreContainer [instanceDir=/home/solr/solr/bin/../config/]
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.CoreContainer) - loading shared library: /home/solr/solr/bin/../config/lib
[29 Jan 2014 19:28:58] [main] WARN (org.apache.solr.core.SolrResourceLoader) - Can't find (or read) directory to add to classloader: lib (resolved as: /home/solr/solr/bin/../config/lib).
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting socketTimeout to: 0
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting urlScheme to: http://
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting connTimeout to: 0
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting maxConnectionsPerHost to: 20
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting corePoolSize to: 0
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting maximumPoolSize to: 2147483647
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting maxThreadIdleTime to: 5
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting sizeOfQueue to: -1
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.handler.component.HttpShardHandlerFactory) - Setting fairnessPolicy to: false
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.client.solrj.impl.HttpClientUtil) - Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.logging.LogWatcher) - Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.core.ZkContainer) - Zookeeper client=truffle-solr-3:9983,truffle-solr-4:9983,truffle-solr-5:9983
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.client.solrj.impl.HttpClientUtil) - Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=0&connTimeout=0
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.common.cloud.ConnectionManager) - Waiting for client to connect to ZooKeeper
[29 Jan 2014 19:28:58] [main-EventThread] INFO (org.apache.solr.common.cloud.ConnectionManager) - Watcher org.apache.solr.common.cloud.ConnectionManager@4d738073 name:ZooKeeperConnection Watcher:truffle-solr-3:9983,truffle-solr-4:9983,truffle-solr-5:9983 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.common.cloud.ConnectionManager) - Client is connected to ZooKeeper
[29 Jan 2014 19:28:58] [main] INFO (org.apache.solr.common.cloud.ZkStateReader) - Updating cluster state from ZooKeeper...
[29 Jan 2014 19:29:28] [main] WARN (org.apache.solr.cloud.ZkController) - Timed out waiting to see all nodes published as DOWN in our cluster state.
[29 Jan 2014 19:29:28] [main] INFO (org.apache.solr.cloud.ZkController) - Register node as live in ZooKeeper:/live_nodes/truffle-solr-4:8983_solr
[29 Jan 2014 19:29:28] [main] INFO (org.apache.solr.common.cloud.SolrZkClient) - makePath: /live_nodes/truffle-solr-4:8983_solr
[29 Jan 2014 19:29:28] [main-EventThread] INFO (org.apache.solr.common.cloud.ZkStateReader$3) - Updating live nodes... (4)
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - publishing core=marin state=down
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - numShards not found on descriptor - reading it from system property
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - waiting to find shard id in clusterstate for marin
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.CoreContainer) - Creating SolrCore 'marin' using instanceDir: /home/solr/solr/bin/../config/marin
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - Check for collection zkNode:marin
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - Collection zkNode exists
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - Load collection config from:/collections/marin
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrResourceLoader) - new SolrResourceLoader for directory: '/home/solr/solr/bin/../config/marin/'
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.update.SolrIndexConfig) - IndexWriter infoStream solr logging is enabled
[29 Jan 2014 19:29:28] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrConfig) - Using Lucene MatchVersion: LUCENE_41
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrConfig) - Loaded SolrConfig: solrconfig.xml
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.schema.IndexSchema) - Reading Solr Schema from schema.xml
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.schema.IndexSchema) - [marin] Schema name=marin
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.schema.IndexSchema) - unique key field: key
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - solr.NRTCachingDirectoryFactory
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] Opening new SolrCore at /home/solr/solr/bin/../config/marin/, dataDir=../../data/
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.JmxMonitoredMap) - JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1775831e
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - return new directory for /home/solr/solr/data
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - New index directory detected: old=null new=../../data/index/
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] WARN (org.apache.solr.core.SolrCore) - [marin] Solr index directory '../../data/index' doesn't exist. Creating new index...
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - return new directory for /home/solr/solr/data/index
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrDeletionPolicy) - SolrDeletionPolicy.onCommit: commits: num=1
commit{dir=NRTCachingDirectory(org.apache.lucene.store.MMapDirectory@/home/solr/solr/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@71cf4b78; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1}
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrDeletionPolicy) - newest commit generation = 1
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.SolrCore) - created xslt: solr.XSLTResponseWriter
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.response.XSLTResponseWriter) - xsltCacheLifetimeSeconds=5
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created standard: solr.StandardRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /replication: solr.ReplicationHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /get: solr.RealTimeGetHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /search: org.apache.solr.handler.component.SearchHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /update: solr.UpdateRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - adding lazy requestHandler: solr.FieldAnalysisRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /analysis/field: solr.FieldAnalysisRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /analysis/document: solr.DocumentAnalysisRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /admin/: org.apache.solr.handler.admin.AdminHandlers
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /admin/ping: solr.PingRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.RequestHandlers) - created /debug/dump: solr.DumpRequestHandler
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.handler.loader.XMLLoader) - xsltCacheLifetimeSeconds=60
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.search.SolrIndexSearcher) - Opening Searcher@65cc2c78 main
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.update.CommitTracker) - Hard AutoCommit: if uncommited for 300000ms; if 500000 uncommited docs
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.update.CommitTracker) - Soft AutoCommit: if uncommited for 300000ms;
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.handler.ReplicationHandler) - Commits will be reserved for 10000
[29 Jan 2014 19:29:29] [searcherExecutor-5-thread-1] INFO (org.apache.solr.core.QuerySenderListener) - QuerySenderListener sending requests to Searcher@65cc2c78 main{StandardDirectoryReader(segments_1:1)}
[29 Jan 2014 19:29:29] [searcherExecutor-5-thread-1] INFO (org.apache.solr.core.QuerySenderListener) - QuerySenderListener done.
[29 Jan 2014 19:29:29] [searcherExecutor-5-thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] Registered new searcher Searcher@65cc2c78 main{StandardDirectoryReader(segments_1:1)}
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.core.CoreContainer) - registering core: marin
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - Register replica - core:marin address:http://truffle-solr-4:8983/solr collection:marin shard:shard2
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.client.solrj.impl.HttpClientUtil) - Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - We are http://truffle-solr-4:8983/solr/marin/ and leader is http://truffle-solr-5:8983/solr/marin/
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - No LogReplay needed for core=marin baseURL=http://truffle-solr-4:8983/solr
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.cloud.ZkController) - Core needs to recover:marin
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.update.DefaultSolrCoreState) - Running recovery - first canceling any ongoing recovery
[29 Jan 2014 19:29:29] [coreLoadExecutor-4-thread-1] INFO (org.apache.solr.common.cloud.ZkStateReader) - Updating cloud state from ZooKeeper...
[29 Jan 2014 19:29:29] [RecoveryThread] INFO (org.apache.solr.cloud.RecoveryStrategy) - Starting recovery process. core=marin recoveringAfterStartup=true
[29 Jan 2014 19:29:29] [RecoveryThread] INFO (org.apache.solr.cloud.RecoveryStrategy) - ###### startupVersions=[]
[29 Jan 2014 19:29:29] [main] INFO (org.apache.solr.servlet.SolrDispatchFilter) - user.dir=/home/solr/solr/solr-4.4.0/example
[29 Jan 2014 19:29:29] [main] INFO (org.apache.solr.servlet.SolrDispatchFilter) - SolrDispatchFilter.init() done
[29 Jan 2014 19:29:29] [RecoveryThread] INFO (org.apache.solr.cloud.ZkController) - publishing core=marin state=recovering
[29 Jan 2014 19:29:29] [RecoveryThread] INFO (org.apache.solr.cloud.ZkController) - numShards not found on descriptor - reading it from system property
[29 Jan 2014 19:29:29] [RecoveryThread] INFO (org.apache.solr.client.solrj.impl.HttpClientUtil) - Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[29 Jan 2014 19:29:29] [main] INFO (org.eclipse.jetty.server.AbstractConnector) - Started SocketConnector@0.0.0.0:8983
[29 Jan 2014 19:29:36] [qtp536104499-16] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={distrib=false&wt=javabin&version=2&rows=10&df=title&fl=key,score&shard.url=truffle-solr-4:8983/solr/marin/|truffle-solr-5:8983/solr/marin/&NOW=1391023775928&start=0&q=*:*&q.op=AND&_=1391023775899&isShard=true&fsv=true} hits=0 status=0 QTime=76
[29 Jan 2014 19:29:36] [qtp536104499-16] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={distrib=false&wt=javabin&version=2&rows=10&df=title&fl=key,score&shard.url=truffle-solr-4:8983/solr/marin/|truffle-solr-5:8983/solr/marin/&NOW=1391023776504&start=0&q=*:*&q.op=AND&_=1391023776475&isShard=true&fsv=true} hits=0 status=0 QTime=1
[29 Jan 2014 19:29:37] [qtp536104499-16] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={distrib=false&wt=javabin&version=2&rows=10&df=title&fl=key,score&shard.url=truffle-solr-4:8983/solr/marin/|truffle-solr-5:8983/solr/marin/&NOW=1391023777906&start=0&q=*:*&q.op=AND&_=1391023777877&isShard=true&fsv=true} hits=0 status=0 QTime=1
[29 Jan 2014 19:30:06] [qtp536104499-17] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2&rows=0} hits=66102419 status=0 QTime=44
[29 Jan 2014 19:30:06] [qtp536104499-19] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={distrib=false&wt=javabin&version=2&rows=0&df=title&fl=key,score&shard.url=truffle-solr-4:8983/solr/marin/|truffle-solr-5:8983/solr/marin/&NOW=1391023806834&start=0&q=*:*&q.op=AND&isShard=true&fsv=true} hits=0 status=0 QTime=1
[29 Jan 2014 19:30:06] [qtp536104499-18] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2&rows=0} hits=25151458 status=0 QTime=12
[29 Jan 2014 19:30:12] [qtp536104499-16] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={facet=false&sort=title_sort+asc&distrib=false&wt=javabin&version=2&rows=1&NOW=1391023812558&shard.url=truffle-solr-4:8983/solr/marin/|truffle-solr-5:8983/solr/marin/&df=title&debugQuery=false&fl=key&start=0&q=*:*&q.op=AND&isShard=true&fq=%2BcustomerId:1+%2BclientId:1&fq=%2BdocType:keyword&fsv=true} hits=0 status=0 QTime=22
[29 Jan 2014 19:30:18] [qtp536104499-20] INFO (org.apache.solr.core.SolrCore) - [marin] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2&rows=0} hits=66102419 status=0 QTime=94
[29 Jan 2014 19:30:43] [Thread-1] INFO (org.eclipse.jetty.server.Server) - Graceful shutdown SocketConnector@0.0.0.0:8983
[29 Jan 2014 19:30:43] [Thread-1] INFO (org.eclipse.jetty.server.Server) - Graceful shutdown o.e.j.w.WebAppContext{/solr,file:/home/solr/solr/solr-4.4.0/example/solr-webapp/webapp/},/home/solr/solr/solr-4.4.0/example/webapps/solr.war
[29 Jan 2014 19:30:44] [Thread-1] INFO (org.apache.solr.core.CoreContainer) - Shutting down CoreContainer instance=834601898
[29 Jan 2014 19:31:14] [Thread-1] WARN (org.apache.solr.cloud.ZkController) - Timed out waiting to see all nodes published as DOWN in our cluster state.
[29 Jan 2014 19:31:14] [Thread-1] INFO (org.apache.solr.cloud.ZkController) - publishing core=marin state=down
[29 Jan 2014 19:31:14] [Thread-1] INFO (org.apache.solr.cloud.ZkController) - numShards not found on descriptor - reading it from system property
[29 Jan 2014 19:31:14] [Thread-1] WARN (org.apache.solr.cloud.RecoveryStrategy) - Stopping recovery for zkNodeName=truffle-solr-4:8983_solr_marincore=marin
[29 Jan 2014 19:31:29] [RecoveryThread] ERROR (org.apache.solr.common.SolrException) - Error while trying to recover. core=marin:org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://truffle-solr-5:8983/solr
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:431)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.RecoveryStrategy.sendPrepRecoveryCmd(RecoveryStrategy.java:198)
at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:342)
at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:219)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:166)
at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:90)
at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:281)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:92)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:62)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:717)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:522)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:365)
... 4 more
[29 Jan 2014 19:31:30] [RecoveryThread] ERROR (org.apache.solr.cloud.RecoveryStrategy) - Recovery failed - trying again... (0) core=marin
[29 Jan 2014 19:31:30] [RecoveryThread] ERROR (org.apache.solr.common.SolrException) - Recovery failed - interrupted. core=marin
[29 Jan 2014 19:31:30] [RecoveryThread] ERROR (org.apache.solr.common.SolrException) - Recovery failed - I give up. core=marin
[29 Jan 2014 19:31:30] [RecoveryThread] INFO (org.apache.solr.cloud.ZkController) - publishing core=marin state=recovery_failed
[29 Jan 2014 19:31:30] [RecoveryThread] INFO (org.apache.solr.cloud.ZkController) - numShards not found on descriptor - reading it from system property
[29 Jan 2014 19:31:30] [RecoveryThread] WARN (org.apache.solr.cloud.RecoveryStrategy) - Stopping recovery for zkNodeName=truffle-solr-4:8983_solr_marincore=marin
[29 Jan 2014 19:31:30] [RecoveryThread] INFO (org.apache.solr.cloud.RecoveryStrategy) - Finished recovery process. core=marin
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] CLOSING SolrCore org.apache.solr.core.SolrCore@54074e95
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.update.DirectUpdateHandler2) - closing DirectUpdateHandler2{commits=0,autocommit maxDocs=500000,autocommit maxTime=300000ms,autocommits=0,soft autocommit maxTime=300000ms,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.update.SolrCoreState) - Closing SolrCoreState
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.update.DefaultSolrCoreState) - SolrCoreState ref count has reached 0 - closing IndexWriter
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.update.DefaultSolrCoreState) - closing IndexWriter with IndexWriterCloser
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.SolrCore) - [marin] Closing main searcher on request.
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - Closing NRTCachingDirectoryFactory - 2 directories currently being tracked
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - looking to close /home/solr/solr/data [CachedDir<<refCount=0;path=/home/solr/solr/data;done=false>>]
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - Closing directory: /home/solr/solr/data
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - looking to close /home/solr/solr/data/index [CachedDir<<refCount=0;path=/home/solr/solr/data/index;done=false>>]
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.apache.solr.core.CachingDirectoryFactory) - Closing directory: /home/solr/solr/data/index
[29 Jan 2014 19:31:30] [main-EventThread] WARN (org.apache.solr.common.cloud.ZkStateReader$3) - ZooKeeper watch triggered, but Solr cannot talk to ZK
[29 Jan 2014 19:31:30] [Thread-1] INFO (org.eclipse.jetty.server.handler.ContextHandler) - stopped o.e.j.w.WebAppContext{/solr,file:/home/solr/solr/solr-4.4.0/example/solr-webapp/webapp/},/home/solr/solr/solr-4.4.0/example/webapps/solr.war
