Weirdly, this happened again today, deleting a brand new 300GB index that we created after last time, and which had been working for several days.
This time, the index was deleted by our log rotation script, which restarted solr, so it's very easy to see what happened before and after the problem. Before the restart, queries were working just fine, and then during shutdown, the only problematic line is the last, which shows: 590125499 [Thread-0] WARN org.eclipse.jetty.util.thread.QueuedThreadPool – 1 threads could not be stopped 590125500 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – Couldn't stop Thread[qtp597653135-10081,5,main] 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.search.FieldValueHitQueue$OneComparatorFieldValueHitQueue.lessThan(FieldValueHitQueue.java:84) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.search.FieldValueHitQueue$OneComparatorFieldValueHitQueue.lessThan(FieldValueHitQueue.java:58) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.util.PriorityQueue.downHeap(PriorityQueue.java:246) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.util.PriorityQueue.pop(PriorityQueue.java:177) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.search.TopFieldCollector.populateResults(TopFieldCollector.java:1207) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.lucene.search.TopDocsCollector.topDocs(TopDocsCollector.java:156) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.search.SolrIndexSearcher.getDocListNC(SolrIndexSearcher.java:1622) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.search.SolrIndexSearcher.getDocListC(SolrIndexSearcher.java:1433) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.search.SolrIndexSearcher.search(SolrIndexSearcher.java:514) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.handler.component.QueryComponent.process(QueryComponent.java:484) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.handler.component.SearchHandler.handleRequestBody(SearchHandler.java:218) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.core.SolrCore.execute(SolrCore.java:1976) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.servlet.SolrDispatchFilter.execute(SolrDispatchFilter.java:777) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:418) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:207) 590125501 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:557) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:231) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1075) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:255) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:154) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.Server.handle(Server.java:368) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.BlockingHttpConnection.handleRequest(BlockingHttpConnection.java:53) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:942) 590125502 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1004) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:640) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.BlockingHttpConnection.handle(BlockingHttpConnection.java:72) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.server.bio.SocketConnector$ConnectorEndPoint.run(SocketConnector.java:264) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543) 590125503 [Thread-0] INFO org.eclipse.jetty.util.thread.QueuedThreadPool – at java.lang.Thread.run(Thread.java:745) Those are the last lines in the log, after all of the other indexes shut down properly. After that, a new log file is started, and it cannot start the index, complaining about missing files. So at that point, the index is gone. I'd love to prevent this from happening a third time. It's super baffling. Any ideas? Mike On Tue, Jun 20, 2017 at 12:38 PM Mike Lissner < mliss...@michaeljaylissner.com> wrote: > Thanks for the suggestions everybody. > > Some responses to Shawn's questions: > > > Does your solr.xml file contain core definitions, or is that information > in a core.properties file in each instanceDir? > > Were using core.properties files. > > > How did you install Solr > > Solr is installed just by downloading and unzipping. From there, we use > the example directories as a starting point. > > > > and how are you starting it? > > Using a pretty simple init script. Nothing too exotic here. > > > Do you have the full error and stacktrace from those null pointer > exceptions? > > I put a log of the startup here: > https://www.courtlistener.com/tools/sample-data/misc/null_logs.txt > > I created this by doing `grep -C 1000 -i nullpointer`, then cleaning out > any private queries. I looked through it a bit. It looks like the index was > missing a file, and was therefore unable to start up. I won't say it's > impossible that the index was deleted before I started Solr, but it seemed > to be operating fine using the other name prior to stopping solr and > putting in a symlink. In the real-world logs, our disks are named /sata and > /sata8 instead of /old and /new. > > > > In the context of that information, what exactly did you do at each step > of your process? > > The process above was pretty boring really. > > 1. Create new index and populate it: > > - copied an existing index configuration into a new directory > - tweaked the datadir parameter in core.properties > - restarted solr > - re-indexed the database using usual HTTP API to populate the new index > > 2. stop solr: sudo service solr stop > > 3. make symlink: > > - mv'ed the old index out of the way > - ln -s old new (or vice versa, I never remember which way ln goes) > > 4. start solr: sudo service solr start > > FWIW, I've got it working now using the SWAP index functionality, so the > above is just in case somebody wants to try to track this down. I'll > probably take those logs offline after a week or two. > > Mike > > > On Tue, Jun 20, 2017 at 7:20 AM Shawn Heisey <apa...@elyograg.org> wrote: > >> On 6/14/2017 12:26 PM, Mike Lissner wrote: >> > We are replacing a drive mounted at /old with one mounted at /new. Our >> > index currently lives on /old, and our plan was to: >> > >> > 1. Create a new index on /new >> > 2. Reindex from our database so that the new index on /new is properly >> > populated. >> > 3. Stop solr. >> > 4. Symlink /old to /new (Solr now looks for the index at /old/solr, >> which >> > redirects to /new/solr) >> > 5. Start solr >> > 6. (Later) Stop solr, swap the drives (old for new), and start solr. >> (Solr >> > now looks for the index at /old/solr again, and finds it there.) >> > 7. Delete the index pointing to /new created in step 1. >> > >> > The idea was that this would create a new index for solr, would >> populate it >> > with the right content, and would avoid having to touch our existing >> solr >> > configurations aside from creating one new index, which we could soon >> > delete. >> > >> > I just did steps 1-5, but I got null pointer exceptions when starting >> solr, >> > and it appears that the index on /new has been almost completely >> deleted by >> > Solr (this is a bummer, since it takes days to populate). >> > >> > Is this expected? Am I terribly crazy to try to swap indexes on disk? As >> > far as I know, the only difference between the indexes is their name. >> > >> > We're using Solr version 4.10.4. >> >> Solr should not delete indexes on startup. The only time it should do >> that is when you explicitly request deletion. Do you have the full >> error and stacktrace from those null pointer exceptions? Something >> would have to be very wrong for it to behave like you describe. >> >> Does your solr.xml file contain core definitions, or is that information >> in a core.properties file in each instanceDir? The latter is the only >> option supported in 5.0 and later, but the 4.10 version still supports >> both. >> >> How is Solr itself and the data directories laid out? How did you >> install Solr, and how are you starting it? In the context of that >> information, what exactly did you do at each step of your process? >> >> Thanks, >> Shawn >> >>
