Hi guys,
Every day in the morning I’m getting this error on Dremio. It doesn’t show the reason for that message and when I check the service on my coordinator and executor nodes, the service is up.
However, When I check the logs, searching for some reason for the problem, I see this message, mentioning the reflection manager. I guess the problem is related to reflections, because when I restart the service, Dremio works again (up to the next day/reflection management). Does anybody know what might be happening here?
Log:
2018-12-20 11:15:34,474 [dremio-general-3] ERROR c.d.s.reflection.ReflectionManager - Reflection manager failed
org.apache.lucene.store.AlreadyClosedException: this IndexWriter is closed
at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:749) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.IndexWriter.ensureOpen(IndexWriter.java:763) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:3206) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at com.dremio.datastore.indexed.LuceneSearchIndex.commit(LuceneSearchIndex.java:274) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.LuceneSearchIndex.access$400(LuceneSearchIndex.java:61) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.LuceneSearchIndex$CommitterThread.commitLoop(LuceneSearchIndex.java:167) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.LuceneSearchIndex$CommitterThread.access$000(LuceneSearchIndex.java:127) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.LuceneSearchIndex$CommitterThread$1.run(LuceneSearchIndex.java:136) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
Caused by: java.nio.file.FileSystemException: /var/lib/dremio/db/search/dac-namespace/core/_fq9_Lucene54_0.dvd: Too many open files
at sun.nio.fs.UnixException.translateToIOException(UnixException.java:91) ~[na:1.8.0_191]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102) ~[na:1.8.0_191]
at sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107) ~[na:1.8.0_191]
at sun.nio.fs.UnixFileSystemProvider.newByteChannel(UnixFileSystemProvider.java:214) ~[na:1.8.0_191]
at java.nio.file.spi.FileSystemProvider.newOutputStream(FileSystemProvider.java:434) ~[na:1.8.0_191]
at java.nio.file.Files.newOutputStream(Files.java:216) ~[na:1.8.0_191]
at org.apache.lucene.store.FSDirectory$FSIndexOutput.<init>(FSDirectory.java:413) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.store.FSDirectory$FSIndexOutput.<init>(FSDirectory.java:409) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.store.FSDirectory.createOutput(FSDirectory.java:253) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.store.LockValidatingDirectoryWrapper.createOutput(LockValidatingDirectoryWrapper.java:44) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.store.TrackingDirectoryWrapper.createOutput(TrackingDirectoryWrapper.java:43) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.codecs.lucene54.Lucene54DocValuesConsumer.<init>(Lucene54DocValuesConsumer.java:73) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.codecs.lucene54.Lucene54DocValuesFormat.fieldsConsumer(Lucene54DocValuesFormat.java:108) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.getInstance(PerFieldDocValuesFormat.java:213) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.codecs.perfield.PerFieldDocValuesFormat$FieldsWriter.addSortedField(PerFieldDocValuesFormat.java:121) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.SortedDocValuesWriter.flush(SortedDocValuesWriter.java:130) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DefaultIndexingChain.writeDocValues(DefaultIndexingChain.java:258) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DefaultIndexingChain.flush(DefaultIndexingChain.java:142) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DocumentsWriterPerThread.flush(DocumentsWriterPerThread.java:444) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DocumentsWriter.doFlush(DocumentsWriter.java:539) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DocumentsWriter.flushAllThreads(DocumentsWriter.java:653) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:445) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.StandardDirectoryReader.doOpenFromWriter(StandardDirectoryReader.java:291) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:266) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:256) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:140) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.search.SearcherManager.refreshIfNeeded(SearcherManager.java:156) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.search.SearcherManager.refreshIfNeeded(SearcherManager.java:58) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.search.ReferenceManager.doMaybeRefresh(ReferenceManager.java:176) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at org.apache.lucene.search.ReferenceManager.maybeRefreshBlocking(ReferenceManager.java:253) ~[lucene-core-6.6.0.jar:6.6.0 5c7a7b65d2aa7ce5ec96458315c661a18b320241 - ishan - 2017-05-30 07:29:46]
at com.dremio.datastore.indexed.LuceneSearchIndex.checkIfChanged(LuceneSearchIndex.java:265) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.LuceneSearchIndex.search(LuceneSearchIndex.java:387) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.datastore.indexed.CoreSearchIterable$SearchIterator.hasNext(CoreSearchIterable.java:126) ~[dremio-services-datastore-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.google.common.collect.TransformedIterator.hasNext(TransformedIterator.java:42) ~[guava-20.0.jar:na]
at com.dremio.service.namespace.NamespaceServiceImpl.getByIndex(NamespaceServiceImpl.java:1294) ~[dremio-services-namespace-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.service.namespace.NamespaceServiceImpl.findDatasetByUUID(NamespaceServiceImpl.java:513) ~[dremio-services-namespace-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.service.reflection.ReflectionManager.handleDatasetDeletion(ReflectionManager.java:418) ~[dremio-services-accelerator-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.service.reflection.ReflectionManager.handleDeletedDatasets(ReflectionManager.java:273) ~[dremio-services-accelerator-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.service.reflection.ReflectionManager.run(ReflectionManager.java:176) ~[dremio-services-accelerator-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at com.dremio.common.WakeupHandler$1.run(WakeupHandler.java:63) [dremio-common-3.0.1-201811132128360291-804fe82.jar:3.0.1-201811132128360291-804fe82]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [na:1.8.0_191]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [na:1.8.0_191]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [na:1.8.0_191]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [na:1.8.0_191]
... 1 common frames omitted