jkrauss82 commented on PR #1895:
URL: https://github.com/apache/solr/pull/1895#issuecomment-2609768003
Thanks for merging this.
I am trying to upgrade our Solr cloud node from Solr `9.5.0` to `9.8.0`,
which has this PR merged. However, something does not seem to work as expected
as Solr is not able to initialize the core, neither with tlogs copied to the
new location, nor with an empty location.
The error encountered is given in the log dump below.
I had previously configured the ulog location like this:
```xml
<updateLog>
<str name="dir">${solr.ulog.dir:/solr/logs/author_search}</str>
<int name="numVersionBuckets">${solr.ulog.numVersionBuckets:65536}</int>
</updateLog>
```
When Solr is starting, it seems to recognize the configuration but aborts
with a message about missing file permissions. The location
`/solr/logs/author_search` exists, belongs to user `solr:solr` and has
permissions `0750` (I have even tried with 0777).
**Question: what is the target folder structure Solr creates under
`/solr/logs/author_search` and what could cause the error I am encountering?**
My suspicion is I am doing something wrong in regards to the folder
structure.
I would like to carry over the old tlogs from 9.5.0 to have a seemless
transition but I am stuck with this problem for now.
**I can provide more logs or help debugging upon request.**
### Solr version etc. from log
```txt
head -n 20 /var/log/solr/solr.log.1
2025-01-23 12:31:29.519 INFO (main) [c: s: r: x: t:] o.e.j.s.Server
jetty-10.0.22; built: 2024-06-27T16:03:51.502Z; git:
5c8471e852d377fd726ad9b1692c35ffc5febb09; jvm 21.0.4+8-LTS-274
2025-01-23 12:31:29.748 WARN (main) [c: s: r: x: t:]
o.e.j.u.DeprecationWarning Using @Deprecated Class
org.eclipse.jetty.servlet.listener.ELContextCleaner
2025-01-23 12:31:29.770 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider Using logger factory
org.apache.logging.slf4j.Log4jLoggerFactory
2025-01-23 12:31:29.775 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider ___ _ Welcome to Apache Solr™ version
9.8.0
2025-01-23 12:31:29.775 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider / __| ___| |_ _ Starting in cloud mode on port
8983
2025-01-23 12:31:29.775 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider \__ \/ _ \ | '_| Install dir: /opt/solr-9.8.0
2025-01-23 12:31:29.776 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider |___/\___/_|_| Start time:
2025-01-23T11:31:29.776093489Z
2025-01-23 12:31:29.778 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider Solr started with "-XX:+CrashOnOutOfMemoryError"
that will crash on any OutOfMemoryError exception. The cause of the OOME will
be logged in the crash file at the following path:
/var/log/solr/jvm_crash_3999500.log
2025-01-23 12:31:29.865 INFO (main) [c: s: r: x: t:]
o.a.l.s.MemorySegmentIndexInputProvider Using MemorySegmentIndexInput and
native madvise support with Java 21 or later; to disable start with
-Dorg.apache.lucene.store.MMapDirectory.enableMemorySegments=false
2025-01-23 12:31:29.890 INFO (main) [c: s: r: x: t:]
o.a.l.i.v.PanamaVectorizationProvider Java vector incubator API enabled; uses
preferredBitSize=256; FMA enabled
2025-01-23 12:31:29.892 INFO (main) [c: s: r: x: t:]
o.a.s.s.CoreContainerProvider Solr Home: /solr/data (source: system property:
solr.solr.home)
2025-01-23 12:31:29.911 WARN (main) [c: s: r: x: t:] o.a.s.c.c.SolrZkClient
Using default ZkCredentialsInjector. ZkCredentialsInjector is not secure, it
creates an empty list of credentials which leads to 'OPEN_ACL_UNSAFE' ACLs to
Zookeeper nodes
2025-01-23 12:31:30.043 INFO (main) [c: s: r: x: t:]
o.a.s.c.c.ConnectionManager Waiting up to 30000ms for client to connect to
ZooKeeper
2025-01-23 12:31:30.183 INFO (zkCallback-1-thread-1) [c: s: r: x: t:]
o.a.s.c.c.ConnectionManager zkClient has connected
2025-01-23 12:31:30.183 INFO (main) [c: s: r: x: t:]
o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
2025-01-23 12:31:30.183 WARN (main) [c: s: r: x: t:] o.a.s.c.c.SolrZkClient
Using default ZkACLProvider. DefaultZkACLProvider is not secure, it creates
'OPEN_ACL_UNSAFE' ACLs to Zookeeper nodes
2025-01-23 12:31:30.362 INFO (main) [c: s: r: x: t:] o.a.s.c.NodeConfig
Loading solr.xml from SolrHome (not found in ZooKeeper)
2025-01-23 12:31:30.362 INFO (main) [c: s: r: x: t:] o.a.s.c.SolrXmlConfig
solr.xml not found in SOLR_HOME, using built-in default
2025-01-23 12:31:30.362 INFO (main) [c: s: r: x: t:] o.a.s.c.SolrXmlConfig
Loading solr.xml from /opt/solr-9.8.0/server/solr/solr.xml
2025-01-23 12:31:30.389 INFO (main) [c: s: r: x: t:]
o.a.s.c.SolrResourceLoader Added 1 libs to classloader, from paths:
[/opt/solr-9.8.0/lib]
```
### Core loading logs:
```txt
$ grep author_search /var/log/solr/solr.log.1
2025-01-23 12:31:32.108 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:] o.a.s.c.SolrConfig
Using Lucene MatchVersion: 9.9.0
2025-01-23 12:31:32.113 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.s.IndexSchemaSchema name=default-config
2025-01-23 12:31:32.120 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.s.IndexSchemaLoaded schema default-config/1.6 with uniqueid field id
2025-01-23 12:31:32.120 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.c.CoreContainer Creating SolrCore 'author_search_shard1_replica_n2' using
configuration from configset author_search, trusted=false
2025-01-23 12:31:32.156 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:] o.a.s.c.SolrCore
Opening new SolrCore at [/solr/data/author_search_shard1_replica_n2],
dataDir=[/solr/data/author_search_shard1_replica_n2/data/]
2025-01-23 12:31:32.669 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.j.SolrRequestAuthorizer Creating a new SolrRequestAuthorizer
2025-01-23 12:31:32.694 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.u.UpdateHandler Using UpdateLog implementation:
org.apache.solr.update.UpdateLog
2025-01-23 12:31:32.694 WARN
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:] o.a.s.u.UpdateLog
numVersionBuckets is obsolete
2025-01-23 12:31:32.698 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:] o.a.s.u.UpdateLog
Initializing UpdateLog: dataDir=/solr/logs/author_search defaultSyncLevel=FLUSH
numRecordsToKeep=100 maxNumLogsToKeep=10
2025-01-23 12:31:32.699 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.u.CommitTracker Hard AutoCommit: if uncommitted for 300000ms; if tlog
file size has exceeded 134217728 bytes
2025-01-23 12:31:32.700 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.u.CommitTracker Soft AutoCommit: if uncommitted for 60000ms;
2025-01-23 12:31:32.701 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:] o.a.s.c.SolrCore
CLOSING SolrCore org.apache.solr.core.SolrCore@4e4e0e7e
author_search_shard1_replica_n2
2025-01-23 12:31:32.702 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.core.author_search.shard1.replica_n2 tag=SolrCore@4e4e0e7e
2025-01-23 12:31:32.726 INFO
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c:author_search
s:shard1 r:core_node4 x:author_search_shard1_replica_n2 t:]
o.a.s.m.SolrMetricManager Closing metric reporters for
registry=solr.collection.author_search.shard1.leader tag=SolrCore@4e4e0e7e
2025-01-23 12:31:32.731 ERROR
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c: s: r: x: t:]
o.a.s.c.CoreContainer SolrCore failed to load on startup =>
org.apache.solr.common.SolrException: Unable to create core
[author_search_shard1_replica_n2]
org.apache.solr.common.SolrException: Unable to create core
[author_search_shard1_replica_n2]
Caused by: java.security.AccessControlException: access denied
("java.io.FilePermission"
"/solr/logs/author_search/author_search_shard1_replica_n2" "read")
```
### Java stacktrace
```txt
2025-01-23 12:31:32.731 ERROR
(coreLoadExecutor-20-thread-1-processing-solr-fsn-2:8983_solr) [c: s: r: x: t:]
o.a.s.c.CoreContainer SolrCore failed to load on startup =>
org.apache.solr.common.SolrException: Unable to create core
[author_search_shard1_replica_n2]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1778)
org.apache.solr.common.SolrException: Unable to create core
[author_search_shard1_replica_n2]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1778)
~[?:?]
at
org.apache.solr.core.CoreContainer.lambda$loadInternal$12(CoreContainer.java:1080)
~[?:?]
at
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:212)
~[metrics-core-4.2.26.jar:4.2.26]
at
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:380)
~[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
~[?:?]
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
~[?:?]
at java.base/java.lang.Thread.run(Thread.java:1583) [?:?]
Caused by: org.apache.solr.common.SolrException: Error Instantiating Update
Handler, solr.DirectUpdateHandler2 failed to instantiate
org.apache.solr.update.UpdateHandler
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1229) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1058) ~[?:?]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1745)
~[?:?]
... 6 more
Caused by: org.apache.solr.common.SolrException: Error Instantiating Update
Handler, solr.DirectUpdateHandler2 failed to instantiate
org.apache.solr.update.UpdateHandler
at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:969) ~[?:?]
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:1045)
~[?:?]
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1289) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1175) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1058) ~[?:?]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1745)
~[?:?]
... 6 more
Caused by: java.lang.reflect.InvocationTargetException
at
java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:74)
~[?:?]
at
java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
~[?:?]
at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
~[?:?]
at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:948) ~[?:?]
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:1045)
~[?:?]
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1289) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1175) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1058) ~[?:?]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1745)
~[?:?]
... 6 more
Caused by: java.security.AccessControlException: access denied
("java.io.FilePermission"
"/solr/logs/author_search/author_search_shard1_replica_n2" "read")
at
java.base/java.security.AccessControlContext.checkPermission(AccessControlContext.java:488)
~[?:?]
at
java.base/java.security.AccessController.checkPermission(AccessController.java:1071)
~[?:?]
at
java.base/java.lang.SecurityManager.checkPermission(SecurityManager.java:411)
~[?:?]
at java.base/java.lang.SecurityManager.checkRead(SecurityManager.java:742)
~[?:?]
at java.base/sun.nio.fs.UnixPath.checkRead(UnixPath.java:789) ~[?:?]
at
java.base/sun.nio.fs.UnixFileSystemProvider.readAttributesIfExists(UnixFileSystemProvider.java:182)
~[?:?]
at java.base/java.nio.file.Files.isDirectory(Files.java:2319) ~[?:?]
at org.apache.lucene.store.FSDirectory.<init>(FSDirectory.java:127) ~[?:?]
at org.apache.lucene.store.MMapDirectory.<init>(MMapDirectory.java:244)
~[?:?]
at org.apache.lucene.store.MMapDirectory.<init>(MMapDirectory.java:173)
~[?:?]
at org.apache.lucene.store.FSDirectory.open(FSDirectory.java:162) ~[?:?]
at
org.apache.solr.core.NRTCachingDirectoryFactory.create(NRTCachingDirectoryFactory.java:53)
~[?:?]
at
org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:410)
~[?:?]
at org.apache.solr.update.UpdateLog.initTlogDir(UpdateLog.java:570) ~[?:?]
at org.apache.solr.update.UpdateLog.init(UpdateLog.java:469) ~[?:?]
at org.apache.solr.update.UpdateHandler.initUlog(UpdateHandler.java:193)
~[?:?]
at
org.apache.solr.update.DirectUpdateHandler2.<init>(DirectUpdateHandler2.java:160)
~[?:?]
at
java.base/jdk.internal.reflect.DirectConstructorHandleAccessor.newInstance(DirectConstructorHandleAccessor.java:62)
~[?:?]
at
java.base/java.lang.reflect.Constructor.newInstanceWithCaller(Constructor.java:502)
~[?:?]
at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:486)
~[?:?]
at org.apache.solr.core.SolrCore.createInstance(SolrCore.java:948) ~[?:?]
at org.apache.solr.core.SolrCore.createUpdateHandler(SolrCore.java:1045)
~[?:?]
at org.apache.solr.core.SolrCore.initUpdateHandler(SolrCore.java:1289) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1175) ~[?:?]
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:1058) ~[?:?]
at
org.apache.solr.core.CoreContainer.createFromDescriptor(CoreContainer.java:1745)
~[?:?]
... 6 more
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]