How do I reload the Solr config in Zookeeper ?

[#1]

Hi all,

Our cluster just got rebooted by a remote user, all is back to normality but the solr instance cant start it complaining for missing xml.

Here is the log can someone help out I am stuck for 3 hours now

root@nuveb:/var/log/solr# cat solr_log_20170322_1046
2017-01-23 16:08:34,915 [main] INFO  [   ] org.eclipse.jetty.util.log.Log (Log.java:186) - Logging initialized @359ms
2017-01-23 16:08:35,064 [main] INFO  [   ] org.eclipse.jetty.server.Server (Server.java:327) - jetty-9.2.13.v20150730
2017-01-23 16:08:35,093 [main] WARN  [   ] org.eclipse.jetty.server.handler.RequestLogHandler (RequestLogHandler.java:137) - !RequestLog
2017-01-23 16:08:35,097 [main] INFO  [   ] org.eclipse.jetty.deploy.providers.ScanningAppProvider (ScanningAppProvider.java:133) - Deployment monitor [file:/opt/lucidworks-hdpsearch/solr/server/contexts/] at interval 0
2017-01-23 16:08:35,312 [main] INFO  [   ] org.eclipse.jetty.webapp.StandardDescriptorProcessor (StandardDescriptorProcessor.java:297) - NO JSP Support for /banana, did not find org.eclipse.jetty.jsp.JettyJspServlet
2017-01-23 16:08:35,353 [main] INFO  [   ] org.eclipse.jetty.server.handler.ContextHandler (ContextHandler.java:744) - Started o.e.j.w.WebAppContext@50eac852{/banana,file:/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp-banana-1.6.0/banana-webapp/webapp/,AVAILABLE}{/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp-banana-1.6.0/banana-1.6.0.war}
2017-01-23 16:08:35,609 [main] INFO  [   ] org.eclipse.jetty.webapp.StandardDescriptorProcessor (StandardDescriptorProcessor.java:297) - NO JSP Support for /solr, did not find org.apache.jasper.servlet.JspServlet
2017-01-23 16:08:35,613 [main] WARN  [   ] org.eclipse.jetty.security.ConstraintSecurityHandler (ConstraintSecurityHandler.java:807) - ServletContext@o.e.j.w.WebAppContext@198b6731{/solr,file:/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp/,STARTING}{/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp} has uncovered http methods for path: /
2017-01-23 16:08:35,626 [main] INFO  [   ] org.apache.solr.servlet.SolrDispatchFilter (SolrDispatchFilter.java:91) - SolrDispatchFilter.init(): WebAppClassLoader=2087258327@7c6908d7
2017-01-23 16:08:35,650 [main] INFO  [   ] org.apache.solr.core.SolrResourceLoader (SolrResourceLoader.java:781) - JNDI not configured for solr (NoInitialContextEx)
2017-01-23 16:08:35,650 [main] INFO  [   ] org.apache.solr.core.SolrResourceLoader (SolrResourceLoader.java:793) - using system property solr.solr.home: /etc/solr/data_dir
2017-01-23 16:08:35,651 [main] INFO  [   ] org.apache.solr.core.SolrResourceLoader (SolrResourceLoader.java:170) - new SolrResourceLoader for directory: '/etc/solr/data_dir'
2017-01-23 16:08:35,652 [main] INFO  [   ] org.apache.solr.core.SolrResourceLoader (SolrResourceLoader.java:781) - JNDI not configured for solr (NoInitialContextEx)
2017-01-23 16:08:35,652 [main] INFO  [   ] org.apache.solr.core.SolrResourceLoader (SolrResourceLoader.java:793) - using system property solr.solr.home: /etc/solr/data_dir
2017-01-23 16:08:35,670 [main] INFO  [   ] org.apache.solr.common.cloud.SolrZkClient (SolrZkClient.java:211) - Using default ZkCredentialsProvider
2017-01-23 16:08:35,701 [main] INFO  [   ] org.apache.solr.common.cloud.ConnectionManager (ConnectionManager.java:192) - Waiting for client to connect to ZooKeeper
2017-01-23 16:08:36,080 [zkCallback-1-thread-1] INFO  [   ] org.apache.solr.common.cloud.ConnectionManager (ConnectionManager.java:102) - Watcher org.apache.solr.common.cloud.ConnectionManager@4668cbcb name:ZooKeeperConnection Watcher:10.176.69.1:2181,10.176.69.9:2181 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
2017-01-23 16:08:36,080 [main] INFO  [   ] org.apache.solr.common.cloud.ConnectionManager (ConnectionManager.java:210) - Client is connected to ZooKeeper
2017-01-23 16:08:36,081 [main] INFO  [   ] org.apache.solr.common.cloud.SolrZkClient (SolrZkClient.java:227) - Using default ZkACLProvider
2017-01-23 16:08:36,087 [main-SendThread(10.176.69.1:2181)] ERROR [   ] org.apache.zookeeper.client.ZooKeeperSaslClient (ZooKeeperSaslClient.java:384) - An error: (java.security.PrivilegedActionException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Server not found in Kerberos database (7) - LOOKING_UP_SERVER)]) occurred when evaluating Zookeeper Quorum Member's  received SASL token. Zookeeper Client will go to AUTH_FAILED state.
2017-01-23 16:08:36,087 [main-SendThread(10.176.69.1:2181)] ERROR [   ] org.apache.zookeeper.ClientCnxn$SendThread (ClientCnxn.java:1015) - SASL authentication with Zookeeper Quorum member failed: javax.security.sasl.SaslException: An error: (java.security.PrivilegedActionException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Server not found in Kerberos database (7) - LOOKING_UP_SERVER)]) occurred when evaluating Zookeeper Quorum Member's  received SASL token. Zookeeper Client will go to AUTH_FAILED state.
2017-01-23 16:08:36,088 [zkCallback-1-thread-1] INFO  [   ] org.apache.solr.common.cloud.ConnectionManager (ConnectionManager.java:102) - Watcher org.apache.solr.common.cloud.ConnectionManager@4668cbcb name:ZooKeeperConnection Watcher:10.176.69.1:2181,10.176.69.9:2181 got event WatchedEvent state:AuthFailed type:None path:null path:null type:None
2017-01-23 16:08:36,088 [zkCallback-1-thread-1] WARN  [   ] org.apache.solr.common.cloud.ConnectionManager (ConnectionManager.java:171) - zkClient received AuthFailed
2017-01-23 16:08:36,197 [main] ERROR [   ] org.apache.solr.servlet.SolrDispatchFilter (SolrDispatchFilter.java:116) - Could not start Solr. Check solr/home property and the logs
2017-01-23 16:08:36,225 [main] ERROR [   ] org.apache.solr.common.SolrException (SolrException.java:159) - null:org.apache.solr.common.SolrException: Error occurred while loading solr.xml from zookeeper
        at org.apache.solr.servlet.SolrDispatchFilter.loadNodeConfig(SolrDispatchFilter.java:159)
        at org.apache.solr.servlet.SolrDispatchFilter.createCoreContainer(SolrDispatchFilter.java:131)
        at org.apache.solr.servlet.SolrDispatchFilter.init(SolrDispatchFilter.java:109)
        at org.eclipse.jetty.servlet.FilterHolder.initialize(FilterHolder.java:138)
        at org.eclipse.jetty.servlet.ServletHandler.initialize(ServletHandler.java:852)
        at org.eclipse.jetty.servlet.ServletContextHandler.startContext(ServletContextHandler.java:298)
        at org.eclipse.jetty.webapp.WebAppContext.startWebapp(WebAppContext.java:1349)
        at org.eclipse.jetty.webapp.WebAppContext.startContext(WebAppContext.java:1342)
        at org.eclipse.jetty.server.handler.ContextHandler.doStart(ContextHandler.java:741)
        at org.eclipse.jetty.webapp.WebAppContext.doStart(WebAppContext.java:505)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.bindings.StandardStarter.processBinding(StandardStarter.java:41)
        at org.eclipse.jetty.deploy.AppLifeCycle.runBindings(AppLifeCycle.java:186)
        at org.eclipse.jetty.deploy.DeploymentManager.requestAppGoal(DeploymentManager.java:498)
        at org.eclipse.jetty.deploy.DeploymentManager.addApp(DeploymentManager.java:146)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider.fileAdded(ScanningAppProvider.java:180)
        at org.eclipse.jetty.deploy.providers.WebAppProvider.fileAdded(WebAppProvider.java:461)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider$1.fileAdded(ScanningAppProvider.java:64)
        at org.eclipse.jetty.util.Scanner.reportAddition(Scanner.java:609)
        at org.eclipse.jetty.util.Scanner.reportDifferences(Scanner.java:528)
        at org.eclipse.jetty.util.Scanner.scan(Scanner.java:391)
        at org.eclipse.jetty.util.Scanner.doStart(Scanner.java:313)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.providers.ScanningAppProvider.doStart(ScanningAppProvider.java:150)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.deploy.DeploymentManager.startAppProvider(DeploymentManager.java:560)
        at org.eclipse.jetty.deploy.DeploymentManager.doStart(DeploymentManager.java:235)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.util.component.ContainerLifeCycle.start(ContainerLifeCycle.java:132)
        at org.eclipse.jetty.server.Server.start(Server.java:387)
        at org.eclipse.jetty.util.component.ContainerLifeCycle.doStart(ContainerLifeCycle.java:114)
        at org.eclipse.jetty.server.handler.AbstractHandler.doStart(AbstractHandler.java:61)
        at org.eclipse.jetty.server.Server.doStart(Server.java:354)
        at org.eclipse.jetty.util.component.AbstractLifeCycle.start(AbstractLifeCycle.java:68)
        at org.eclipse.jetty.xml.XmlConfiguration$1.run(XmlConfiguration.java:1255)
        at java.security.AccessController.doPrivileged(Native Method)
        at org.eclipse.jetty.xml.XmlConfiguration.main(XmlConfiguration.java:1174)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:497)
        at org.eclipse.jetty.start.Main.invokeMain(Main.java:321)
        at org.eclipse.jetty.start.Main.start(Main.java:817)
        at org.eclipse.jetty.start.Main.main(Main.java:112)
Caused by: org.apache.zookeeper.KeeperException$AuthFailedException: KeeperErrorCode = AuthFailed for /solr.xml
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:123)
        at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
        at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
        at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:311)
        at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:308)
        at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
        at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:308)
        at org.apache.solr.servlet.SolrDispatchFilter.loadNodeConfig(SolrDispatchFilter.java:153)
        ... 43 more
2017-01-23 16:08:36,225 [main] INFO  [   ] org.apache.solr.servlet.SolrDispatchFilter (SolrDispatchFilter.java:123) - SolrDispatchFilter.init() done
2017-01-23 16:08:36,228 [main] INFO  [   ] org.eclipse.jetty.server.handler.ContextHandler (ContextHandler.java:744) - Started o.e.j.w.WebAppContext@198b6731{/solr,file:/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp/,AVAILABLE}{/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp}
2017-01-23 16:08:36,236 [main] INFO  [   ] org.eclipse.jetty.server.AbstractConnector (AbstractConnector.java:266) - Started ServerConnector@6caf0677{HTTP/1.1}{0.0.0.0:8983}
2017-01-23 16:08:36,237 [main] INFO  [   ] org.eclipse.jetty.server.Server (Server.java:379) - Started @1683ms
2017-03-22 10:42:09,937 [ShutdownMonitor] INFO  [   ] org.eclipse.jetty.server.AbstractConnector (AbstractConnector.java:306) - Stopped ServerConnector@6caf0677{HTTP/1.1}{0.0.0.0:8983}
2017-03-22 10:42:09,947 [ShutdownMonitor] INFO  [   ] org.eclipse.jetty.server.handler.ContextHandler (ContextHandler.java:865) - Stopped o.e.j.w.WebAppContext@198b6731{/solr,file:/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp/,UNAVAILABLE}{/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp}
2017-03-22 10:42:09,949 [ShutdownMonitor] INFO  [   ] org.eclipse.jetty.server.handler.ContextHandler (ContextHandler.java:865) - Stopped o.e.j.w.WebAppContext@50eac852{/banana,file:/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp-banana-1.6.0/banana-webapp/webapp/,UNAVAILABLE}{/opt/lucidworks-hdpsearch/solr/server/solr-webapp/webapp-banana-1.6.0/banana-1.6.0.war} 

[#2 · Accepted solution]

@Geoffrey Shelton Okot

As per the "SolrDispatchFilter.java" code following is the logic which it uses to load the "solr.xml" file (from zookeeper)

  public static NodeConfig loadNodeConfig(Path solrHome, Properties nodeProperties) {
    SolrResourceLoader loader = new SolrResourceLoader(solrHome, null, nodeProperties);
    if (!StringUtils.isEmpty(System.getProperty("solr.solrxml.location"))) {
      log.warn("Solr property solr.solrxml.location is no longer supported. " +
               "Will automatically load solr.xml from ZooKeeper if it exists");
    }

.

But in your mentioned log it looks like zookeeper is having some Kerberos issues "GSS initiate failed" and "Server not found in Kerberos database (7)"

. Can you check if you see valid kerberos tickets or if you are able to list the tickets or do a "kinit" ?

2017-01-23 16:08:36,087 [main-SendThread(10.176.69.1:2181)] ERROR [   ] org.apache.zookeeper.client.ZooKeeperSaslClient (ZooKeeperSaslClient.java:384) - An error: (java.security.PrivilegedActionException: javax.security.sasl.SaslException: GSS initiate failed [Caused by GSSException: No valid credentials provided (Mechanism level: Server not found in Kerberos database (7) - LOOKING_UP_SERVER)]) occurred when evaluating Zookeeper Quorum Member's  received SASL token. Zookeeper Client will go to AUTH_FAILED state.

.

[#3]

We got the solution at the same time but I will give you the points it isn't fare to give myself 🙂

[#4]

Hi all,

Problem resolved I grabbed a new kerberos ticket and started solr

root@nuveb:/opt/lucidworks-hdpsearch/solr# bin/solr start
Waiting up to 30 seconds to see Solr running on port 8983 [/]
Started Solr server on port 8983 (pid=5214). Happy searching!

Thanks