Solr 4.1/4.2 - SolrException: Error opening new searcher

classic Classic list List threaded Threaded
6 messages Options
Reply | Threaded
Open this post in threaded view
|

Solr 4.1/4.2 - SolrException: Error opening new searcher

mark12345
This post was updated on .
I am running into issues where my Solr 4.1/4.2 instance is behaving weirdly.  After I get the SolrException "Error opening new searcher", my Solr instance fails to handle even the simplest of update requests.

I have found some suggestions that tend to suggest that I am making more Solr commit requests than what my instance can handle, though I am unsure on the way forward.  What is really annoying is that I seem to have to restart my Solr instance (service tomcat7 restart) to get things working again.  I am very concerned about this behaviour, as it seems that if I was to get a spike in demand, the whole instance could fall down.

Any suggestions on the way forward?


---------

14:30:00 SEVERE SolrCore org.apache.solr.common.SolrException: Error opening new searcher
14:30:00 SEVERE SolrDispatchFilter null:org.apache.solr.common.SolrException: Error opening new searcher

-- On Tomcat Solr restart --

14:31:19 WARNING UpdateLog Starting log replay tlog{file=/opt/solr/instances/solr/collection1/data/tlog/tlog.0000000000000017502 refcount=2} active=false starting pos=0
14:31:20 WARNING UpdateLog Log replay finished. recoveryInfo=RecoveryInfo{adds=2 deletes=0 deleteByQuery=0 errors=0 positionOfStart=0}

---------
Reply | Threaded
Open this post in threaded view
|

Re: SolrException: Error opening new searcher

Mark Miller-3
exceeding max warming searchers and failing to open a searcher are entirely different things.

Your problem is more severe.

Have any more logs? There should likely be deeper stack traces telling why the Searcher could not be opened.

- Mark

On Mar 12, 2013, at 12:41 AM, mark12345 <[hidden email]> wrote:

> I am running into issues where my Solr instance is behaving weirdly.  After I
> get the SolrException "Error opening new searcher", my Solr instance fails
> to handle even the simplest of update requests.
>
>
>> http://lucene.472066.n3.nabble.com/exceeded-limit-of-maxWarmingSearchers-td494732.html
>
> I have found some suggestions that tend to suggest that I am making more
> Solr commit requests than what my instance can handle, though I am unsure on
> the way forward.  What is really annoying is that I seem to have to restart
> my Solr instance (service tomcat7 restart) to get things working again.  I
> am very concerned about this behaviour, as it seems that if I was to get a
> spike in demand, the whole instance could fall down.
>
> Any suggestions on the way forward?
>
>
> ---------
>
> 14:30:00 SEVERE SolrCore org.apache.solr.common.SolrException: Error
> opening new searcher
> 14:30:00 SEVERE SolrDispatchFilter
> null:org.apache.solr.common.SolrException: Error opening new searcher
>
> -- On Tomcat Solr restart --
>
> 14:31:19 WARNING UpdateLog Starting log replay
> tlog{file=/opt/solr/instances/solr/collection1/data/tlog/tlog.0000000000000017502
> refcount=2} active=false starting pos=0
> 14:31:20 WARNING UpdateLog Log replay finished.
> recoveryInfo=RecoveryInfo{adds=2 deletes=0 deleteByQuery=0 errors=0
> positionOfStart=0}
>
> ---------
>
>
>
> --
> View this message in context: http://lucene.472066.n3.nabble.com/SolrException-Error-opening-new-searcher-tp4046543.html
> Sent from the Solr - User mailing list archive at Nabble.com.

Reply | Threaded
Open this post in threaded view
|

Re: SolrException: Error opening new searcher

mark12345
I am continuing to work on this problem.  So will update this thread as I go.

These are the only logs I have through the "http://localhost:8080/solr-app/#/~logging " interface.  I am using tomcat to run the solr war.  Is there anything I can do to get more descriptive logs?
Reply | Threaded
Open this post in threaded view
|

Re: SolrException: Error opening new searcher

mark12345
Found the exception logs that match the notifications in http://localhost:8080/solr-app/#/~logging as quoted below:  

14:30:00 SEVERE SolrCore org.apache.solr.common.SolrException: Error opening new searcher
14:30:00 SEVERE SolrDispatchFilter null:org.apache.solr.common.SolrException: Error opening new searcher

Mar 12, 2013 2:30:00 PM org.apache.solr.common.SolrException log
SEVERE: org.apache.solr.common.SolrException: Error opening new searcher
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1423)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1535)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1312)
        at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:558)
        at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(RunUpdateProcessorFactory.java:95)
        at org.apache.solr.update.processor.UpdateRequestProcessor.processCommit(UpdateRequestProcessor.java:64)
        at org.apache.solr.update.processor.DistributedUpdateProcessor.processCommit(DistributedUpdateProcessor.java:1060)
        at org.apache.solr.update.processor.LogUpdateProcessor.processCommit(LogUpdateProcessorFactory.java:157)
        at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandlerUtils.java:69)
        at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
        at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
        at org.apache.solr.core.SolrCore.execute(SolrCore.java:1816)
        at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:448)
        at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:927)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:579)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:309)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:583)
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:597)
        at org.apache.lucene.index.IndexWriter.nrtIsCurrent(IndexWriter.java:4148)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenFromWriter(StandardDirectoryReader.java:266)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:245)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:235)
        at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:169)
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1368)
        ... 28 more

Mar 12, 2013 2:30:00 PM org.apache.solr.common.SolrException log
SEVERE: null:org.apache.solr.common.SolrException: Error opening new searcher
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1423)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1535)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1312)
        at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:558)
        at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(RunUpdateProcessorFactory.java:95)
        at org.apache.solr.update.processor.UpdateRequestProcessor.processCommit(UpdateRequestProcessor.java:64)
        at org.apache.solr.update.processor.DistributedUpdateProcessor.processCommit(DistributedUpdateProcessor.java:1060)
        at org.apache.solr.update.processor.LogUpdateProcessor.processCommit(LogUpdateProcessorFactory.java:157)
        at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandlerUtils.java:69)
        at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
        at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
        at org.apache.solr.core.SolrCore.execute(SolrCore.java:1816)
        at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:448)
        at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:269)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:927)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:579)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:309)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:583)
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:597)
        at org.apache.lucene.index.IndexWriter.nrtIsCurrent(IndexWriter.java:4148)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenFromWriter(StandardDirectoryReader.java:266)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:245)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:235)
        at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:169)
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1368)
        ... 28 more
Reply | Threaded
Open this post in threaded view
|

Re: Solr 4.1/4.2 - SolrException: Error opening new searcher - With JUnit test class

mark12345
This post was updated on .
In reply to this post by mark12345
I wrote a simple test to reproduce a very similar stack trace to the above issue, where only some line numbers differences due to Solr 4.1 vs Solr 4.2.


Source of Exception

* http://svn.apache.org/viewvc/lucene/dev/tags/lucene_solr_4_1_0/solr/core/src/java/org/apache/solr/core/SolrCore.java?view=markup
* http://svn.apache.org/viewvc/lucene/dev/tags/lucene_solr_4_2_0/solr/core/src/java/org/apache/solr/core/SolrCore.java?view=markup
catch (Exception e) {
    throw new SolrException(SolrException.ErrorCode.SERVER_ERROR, "Error opening new searcher", e);
}


Any ideas as to why the following happens?  Any help would be very appreciated.




* The test case:
    @Test
    public void documentCommitAndRollbackTest() throws Exception {

        // Fix:  SolrException: Error opening new searcher

        server.rollback();
        server.commit();
    }

* The similar stack trace (Which is repeated twice):
Mar 15, 2013 3:48:09 PM org.apache.solr.common.SolrException log
SEVERE: org.apache.solr.common.SolrException: Error opening new searcher
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1415)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1527)
        at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1304)
        at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:570)
        at org.apache.solr.update.processor.RunUpdateProcessor.processCommit(RunUpdateProcessorFactory.java:95)
        at org.apache.solr.update.processor.UpdateRequestProcessor.processCommit(UpdateRequestProcessor.java:64)
        at org.apache.solr.update.processor.DistributedUpdateProcessor.processCommit(DistributedUpdateProcessor.java:1055)
        at org.apache.solr.update.processor.LogUpdateProcessor.processCommit(LogUpdateProcessorFactory.java:157)
        at org.apache.solr.handler.RequestHandlerUtils.handleCommit(RequestHandlerUtils.java:69)
        at org.apache.solr.handler.ContentStreamHandlerBase.handleRequestBody(ContentStreamHandlerBase.java:68)
        at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
        at org.apache.solr.core.SolrCore.execute(SolrCore.java:1797)
        at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:637)
        at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:343)
        at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:141)
        at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
        at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
        at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
        at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
        at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:98)
        at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:927)
        at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
        at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:407)
        at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:987)
        at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:579)
        at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:307)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:722)
Caused by: org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:583)
        at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:597)
        at org.apache.lucene.index.IndexWriter.nrtIsCurrent(IndexWriter.java:4143)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenFromWriter(StandardDirectoryReader.java:266)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:245)
        at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:235)
        at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:169)
        at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1360)
        ... 29 more



* The test class:
package org.apache.lucene.solr;

import java.io.Serializable;
import java.util.Date;
import java.util.List;
import java.util.Locale;
import java.util.UUID;

import junit.framework.Assert;

import org.apache.solr.client.solrj.SolrQuery;
import org.apache.solr.client.solrj.beans.Field;
import org.apache.solr.client.solrj.impl.BinaryRequestWriter;
import org.apache.solr.client.solrj.impl.HttpSolrServer;
import org.apache.solr.client.solrj.response.QueryResponse;
import org.apache.solr.client.solrj.response.UpdateResponse;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;


public class SolrJBeanTest {

    private static HttpSolrServer server;

    static {

        String url = "http://localhost:8080/solr/collection1";

        server = new HttpSolrServer(url);

         server.setRequestWriter(new BinaryRequestWriter());
//         server.setParser(new XMLResponseParser()); // binary parser is used by default

        server.setSoTimeout(5000); // socket read timeout
        server.setConnectionTimeout(30000);
        server.setDefaultMaxConnectionsPerHost(100);
        server.setMaxTotalConnections(100);
        server.setFollowRedirects(false); // defaults to false
        // allowCompression defaults to false.
        // Server side must support gzip or deflate for this to have any effect.
        server.setAllowCompression(true);
        server.setMaxRetries(1); // defaults to 0.  > 1 not recommended.

    }

    @Before
    public void setUp() throws Exception {

        UpdateResponse updateResponse = server.deleteByQuery("type_s:" + "MyTestBean");
        Assert.assertEquals(0, updateResponse.getStatus());

        commit();

    }


    @After
    public void tearDown() throws Exception {

        UpdateResponse updateResponse = server.deleteByQuery("type_s:" + "MyTestBean");
        Assert.assertEquals(0, updateResponse.getStatus());

        commit();

        List<MyTestBean> beans = getTestBeans();
        Assert.assertEquals(0, beans.size());

    }

    private static void commit() throws Exception {
        UpdateResponse updateResponseForCommit = server.commit();
        Assert.assertEquals(0, updateResponseForCommit.getStatus());
    }

    private static void rollback() throws Exception {
        UpdateResponse updateResponseForCommit = server.rollback();
        Assert.assertEquals(0, updateResponseForCommit.getStatus());
    }


    @Test
    public void documentCommitAndRollbackTest() throws Exception {

        // Fix:  SolrException: Error opening new searcher

        server.rollback();
        server.commit();
    }

    @Test
    public void addBeanTest() throws Exception {

        MyTestBean myTestBean = createTestBean("addBeanTest");
        UpdateResponse updateResponse = server.addBean(myTestBean);
        Assert.assertEquals(0, updateResponse.getStatus());

        Thread.sleep(1000);

        // No Bean Found
        {
            MyTestBean myTestBeanStored = getTestBean(myTestBean.getId());
            Assert.assertNull(myTestBeanStored);
        }

        UpdateResponse updateResponseForCommit = server.commit();
        Assert.assertEquals(0, updateResponseForCommit.getStatus());

        // Bean Found
        {
            MyTestBean myTestBeanStored = getTestBean(myTestBean.getId());
            Assert.assertNotNull(myTestBeanStored);

            Assert.assertEquals(myTestBean.getId(), myTestBeanStored.getId());
            Assert.assertEquals(myTestBean.getType(), myTestBeanStored.getType());
            Assert.assertEquals(myTestBean.getValue(), myTestBeanStored.getValue());
            Assert.assertEquals(myTestBean.getCreatedDate(), myTestBeanStored.getCreatedDate());

            Assert.assertEquals(-1L, myTestBean.get_version_().longValue());
            Assert.assertTrue(myTestBeanStored.get_version_() > 0);
        }

    }

    @Test
    public void addBeanWithRollbackTest() throws Exception {

        MyTestBean myTestBean = createTestBean("addBeanTest");
        UpdateResponse updateResponse = server.addBean(myTestBean);
        Assert.assertEquals(0, updateResponse.getStatus());

        Thread.sleep(1000);

        // No Bean Found
        {
            MyTestBean myTestBeanStored = getTestBean(myTestBean.getId());
            Assert.assertNull(myTestBeanStored);
        }

        UpdateResponse updateResponseForCommit = server.rollback();
        Assert.assertEquals(0, updateResponseForCommit.getStatus());

        // No Bean Found
        {
            MyTestBean myTestBeanStored = getTestBean(myTestBean.getId());
            Assert.assertNull(myTestBeanStored);
        }

    }


    private MyTestBean createTestBean(String value) {
        MyTestBean myTestBean = new MyTestBean();
        myTestBean.setId(UUID.randomUUID().toString().toLowerCase(Locale.ENGLISH));
        myTestBean.setType("MyTestBean");
        myTestBean.setCreatedDate(new Date());
        myTestBean.setValue(value);
        myTestBean.set_version_(-1L);
        return myTestBean;
    }

    private static List<MyTestBean> getTestBeans() throws Exception {
        return getTestBeans(null, null);
    }

    private static MyTestBean getTestBean(String id) throws Exception {
        List<MyTestBean> beans = getTestBeans(id, null);

        if (beans == null || beans.size() == 0) {
            return null;
        }

        return beans.get(0);
    }

    private static List<MyTestBean> getTestBeans(String id, String value) throws Exception {

        SolrQuery solrQuery = new SolrQuery();
        solrQuery.setQuery("*:*");
        if (id != null) {
            solrQuery.addFilterQuery("id:" + id);
        }
        solrQuery.addFilterQuery("type_s:" + "MyTestBean");
        if (value != null) {
            solrQuery.addFilterQuery("value:" + value);
        }

        QueryResponse queryResponse = server.query(solrQuery);

        List<MyTestBean> beans = queryResponse.getBeans(MyTestBean.class);

        return beans;

    }


    public static class MyTestBean implements Serializable {

        private static final long serialVersionUID = 1L;

        @Field("id")
        private String id;

        @Field("type_s")
        private String type;

        @Field("value_s")
        private String value;

        @Field("created_dt")
        private Date createdDate;

        @Field("_version_")
        private Long _version_;

        public MyTestBean() {

        }

        public String getId() {
            return id;
        }

        public void setId(String id) {
            this.id = id;
        }

        public String getType() {
            return type;
        }

        public void setType(String type) {
            this.type = type;
        }

        public String getValue() {
            return value;
        }

        public void setValue(String value) {
            this.value = value;
        }

        public Date getCreatedDate() {
            return createdDate;
        }

        public void setCreatedDate(Date createdDate) {
            this.createdDate = createdDate;
        }

        public Long get_version_() {
            return _version_;
        }

        public void set_version_(Long _version_) {
            this._version_ = _version_;
        }

        @Override
        public String toString() {
            return "MyTestBean [id=" + id + ", type=" + type + ", value=" + value + ", createdDate=" + createdDate
                    + ", _version_=" + _version_ + "]";
        }

    }

}
Reply | Threaded
Open this post in threaded view
|

Re: Solr 4.1/4.2 - SolrException: Error opening new searcher - With JUnit test class

mark12345