Errors on large Mailbox, logs relate to Solr

OSSVirt

I have a user with a large mailbox currently containing 19.1GiB with 43144 message count. He has started having an issue where his mail clients will not send or receive. Checking the Dovecot logs shows me:

09/04/2024, 14:13:10	err	indexer-worker(user@domain.com)<50877><HFwRrqkVJLKsFgH4:GMZNM94+FWa9xgAAQv95JA>: Error: Mailbox Trash: Transaction commit failed: FTS transaction commit failed: backend deinit (attempted to index 1000 messages (UIDs 8584..9587))
09/04/2024, 14:13:10	err	indexer-worker(user@domain.com)<50877><HFwRrqkVJLKsFgH4:GMZNM94+FWa9xgAAQv95JA>: Error: fts_solr: Indexing failed: 500 Server Error
09/04/2024, 14:13:10	err	indexer-worker(user@domain.com)<50877><HFwRrqkVJLKsFgH4:GMZNM94+FWa9xgAAQv95JA>: Error: fts_solr: Indexing failed: 500 Server Error

On the /debug > System Containers page I can see that Solr shows as:

solr-mailcow
Container stopped or disabled
Stopped

I understood that Solr was deprecated and not required for Mailcow operation. Is that correct, or is it necessary for large mailboxes to act as an indexer?

Additionally, reactivating Solr doesn’t work. I have restarted the container:
docker compose restart solr-mailcow

Which succeeds but Solr is still Stopped. I have changed the setting in docker-compose.yml

- SKIP_SOLR=${SKIP_SOLR:-y}
to
- SKIP_SOLR=${SKIP_SOLR:-n}

But Solr stays stopped. The Dovecot logs are showing the same errors more often, so I would like to fix it before it causes a real problem.

Thanks.

DocFraggle

Please never change the docker-compose.yml directly! Check your mailcow.conf, there you can set the SKIP_SOLR property
Solr consumers a lot of memory and is therefore disabled per default

The problem itself may as well be RAM related… how much RAM do you have?

OSSVirt

Please never change the docker-compose.yml directly! Check your mailcow.conf, there you can set the SKIP_SOLR property

Ah that’s good to know! Thank you. I did check mailcow.conf first and solr was not disabled there.

Yes I think it was RAM related. I did a cold-standby sync onto a VM with 7.75GB RAM and Solr was auto-disabled at that point. It ran previously on a very similar VM. I can’t find anything in the Solr logs that specifically mentions auto-disabling due to RAM, I can post the Solr logs if that helps.

Now I have cold-standby synced onward to a new VM with 16GB (15.25GB available) and Solr will not restart even though there is a lot of free RAM.

But is it likely that Solr is the issue here?

Thanks

DocFraggle

Here’s the part about RAM for Solr during the initial generation of mailcow.conf

mailcow/mailcow-dockerizedblob/master/generate_config.sh#L166

But I agree, 16G should be enough now… there’s really nothing in the logs?

What client is being used by the user?

OSSVirt

Here is the Solr log:

Starting Solr OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release. 2024-04-09 13:09:19.436 INFO (main) [ ] o.e.j.u.log Logging initialized @1028ms to org.eclipse.jetty.util.log.Slf4jLog 2024-04-09 13:09:19.578 WARN (main) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time 2024-04-09 13:09:19.584 INFO (main) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 11.0.15+10 2024-04-09 13:09:19.629 INFO (main) [ ] o.e.j.d.p.ScanningAppProvider Deployment monitor [file:///opt/solr/server/contexts/] at interval 0 2024-04-09 13:09:19.844 INFO (main) [ ] o.e.j.w.StandardDescriptorProcessor NO JSP Support for /solr, did not find org.apache.jasper.servlet.JspServlet 2024-04-09 13:09:19.851 INFO (main) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 2024-04-09 13:09:19.851 INFO (main) [ ] o.e.j.s.session No SessionScavenger set, using defaults 2024-04-09 13:09:19.852 INFO (main) [ ] o.e.j.s.session node0 Scavenging every 660000ms 2024-04-09 13:09:19.896 INFO (main) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory 2024-04-09 13:09:19.900 INFO (main) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.7.3 2024-04-09 13:09:19.900 INFO (main) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port 8983 2024-04-09 13:09:19.900 INFO (main) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /opt/solr 2024-04-09 13:09:19.901 INFO (main) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2024-04-09T13:09:19.900970Z 2024-04-09 13:09:19.930 INFO (main) [ ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: /opt/solr/server/solr 2024-04-09 13:09:19.934 INFO (main) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /opt/solr/server/solr/solr.xml 2024-04-09 13:09:19.975 INFO (main) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a, but no JMX reporters were configured - adding default JMX reporter. 2024-04-09 13:09:20.348 INFO (main) [ ] o.a.s.c.SolrResourceLoader [null] Added 0 libs to classloader, from paths: [] 2024-04-09 13:09:20.445 INFO (main) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true] 2024-04-09 13:09:20.690 INFO (main) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores 2024-04-09 13:09:20.692 INFO (main) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. 2024-04-09 13:09:20.744 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-09 13:09:20.744 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-09 13:09:20.750 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-09 13:09:20.770 INFO (main) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /opt/solr/server/solr 2024-04-09 13:09:20.770 INFO (main) [ ] o.a.s.c.CorePropertiesLocator Cores are: [dovecot-fts] 2024-04-09 13:09:20.821 INFO (main) [ ] o.e.j.s.h.ContextHandler Started o.e.j.w.WebAppContext@53142455{/solr,file:///opt/solr/server/solr-webapp/webapp/,AVAILABLE}{/opt/solr/server/solr-webapp/webapp} 2024-04-09 13:09:20.825 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrResourceLoader [dovecot-fts] Added 58 libs to classloader, from paths: [/opt/solr/contrib/clustering/lib, /opt/solr/contrib/extraction/lib, /opt/solr/contrib/langid/lib, /opt/solr/contrib/velocity/lib, /opt/solr/dist] 2024-04-09 13:09:20.832 INFO (main) [ ] o.e.j.s.AbstractConnector Started ServerConnector@12d1f1d4{HTTP/1.1,[http/1.1]}{0.0.0.0:8983} 2024-04-09 13:09:20.832 INFO (main) [ ] o.e.j.s.Server Started @2427ms 2024-04-09 13:09:20.870 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.7.0 2024-04-09 13:09:20.979 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.s.IndexSchema [dovecot-fts] Schema name=dovecot-fts 2024-04-09 13:09:21.087 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.s.IndexSchema Loaded schema dovecot-fts/2.0 with uniqueid field id 2024-04-09 13:09:21.091 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.CoreContainer Creating SolrCore 'dovecot-fts' using configuration from instancedir /opt/solr/server/solr/dovecot-fts, trusted=true 2024-04-09 13:09:21.108 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.dovecot-fts' (registry 'solr.core.dovecot-fts') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-09 13:09:21.116 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrCore [[dovecot-fts] ] Opening new SolrCore at [/opt/solr/server/solr/dovecot-fts], dataDir=[/opt/solr/server/solr/dovecot-fts/data/] 2024-04-09 13:09:21.371 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog 2024-04-09 13:09:21.371 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 2024-04-09 13:09:21.399 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms; 2024-04-09 13:09:21.399 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.CommitTracker Soft AutoCommit: disabled 2024-04-09 13:09:21.423 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrCore [dovecot-fts] CLOSING SolrCore org.apache.solr.core.SolrCore@32b1c7a0 2024-04-09 13:09:21.424 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.dovecot-fts, tag=32b1c7a0 2024-04-09 13:09:21.425 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@3f987204: rootName = null, domain = solr.core.dovecot-fts, service url = null, agent id = null] for registry solr.core.dovecot-fts / com.codahale.metrics.MetricRegistry@63b572d6 2024-04-09 13:09:21.445 ERROR (coreContainerWorkExecutor-2-thread-1) [ ] o.a.s.c.CoreContainer Error waiting for SolrCore to be loaded on startup org.apache.solr.common.SolrException: Unable to create core [dovecot-fts] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1208) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:699) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) ~[metrics-core-3.2.6.jar:3.2.6] at java.util.concurrent.FutureTask.run(Unknown Source) [?:?] at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [solr-solrj-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:34] at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?] at java.lang.Thread.run(Unknown Source) [?:?] Caused by: org.apache.solr.common.SolrException: Error opening new searcher at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1048) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more Caused by: org.apache.solr.common.SolrException: Error opening new searcher at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2137) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:2257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.initSearcher(SolrCore.java:1106) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:993) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more Caused by: org.apache.lucene.index.IndexNotFoundException: no segments* file found in LockValidatingDirectoryWrapper(NRTCachingDirectory(MMapDirectory@/opt/solr/server/solr/dovecot-fts/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@21af4f; maxCacheMB=48.0 maxMergeSizeMB=4.0)): files: [_11ul.cfe, _11ul.cfs, _11ul.si, _11ul_4.liv, _152q.dii, _152q.dim, _152q.fdt, _152q.fdx, _152q.fnm, _152q.nvd, _152q.nvm, _152q.si, _152q_Lucene50_0.doc, _152q_Lucene50_0.pos, _152q_Lucene50_0.tim, _152q_Lucene50_0.tip, _152q_k.liv, _16hv.cfe, _16hv.cfs, _16hv.si, _17h5.cfe, _17h5.cfs, _17h5.si, _17h5_1.liv, _1ch4.cfe, _1ch4.cfs, _1ch4.si, _1ch4_v.liv, _1hi9.cfe, _1hi9.cfs, _1hi9.si, _1hi9_10.liv, _1kgw.cfe, _1kgw.cfs, _1kgw.si, _1kgw_10.liv, _1qp7.cfe, _1qp7.cfs, _1qp7.si, _1qp7_b.liv, _1se4.cfe, _1se4.cfs, _1se4.si, _1se4_c.liv, _1tyj.cfe, _1tyj.cfs, _1tyj.si, _1tyj_9.liv, _1uea.cfe, _1uea.cfs, _1uea.si, _1uea_5.liv, _1vdc.dii, _1vdc.dim, _1vdc.fdt, _1vdc.fdx, _1vdc.fnm, _1vdc.nvd, _1vdc.nvm, _1vdc.si, _1vdc_Lucene50_0.doc, _1vdc_Lucene50_0.pos, _1vdc_Lucene50_0.tim, _1vdc_Lucene50_0.tip, _1vdd.dii, _1vdd.dim, _1vdd.fdt, _1vdd.fdx, _1vdd.fnm, _1vdd.nvd, _1vdd.nvm, _1vdd.si, _1vdd_Lucene50_0.doc, _1vdd_Lucene50_0.pos, _1vdd_Lucene50_0.tim, _1vdd_Lucene50_0.tip, _1vde.dii, _1vde.dim, _1vde.fdt, _1vde.fdx, _1vde.fnm, _1vde.nvd, _1vde.nvm, _1vde.si, _1vde_Lucene50_0.doc, _1vde_Lucene50_0.pos, _1vde_Lucene50_0.tim, _1vde_Lucene50_0.tip, _1vdk.cfe, _1vdk.cfs, _1vdk.si, _1vdn.dii, _1vdn.dim, _1vdn.fdt, _1vdn.fdx, _1vdn.fnm, _1vdn.nvd, _1vdn.nvm, _1vdn.si, _1vdn_Lucene50_0.doc, _1vdn_Lucene50_0.pos, _1vdn_Lucene50_0.tim, _1vdn_Lucene50_0.tip, _1vdo.dii, _1vdo.dim, _1vdo.fdt, _1vdo.fdx, _1vdo.fnm, _1vdo.nvd, _1vdo.nvm, _1vdo.si, _1vdo_Lucene50_0.doc, _1vdo_Lucene50_0.pos, _1vdo_Lucene50_0.tim, _1vdo_Lucene50_0.tip, _1vdt.dii, _1vdt.dim, _1vdt.fdt, _1vdt.fdx, _1vdt.fnm, _1vdt.nvd, _1vdt.nvm, _1vdt.si, _1vdt_Lucene50_0.doc, _1vdt_Lucene50_0.pos, _1vdt_Lucene50_0.tim, _1vdt_Lucene50_0.tip, _1vdx.cfe, _1vdx.cfs, _1vdx.si, _1vdy.dii, _1vdy.dim, _1vdy.fdt, _1vdy.fdx, _1vdy.fnm, _1vdy.nvd, _1vdy.nvm, _1vdy.si, _1vdy_Lucene50_0.doc, _1vdy_Lucene50_0.pos, _1vdy_Lucene50_0.tim, _1vdy_Lucene50_0.tip, _1vdz.dii, _1vdz.dim, _1vdz.fdt, _1vdz.fdx, _1vdz.fnm, _1vdz.nvd, _1vdz.nvm, _1vdz.si, _1vdz_Lucene50_0.doc, _1vdz_Lucene50_0.pos, _1vdz_Lucene50_0.tim, _1vdz_Lucene50_0.tip, _1ve0.dii, _1ve0.dim, _1ve0.fdt, _1ve0.fdx, _1ve0.fnm, _1ve0.nvd, _1ve0.nvm, _1ve0.si, _1ve0_Lucene50_0.doc, _1ve0_Lucene50_0.pos, _1ve0_Lucene50_0.tim, _1ve0_Lucene50_0.tip, _1ve1.dii, _1ve1.dim, _1ve1.fdt, _1ve1.fdx, _1ve1.fnm, _1ve1.nvd, _1ve1.nvm, _1ve1.si, _1ve1_Lucene50_0.doc, _1ve1_Lucene50_0.pos, _1ve1_Lucene50_0.tim, _1ve1_Lucene50_0.tip, _1ve2.dii, _1ve2.dim, _1ve2.fdt, _1ve2.fdx, _1ve2.fnm, _1ve2.nvd, _1ve2.nvm, _1ve2.si, _1ve2_Lucene50_0.doc, _1ve2_Lucene50_0.pos, _1ve2_Lucene50_0.tim, _1ve2_Lucene50_0.tip, _1ve3.dii, _1ve3.dim, _1ve3.fdt, _1ve3.fdx, _1ve3.fnm, _1ve3.nvd, _1ve3.nvm, _1ve3.si, _1ve3_Lucene50_0.doc, _1ve3_Lucene50_0.pos, _1ve3_Lucene50_0.tim, _1ve3_Lucene50_0.tip, _gfn.dii, _gfn.dim, _gfn.fdt, _gfn.fdx, _gfn.fnm, _gfn.nvd, _gfn.nvm, _gfn.si, _gfn_Lucene50_0.doc, _gfn_Lucene50_0.pos, _gfn_Lucene50_0.tim, _gfn_Lucene50_0.tip, _gfn_h.liv, _j1a.dii, _j1a.dim, _j1a.fdt, _j1a.fdx, _j1a.fnm, _j1a.nvd, _j1a.nvm, _j1a.si, _j1a_Lucene50_0.doc, _j1a_Lucene50_0.pos, _j1a_Lucene50_0.tim, _j1a_Lucene50_0.tip, write.lock] at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:840) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.<init>(SolrIndexWriter.java:124) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:97) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.DefaultSolrCoreState.createMainIndexWriter(DefaultSolrCoreState.java:257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:131) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2098) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:2257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.initSearcher(SolrCore.java:1106) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:993) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more 2024-04-09 13:09:27.098 ERROR (Finalizer) [ ] o.a.s.u.SolrIndexWriter SolrIndexWriter was not closed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! 2024-04-09 13:09:27.100 ERROR (Finalizer) [ ] o.a.s.u.SolrIndexWriter Error closing IndexWriter java.lang.NullPointerException: null at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3626) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3586) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.shutdown(IndexWriter.java:1036) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1079) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:286) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.finalize(SolrIndexWriter.java:342) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at java.lang.System$2.invokeFinalize(Unknown Source) [?:?] at java.lang.ref.Finalizer.runFinalizer(Unknown Source) [?:?] at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source) [?:?] Suppressed: java.lang.NullPointerException at org.apache.lucene.index.IndexWriter.rollbackInternalNoCommit(IndexWriter.java:2310) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.rollbackInternal(IndexWriter.java:2288) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.shutdown(IndexWriter.java:1043) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1079) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:286) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.finalize(SolrIndexWriter.java:342) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at java.lang.System$2.invokeFinalize(Unknown Source) [?:?] at java.lang.ref.Finalizer.runFinalizer(Unknown Source) [?:?] at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source) [?:?] 2024-04-09 13:10:22.700 INFO (qtp1819940427-20) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=2 2024-04-09 13:10:22.731 INFO (qtp1819940427-14) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=18 2024-04-09 13:17:08.127 INFO (qtp1819940427-23) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=0 2024-04-09 13:17:08.135 INFO (qtp1819940427-21) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=5 2024-04-09 13:36:51.508 INFO (qtp1819940427-14) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=0 2024-04-09 13:36:51.517 INFO (qtp1819940427-19) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=6 2024-04-10 13:01:53.226 INFO (qtp1819940427-14) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=1 2024-04-10 13:01:53.242 INFO (qtp1819940427-19) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=9 2024-04-10 13:04:03.607 INFO (Thread-0) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@12d1f1d4{HTTP/1.1,[http/1.1]}{0.0.0.0:8983} 2024-04-10 13:04:03.607 INFO (Thread-0) [ ] o.e.j.s.session node0 Stopped scavenging 2024-04-10 13:04:03.627 INFO (Thread-0) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1037942373 2024-04-10 13:04:03.681 INFO (Thread-0) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null 2024-04-10 13:04:03.687 INFO (Thread-0) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@39e43310: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@3fb26dd5 2024-04-10 13:04:03.739 INFO (Thread-0) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null 2024-04-10 13:04:03.747 INFO (Thread-0) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@58516c91: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@6ce75d06 2024-04-10 13:04:03.750 INFO (Thread-0) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null 2024-04-10 13:04:03.751 INFO (Thread-0) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7c129ef6: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@57d1fbdc 2024-04-10 13:04:03.788 INFO (Thread-0) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.w.WebAppContext@53142455{/solr,null,UNAVAILABLE}{/opt/solr/server/solr-webapp/webapp} Starting Solr OpenJDK 64-Bit Server VM warning: Option UseConcMarkSweepGC was deprecated in version 9.0 and will likely be removed in a future release. 2024-04-10 14:08:07.608 INFO (main) [ ] o.e.j.u.log Logging initialized @1000ms to org.eclipse.jetty.util.log.Slf4jLog 2024-04-10 14:08:07.740 WARN (main) [ ] o.e.j.s.AbstractConnector Ignoring deprecated socket close linger time 2024-04-10 14:08:07.754 INFO (main) [ ] o.e.j.s.Server jetty-9.4.14.v20181114; built: 2018-11-14T21:20:31.478Z; git: c4550056e785fb5665914545889f21dc136ad9e6; jvm 11.0.15+10 2024-04-10 14:08:07.775 INFO (main) [ ] o.e.j.d.p.ScanningAppProvider Deployment monitor [file:///opt/solr/server/contexts/] at interval 0 2024-04-10 14:08:08.055 INFO (main) [ ] o.e.j.w.StandardDescriptorProcessor NO JSP Support for /solr, did not find org.apache.jasper.servlet.JspServlet 2024-04-10 14:08:08.063 INFO (main) [ ] o.e.j.s.session DefaultSessionIdManager workerName=node0 2024-04-10 14:08:08.063 INFO (main) [ ] o.e.j.s.session No SessionScavenger set, using defaults 2024-04-10 14:08:08.065 INFO (main) [ ] o.e.j.s.session node0 Scavenging every 660000ms 2024-04-10 14:08:08.185 INFO (main) [ ] o.a.s.s.SolrDispatchFilter Using logger factory org.apache.logging.slf4j.Log4jLoggerFactory 2024-04-10 14:08:08.190 INFO (main) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr™ version 7.7.3 2024-04-10 14:08:08.191 INFO (main) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port 8983 2024-04-10 14:08:08.194 INFO (main) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: /opt/solr 2024-04-10 14:08:08.194 INFO (main) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2024-04-10T14:08:08.194767Z 2024-04-10 14:08:08.231 INFO (main) [ ] o.a.s.c.SolrResourceLoader Using system property solr.solr.home: /opt/solr/server/solr 2024-04-10 14:08:08.237 INFO (main) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /opt/solr/server/solr/solr.xml 2024-04-10 14:08:08.293 INFO (main) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a, but no JMX reporters were configured - adding default JMX reporter. 2024-04-10 14:08:08.559 INFO (main) [ ] o.a.s.c.SolrResourceLoader [null] Added 0 libs to classloader, from paths: [] 2024-04-10 14:08:08.741 INFO (main) [ ] o.a.s.h.c.HttpShardHandlerFactory Host whitelist initialized: WhitelistHostChecker [whitelistHosts=null, whitelistHostCheckingEnabled=true] 2024-04-10 14:08:09.109 INFO (main) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 transient cores 2024-04-10 14:08:09.111 INFO (main) [ ] o.a.s.h.a.MetricsHistoryHandler No .system collection, keeping metrics history in memory. 2024-04-10 14:08:09.165 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-10 14:08:09.165 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-10 14:08:09.171 INFO (main) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-10 14:08:09.197 INFO (main) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /opt/solr/server/solr 2024-04-10 14:08:09.198 INFO (main) [ ] o.a.s.c.CorePropertiesLocator Cores are: [dovecot-fts] 2024-04-10 14:08:09.245 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrResourceLoader [dovecot-fts] Added 58 libs to classloader, from paths: [/opt/solr/contrib/clustering/lib, /opt/solr/contrib/extraction/lib, /opt/solr/contrib/langid/lib, /opt/solr/contrib/velocity/lib, /opt/solr/dist] 2024-04-10 14:08:09.251 INFO (main) [ ] o.e.j.s.h.ContextHandler Started o.e.j.w.WebAppContext@53142455{/solr,file:///opt/solr/server/solr-webapp/webapp/,AVAILABLE}{/opt/solr/server/solr-webapp/webapp} 2024-04-10 14:08:09.261 INFO (main) [ ] o.e.j.s.AbstractConnector Started ServerConnector@2a46d112{HTTP/1.1,[http/1.1]}{0.0.0.0:8983} 2024-04-10 14:08:09.261 INFO (main) [ ] o.e.j.s.Server Started @2659ms 2024-04-10 14:08:09.319 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.7.0 2024-04-10 14:08:09.390 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.s.IndexSchema [dovecot-fts] Schema name=dovecot-fts 2024-04-10 14:08:09.477 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.s.IndexSchema Loaded schema dovecot-fts/2.0 with uniqueid field id 2024-04-10 14:08:09.481 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.CoreContainer Creating SolrCore 'dovecot-fts' using configuration from instancedir /opt/solr/server/solr/dovecot-fts, trusted=true 2024-04-10 14:08:09.546 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.dovecot-fts' (registry 'solr.core.dovecot-fts') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@1af2d44a 2024-04-10 14:08:09.570 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrCore [[dovecot-fts] ] Opening new SolrCore at [/opt/solr/server/solr/dovecot-fts], dataDir=[/opt/solr/server/solr/dovecot-fts/data/] 2024-04-10 14:08:09.905 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog 2024-04-10 14:08:09.905 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536 2024-04-10 14:08:09.928 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 15000ms; 2024-04-10 14:08:09.928 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.u.CommitTracker Soft AutoCommit: disabled 2024-04-10 14:08:09.963 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.c.SolrCore [dovecot-fts] CLOSING SolrCore org.apache.solr.core.SolrCore@34a338f2 2024-04-10 14:08:09.963 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.dovecot-fts, tag=34a338f2 2024-04-10 14:08:09.966 INFO (coreLoadExecutor-9-thread-1) [ x:dovecot-fts] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6d48e12: rootName = null, domain = solr.core.dovecot-fts, service url = null, agent id = null] for registry solr.core.dovecot-fts / com.codahale.metrics.MetricRegistry@6f7afa0d 2024-04-10 14:08:09.986 ERROR (coreContainerWorkExecutor-2-thread-1) [ ] o.a.s.c.CoreContainer Error waiting for SolrCore to be loaded on startup org.apache.solr.common.SolrException: Unable to create core [dovecot-fts] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1208) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.lambda$load$13(CoreContainer.java:699) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) ~[metrics-core-3.2.6.jar:3.2.6] at java.util.concurrent.FutureTask.run(Unknown Source) [?:?] at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:209) [solr-solrj-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:34] at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source) [?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source) [?:?] at java.lang.Thread.run(Unknown Source) [?:?] Caused by: org.apache.solr.common.SolrException: Error opening new searcher at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1048) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more Caused by: org.apache.solr.common.SolrException: Error opening new searcher at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2137) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:2257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.initSearcher(SolrCore.java:1106) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:993) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more Caused by: org.apache.lucene.index.IndexNotFoundException: no segments* file found in LockValidatingDirectoryWrapper(NRTCachingDirectory(MMapDirectory@/opt/solr/server/solr/dovecot-fts/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ffa7df6; maxCacheMB=48.0 maxMergeSizeMB=4.0)): files: [_11ul.cfe, _11ul.cfs, _11ul.si, _11ul_4.liv, _152q.dii, _152q.dim, _152q.fdt, _152q.fdx, _152q.fnm, _152q.nvd, _152q.nvm, _152q.si, _152q_Lucene50_0.doc, _152q_Lucene50_0.pos, _152q_Lucene50_0.tim, _152q_Lucene50_0.tip, _152q_k.liv, _16hv.cfe, _16hv.cfs, _16hv.si, _17h5.cfe, _17h5.cfs, _17h5.si, _17h5_1.liv, _1ch4.cfe, _1ch4.cfs, _1ch4.si, _1ch4_v.liv, _1hi9.cfe, _1hi9.cfs, _1hi9.si, _1hi9_10.liv, _1kgw.cfe, _1kgw.cfs, _1kgw.si, _1kgw_10.liv, _1qp7.cfe, _1qp7.cfs, _1qp7.si, _1qp7_b.liv, _1se4.cfe, _1se4.cfs, _1se4.si, _1se4_c.liv, _1tyj.cfe, _1tyj.cfs, _1tyj.si, _1tyj_9.liv, _1uea.cfe, _1uea.cfs, _1uea.si, _1uea_5.liv, _1vdc.dii, _1vdc.dim, _1vdc.fdt, _1vdc.fdx, _1vdc.fnm, _1vdc.nvd, _1vdc.nvm, _1vdc.si, _1vdc_Lucene50_0.doc, _1vdc_Lucene50_0.pos, _1vdc_Lucene50_0.tim, _1vdc_Lucene50_0.tip, _1vdd.dii, _1vdd.dim, _1vdd.fdt, _1vdd.fdx, _1vdd.fnm, _1vdd.nvd, _1vdd.nvm, _1vdd.si, _1vdd_Lucene50_0.doc, _1vdd_Lucene50_0.pos, _1vdd_Lucene50_0.tim, _1vdd_Lucene50_0.tip, _1vde.dii, _1vde.dim, _1vde.fdt, _1vde.fdx, _1vde.fnm, _1vde.nvd, _1vde.nvm, _1vde.si, _1vde_Lucene50_0.doc, _1vde_Lucene50_0.pos, _1vde_Lucene50_0.tim, _1vde_Lucene50_0.tip, _1vdk.cfe, _1vdk.cfs, _1vdk.si, _1vdn.dii, _1vdn.dim, _1vdn.fdt, _1vdn.fdx, _1vdn.fnm, _1vdn.nvd, _1vdn.nvm, _1vdn.si, _1vdn_Lucene50_0.doc, _1vdn_Lucene50_0.pos, _1vdn_Lucene50_0.tim, _1vdn_Lucene50_0.tip, _1vdo.dii, _1vdo.dim, _1vdo.fdt, _1vdo.fdx, _1vdo.fnm, _1vdo.nvd, _1vdo.nvm, _1vdo.si, _1vdo_Lucene50_0.doc, _1vdo_Lucene50_0.pos, _1vdo_Lucene50_0.tim, _1vdo_Lucene50_0.tip, _1vdt.dii, _1vdt.dim, _1vdt.fdt, _1vdt.fdx, _1vdt.fnm, _1vdt.nvd, _1vdt.nvm, _1vdt.si, _1vdt_Lucene50_0.doc, _1vdt_Lucene50_0.pos, _1vdt_Lucene50_0.tim, _1vdt_Lucene50_0.tip, _1vdx.cfe, _1vdx.cfs, _1vdx.si, _1vdy.dii, _1vdy.dim, _1vdy.fdt, _1vdy.fdx, _1vdy.fnm, _1vdy.nvd, _1vdy.nvm, _1vdy.si, _1vdy_Lucene50_0.doc, _1vdy_Lucene50_0.pos, _1vdy_Lucene50_0.tim, _1vdy_Lucene50_0.tip, _1vdz.dii, _1vdz.dim, _1vdz.fdt, _1vdz.fdx, _1vdz.fnm, _1vdz.nvd, _1vdz.nvm, _1vdz.si, _1vdz_Lucene50_0.doc, _1vdz_Lucene50_0.pos, _1vdz_Lucene50_0.tim, _1vdz_Lucene50_0.tip, _1ve0.dii, _1ve0.dim, _1ve0.fdt, _1ve0.fdx, _1ve0.fnm, _1ve0.nvd, _1ve0.nvm, _1ve0.si, _1ve0_Lucene50_0.doc, _1ve0_Lucene50_0.pos, _1ve0_Lucene50_0.tim, _1ve0_Lucene50_0.tip, _1ve1.dii, _1ve1.dim, _1ve1.fdt, _1ve1.fdx, _1ve1.fnm, _1ve1.nvd, _1ve1.nvm, _1ve1.si, _1ve1_Lucene50_0.doc, _1ve1_Lucene50_0.pos, _1ve1_Lucene50_0.tim, _1ve1_Lucene50_0.tip, _1ve2.dii, _1ve2.dim, _1ve2.fdt, _1ve2.fdx, _1ve2.fnm, _1ve2.nvd, _1ve2.nvm, _1ve2.si, _1ve2_Lucene50_0.doc, _1ve2_Lucene50_0.pos, _1ve2_Lucene50_0.tim, _1ve2_Lucene50_0.tip, _1ve3.dii, _1ve3.dim, _1ve3.fdt, _1ve3.fdx, _1ve3.fnm, _1ve3.nvd, _1ve3.nvm, _1ve3.si, _1ve3_Lucene50_0.doc, _1ve3_Lucene50_0.pos, _1ve3_Lucene50_0.tim, _1ve3_Lucene50_0.tip, _gfn.dii, _gfn.dim, _gfn.fdt, _gfn.fdx, _gfn.fnm, _gfn.nvd, _gfn.nvm, _gfn.si, _gfn_Lucene50_0.doc, _gfn_Lucene50_0.pos, _gfn_Lucene50_0.tim, _gfn_Lucene50_0.tip, _gfn_h.liv, _j1a.dii, _j1a.dim, _j1a.fdt, _j1a.fdx, _j1a.fnm, _j1a.nvd, _j1a.nvm, _j1a.si, _j1a_Lucene50_0.doc, _j1a_Lucene50_0.pos, _j1a_Lucene50_0.tim, _j1a_Lucene50_0.tip, write.lock] at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:840) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.<init>(SolrIndexWriter.java:124) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:97) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.DefaultSolrCoreState.createMainIndexWriter(DefaultSolrCoreState.java:257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:131) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:2098) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:2257) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.initSearcher(SolrCore.java:1106) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:993) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.SolrCore.<init>(SolrCore.java:874) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1187) ~[solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] ... 7 more 2024-04-10 14:08:15.742 ERROR (Finalizer) [ ] o.a.s.u.SolrIndexWriter SolrIndexWriter was not closed prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! 2024-04-10 14:08:15.751 ERROR (Finalizer) [ ] o.a.s.u.SolrIndexWriter Error closing IndexWriter java.lang.NullPointerException: null at org.apache.lucene.index.IndexWriter.doFlush(IndexWriter.java:3626) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.flush(IndexWriter.java:3586) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.shutdown(IndexWriter.java:1036) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1079) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:286) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.finalize(SolrIndexWriter.java:342) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at java.lang.System$2.invokeFinalize(Unknown Source) [?:?] at java.lang.ref.Finalizer.runFinalizer(Unknown Source) [?:?] at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source) [?:?] Suppressed: java.lang.NullPointerException at org.apache.lucene.index.IndexWriter.rollbackInternalNoCommit(IndexWriter.java:2310) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.rollbackInternal(IndexWriter.java:2288) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.shutdown(IndexWriter.java:1043) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.lucene.index.IndexWriter.close(IndexWriter.java:1079) ~[lucene-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:31:55] at org.apache.solr.update.SolrIndexWriter.close(SolrIndexWriter.java:286) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at org.apache.solr.update.SolrIndexWriter.finalize(SolrIndexWriter.java:342) [solr-core-7.7.3.jar:7.7.3 1a0d2a901dfec93676b0fe8be425101ceb754b85 - noble - 2020-04-21 10:37:32] at java.lang.System$2.invokeFinalize(Unknown Source) [?:?] at java.lang.ref.Finalizer.runFinalizer(Unknown Source) [?:?] at java.lang.ref.Finalizer$FinalizerThread.run(Unknown Source) [?:?] 2024-04-10 14:09:25.970 INFO (qtp1819940427-15) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=2 2024-04-10 14:09:26.001 INFO (qtp1819940427-14) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=16 2024-04-10 14:31:20.087 INFO (qtp1819940427-15) [ x:dovecot-fts] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={core=dovecot-fts&action=STATUS&indexInfo=true} status=0 QTime=1 2024-04-10 14:31:20.096 INFO (qtp1819940427-19) [ ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/info/system params={} status=0 QTime=5

It seems like the same event flow twice, from a quick reading. I rebooted yesterday and today.

The mail client is iOS Mail on an iPhone I believe.

There are plenty of errors in the Solr log but nothing that I can understand as a reason for it failing. But I don’t know Solr at all. I can’t find anything about RAM levels. Maybe I will try to re-index Solr as the docs page explains:

https://docs.mailcow.email/manual-guides/Dovecot/u_e-dovecot-fts/#fts-solr

The real question though, is; Is this issue with Solr not running enough of a problem to potentially be the cause of the outages issue?

Thanks very much for your help.

DocFraggle

OSSVirt I don’t think so, Solr is used for the full text search, i.e. if you search for content inside emails etc

esackbauer

Seems like some of your index files are broken:

OSSVirt Caused by: org.apache.lucene.index.IndexNotFoundException: no segments* file found in LockValidatingDirectoryWrapper

So what the internet says is you stop solr, delete the contents of /var/lib/docker/volumes/mailcowdockerized_solr-vol-1/_data directory (or however your docker volume for solr is named), and start solr again, it should then properly rebuild the index.
Have backup done before you do this 😉

OSSVirt

Great! This seemed to work. I tested this on a cold-standby clone server that I made first, so backups were already covered. I didn’t do this on the Production server yet.

In case anyone else needs to do this - I did the following:

#Change to Mailcow directory
cd /opt/mailcow-dockerized/

#Stop Solr Container safely
docker compose stop solr-mailcow

#Check Solr Container stopped
docker info

#Change to Solr data volume directory
cd /var/lib/docker/volumes/mailcowdockerized_solr-vol-1/_data/

#Remove empty directory with rmdir and non-empty directories with rm -r

rmdir snapshot_metadata
rm -r index
rm -r tlog

#Change back to Mailcow directory again
cd /opt/mailcow-dockerized/

#Restart Solr Container
docker compose restart solr-mailcow

After a short time the /debug dashboard showed:

solr-mailcow (mailcow/solr:1.8.2)
(Started on 10/04/2024, 20:21:24)
Running . . .

The deleted contents of the /_data/index subdirectory was over 2.7GB.

Thanks for all your help @DocFraggle and @esackbauer, much appreciated!

DocFraggle

Great, and was this really related to your user not being able to sync his mail? Is it now working again?

OSSVirt

Well this is the question! 😃

I tested the above fix on a Cold-Standby clone and it seemed to work perfectly. So I will now make the fix on Production and then see what happens.

It may be tricky to know for sure as it was an intermittent issue that appeared only twice so far. If it no longer happens I will declare it fixed, but will maybe never know for sure. Also I guess Solr will disappear from Mailcow in the near future, so that whole issue may go away. If the same thing happens again but without the Solr error in the logs then I’ll know it wasn’t Solr and I’ll keep hunting for the cause.

I’ll definitely come back and add an update onto this thread after I have fixed Production, in case it helps anyone.

It doesn’t look like issue threads get closed on here, so I should be able to add to this discussion next week no problem I guess. 👍️

OSSVirt

Hi again, here’s the update.

I ran the Best Answer fix above on my production server on Saturday 13th April 2024 and everything behaved as expected. Solr runs fine again and there have not been any connection outage issues reported since. It’s too soon to be certain that this fix is the solution to the errors the user was experiencing, but I feel like it probably is the answer.

Now that I’m aware of this situation I am monitoring Solr and watching its memory usage, cache size and document count gradually creep up each day. That would be what I would expect an indexer to do. I guess when it reaches a critical capacity it can’t cope with the scale of the index any further and crashes. Is that right?

Do we know what the critical point is? Is it the JVM memory usage or the index size?

Thanks again for all the help with this before 😃

Jef

Same issue and same solution.
Thx!