Skip to content

Failed to launch - "Error on creating new database instance" #1249

New issue
New issue
Closed
Bug
Closed
Failed to launch - "Error on creating new database instance"#1249
Bug
Assignees
lvca
Milestone
26.7.1

Description

@shasaur
shasaur
opened on Sep 21, 2023

ArcadeDB Version:

arcadedb-23.1.2 <- note: it's an old version, but I checked the function that errors between the current version and the old version and I'm pretty sure it hasn't been changed

Expected behavior

Launch DBMS and it loads.

Actual behavior

Launched DMBS and it failed to load. Cannot open the web interface.

Steps to reproduce

Some pre-amble: the database could be in a state where there was a large / expensive operation performed and it shut down in the middle of it (aka, something corrupted). I'm not sure.

server.bat output:

 █████╗ ██████╗  ██████╗ █████╗ ██████╗ ███████╗██████╗ ██████╗
'██║██║' is not recognized as an internal or external command,
operable program or batch file.
'╚══════╝╚═════╝' is not recognized as an internal or external command,
operable program or batch file.
PLAY WITH DATA                             https://arcadedb.com

ARCADEDB server script path = C:\Users\X\arcadedb-23.1.2\bin\server.bat
ARCADEDB home directory     = C:\Users\X\arcadedb-23.1.2

2023-09-22 00:09:01.371 INFO  [ArcadeDBServer] <ArcadeDB_0> ArcadeDB Server v23.2.1 (build e8f512fa466c4a32ef9d14d89af20e7ac2859c7e/1677638572021/main) is starting up...
2023-09-22 00:09:01.372 INFO  [ArcadeDBServer] <ArcadeDB_0> Starting ArcadeDB Server with plugins [Postgres] ...
2023-09-22 00:09:01.385 INFO  [ArcadeDBServer] <ArcadeDB_0> - JMX Metrics Started...Exception in thread "main" com.arcadedb.exception.DatabaseOperationException: Error on creating new database instance
        at com.arcadedb.database.EmbeddedDatabase.openInternal(EmbeddedDatabase.java:1651)
        at com.arcadedb.database.EmbeddedDatabase.open(EmbeddedDatabase.java:182)
        at com.arcadedb.database.DatabaseFactory.open(DatabaseFactory.java:76)
        at com.arcadedb.server.ArcadeDBServer.getDatabase(ArcadeDBServer.java:381)
        at com.arcadedb.server.ArcadeDBServer.getDatabase(ArcadeDBServer.java:265)
        at com.arcadedb.server.ArcadeDBServer.loadDatabases(ArcadeDBServer.java:403)
        at com.arcadedb.server.ArcadeDBServer.start(ArcadeDBServer.java:127)
        at com.arcadedb.server.ArcadeDBServer.main(ArcadeDBServer.java:92)
Caused by: java.lang.NullPointerException
        at com.arcadedb.schema.EmbeddedSchema.load(EmbeddedSchema.java:150)
        at com.arcadedb.database.EmbeddedDatabase.openInternal(EmbeddedDatabase.java:1623)
        ... 7 more

jstack:

2023-09-22 00:14:25
Full thread dump OpenJDK 64-Bit Server VM (11.0.14.1+1-LTS mixed mode):

Threads class SMR info:
_java_thread_list=0x000001a469fb8860, length=15, elements={
0x000001a467665000, 0x000001a467666000, 0x000001a467f69800, 0x000001a467f6a000,
0x000001a467f6b000, 0x000001a467f70000, 0x000001a467f75800, 0x000001a467f7f800,
0x000001a46808f800, 0x000001a46870c800, 0x000001a46872f800, 0x000001a4688d5800,
0x000001a4687ed000, 0x000001a469730800, 0x000001a443953000
}

"Reference Handler" #2 daemon prio=10 os_prio=2 cpu=0.00ms elapsed=325.50s tid=0x000001a467665000 nid=0x5954 waiting on condition  [0x0000004317eff000]
   java.lang.Thread.State: RUNNABLE
	at java.lang.ref.Reference.waitForReferencePendingList(java.base@11.0.14.1/Native Method)
	at java.lang.ref.Reference.processPendingReferences(java.base@11.0.14.1/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run(java.base@11.0.14.1/Reference.java:213)

"Finalizer" #3 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=325.50s tid=0x000001a467666000 nid=0x45ac in Object.wait()  [0x0000004317fff000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.14.1/Native Method)
	- waiting on <0x000000070a035ea0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.14.1/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000070a035ea0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.14.1/ReferenceQueue.java:176)
	at java.lang.ref.Finalizer$FinalizerThread.run(java.base@11.0.14.1/Finalizer.java:170)

"Signal Dispatcher" #4 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=325.49s tid=0x000001a467f69800 nid=0x5d5c runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Attach Listener" #5 daemon prio=5 os_prio=2 cpu=0.00ms elapsed=325.49s tid=0x000001a467f6a000 nid=0x1718 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Service Thread" #6 daemon prio=9 os_prio=0 cpu=0.00ms elapsed=325.49s tid=0x000001a467f6b000 nid=0x2924 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"C2 CompilerThread0" #7 daemon prio=9 os_prio=2 cpu=156.25ms elapsed=325.49s tid=0x000001a467f70000 nid=0x4de4 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"C1 CompilerThread0" #10 daemon prio=9 os_prio=2 cpu=109.38ms elapsed=325.49s tid=0x000001a467f75800 nid=0x2b3c waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE
   No compile task

"Sweeper thread" #11 daemon prio=9 os_prio=2 cpu=0.00ms elapsed=325.49s tid=0x000001a467f7f800 nid=0x52f4 runnable  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Common-Cleaner" #12 daemon prio=8 os_prio=1 cpu=0.00ms elapsed=325.45s tid=0x000001a46808f800 nid=0x5af8 in Object.wait()  [0x00000043186fe000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.14.1/Native Method)
	- waiting on <0x000000070a0367c8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove(java.base@11.0.14.1/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000070a0367c8> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run(java.base@11.0.14.1/CleanerImpl.java:148)
	at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)
	at jdk.internal.misc.InnocuousThread.run(java.base@11.0.14.1/InnocuousThread.java:161)

"RMI TCP Accept-9998" #14 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=324.99s tid=0x000001a46870c800 nid=0x88c runnable  [0x00000043188fe000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.accept0(java.base@11.0.14.1/Native Method)
	at java.net.PlainSocketImpl.socketAccept(java.base@11.0.14.1/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept(java.base@11.0.14.1/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept(java.base@11.0.14.1/ServerSocket.java:576)
	at java.net.ServerSocket.accept(java.base@11.0.14.1/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(java.rmi@11.0.14.1/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(java.rmi@11.0.14.1/TCPTransport.java:366)
	at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)

"RMI TCP Accept-9999" #15 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=324.98s tid=0x000001a46872f800 nid=0x2028 runnable  [0x00000043189fe000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.accept0(java.base@11.0.14.1/Native Method)
	at java.net.PlainSocketImpl.socketAccept(java.base@11.0.14.1/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept(java.base@11.0.14.1/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept(java.base@11.0.14.1/ServerSocket.java:576)
	at java.net.ServerSocket.accept(java.base@11.0.14.1/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(java.rmi@11.0.14.1/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(java.rmi@11.0.14.1/TCPTransport.java:366)
	at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)

"RMI TCP Accept-0" #16 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=324.96s tid=0x000001a4688d5800 nid=0x508 runnable  [0x0000004318afe000]
   java.lang.Thread.State: RUNNABLE
	at java.net.PlainSocketImpl.accept0(java.base@11.0.14.1/Native Method)
	at java.net.PlainSocketImpl.socketAccept(java.base@11.0.14.1/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept(java.base@11.0.14.1/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept(java.base@11.0.14.1/ServerSocket.java:576)
	at java.net.ServerSocket.accept(java.base@11.0.14.1/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(java.rmi@11.0.14.1/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(java.rmi@11.0.14.1/TCPTransport.java:366)
	at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)

"Timer-0" #17 daemon prio=5 os_prio=0 cpu=0.00ms elapsed=324.94s tid=0x000001a4687ed000 nid=0x3d60 in Object.wait()  [0x0000004318cff000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.14.1/Native Method)
	- waiting on <0x000000070a036f70> (a java.util.TaskQueue)
	at java.lang.Object.wait(java.base@11.0.14.1/Object.java:328)
	at java.util.TimerThread.mainLoop(java.base@11.0.14.1/Timer.java:527)
	- waiting to re-lock in wait() <0x000000070a036f70> (a java.util.TaskQueue)
	at java.util.TimerThread.run(java.base@11.0.14.1/Timer.java:506)

"ArcadeDB TransactionManager Pantsing_my_shit" #20 prio=5 os_prio=0 cpu=0.00ms elapsed=323.90s tid=0x000001a469730800 nid=0x5e14 in Object.wait()  [0x00000043194fe000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(java.base@11.0.14.1/Native Method)
	- waiting on <0x00000007179b5f18> (a java.util.TaskQueue)
	at java.lang.Object.wait(java.base@11.0.14.1/Object.java:328)
	at java.util.TimerThread.mainLoop(java.base@11.0.14.1/Timer.java:527)
	- waiting to re-lock in wait() <0x00000007179b5f18> (a java.util.TaskQueue)
	at java.util.TimerThread.run(java.base@11.0.14.1/Timer.java:506)

"DestroyJavaVM" #22 prio=5 os_prio=0 cpu=546.88ms elapsed=323.59s tid=0x000001a443953000 nid=0x2c78 waiting on condition  [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"VM Thread" os_prio=2 cpu=15.63ms elapsed=325.51s tid=0x000001a467661800 nid=0x3818 runnable  

"GC Thread#0" os_prio=2 cpu=0.00ms elapsed=325.53s tid=0x000001a44396e800 nid=0x30b4 runnable  

"GC Thread#1" os_prio=2 cpu=0.00ms elapsed=324.52s tid=0x000001a469d51000 nid=0x5cf0 runnable  

"GC Thread#2" os_prio=2 cpu=0.00ms elapsed=324.52s tid=0x000001a4693b7000 nid=0x4ae4 runnable  

"GC Thread#3" os_prio=2 cpu=15.63ms elapsed=324.52s tid=0x000001a4694f0000 nid=0x5054 runnable  

"GC Thread#4" os_prio=2 cpu=0.00ms elapsed=324.52s tid=0x000001a4687cc000 nid=0x3b88 runnable  

"G1 Main Marker" os_prio=2 cpu=0.00ms elapsed=325.53s tid=0x000001a4439c8800 nid=0x24c0 runnable  

"G1 Conc#0" os_prio=2 cpu=0.00ms elapsed=325.53s tid=0x000001a4439cb000 nid=0x3268 runnable  

"G1 Conc#1" os_prio=2 cpu=0.00ms elapsed=324.36s tid=0x000001a468a1a000 nid=0x59bc runnable  

"G1 Conc#2" os_prio=2 cpu=0.00ms elapsed=324.36s tid=0x000001a4687d3000 nid=0x28e4 runnable  

"G1 Refine#0" os_prio=2 cpu=0.00ms elapsed=325.52s tid=0x000001a467536000 nid=0x5c4 runnable  

"G1 Refine#1" os_prio=2 cpu=0.00ms elapsed=324.52s tid=0x000001a46842a000 nid=0x53a0 runnable  

"G1 Young RemSet Sampling" os_prio=2 cpu=15.63ms elapsed=325.52s tid=0x000001a467537000 nid=0x5adc runnable  
"VM Periodic Task Thread" os_prio=2 cpu=0.00ms elapsed=324.96s tid=0x000001a4688d4000 nid=0x5e5c waiting on condition  

JNI global refs: 18, weak refs: 0

Activity

  1. shasaur commented on Sep 22, 2023

    @shasaur
    shasaur
    on Sep 22, 2023
    ContributorAuthor

    I noticed that it's possible to set a more detailed log level, so I set it to FINER. Didn't give anymore useful information near the error, just some start-up info.

  2. mergify
    added a commit that references this issue on Dec 1, 2025

    chore(deps): bump org.apache.maven.plugins:maven-assembly-plugin from…

    aadbdfa
  3. lvca
    self-assigned this
    on Jun 16, 2026
  4. lvca
    added the
    Bug
    issue type on Jun 16, 2026
  5. lvca
    added this to the 26.7.1 milestone on Jun 16, 2026

  6. lvca commented on Jun 16, 2026

    @lvca
    lvca
    on Jun 16, 2026
    Member

    Revisited this on the current main.

    The original crash is already gone. EmbeddedSchema is now LocalSchema, and the whole schema-load body in LocalSchema.readConfiguration() is wrapped in a try/catch that logs and continues instead of aborting startup, so a bad schema no longer prevents the server from booting.

    But there was a real residual gap, now fixed. Your scenario was a crash in the middle of a schema save. On every save the engine rotates the old schema.json to schema.prev.json and then writes the new one, so a crash mid-write leaves a corrupt (truncated, non-empty) schema.json next to a perfectly valid schema.prev.json. The recovery logic only fell back to that backup when schema.json was missing or zero-length; a corrupt-but-non-empty file instead hit the catch-all and silently reset the schema to empty - making every type/index disappear (records still on disk but unreachable) even though a good backup sat right beside it.

    Fix: when parsing schema.json throws, readConfiguration() now falls back to schema.prev.json (if present and non-empty) and flags a rewrite so the corruption self-heals on the next save. If there's no usable backup it re-throws and the existing reset path is preserved.

    Added a regression test (CorruptSchemaRecoveryTest) that creates types + an index, truncates schema.json mid-JSON to simulate the crash, reopens, and verifies the schema is recovered from the backup and rewritten as valid JSON.

    Caveat: schema.prev.json is always one save behind, so only the single most recent schema change being written at the moment of the crash can be lost; everything prior is recovered.

  7. lvca
    added a commit that references this issue on Jun 16, 2026

    fix: [#1249] recover schema from schema.prev.json backup when schema.…

    0de86e4

  8. lvca commented on Jun 16, 2026

    @lvca
    lvca
    on Jun 16, 2026
    Member

    Fixed

  9. lvca
    closed this as completedon Jun 16, 2026
  10. tae898
    added a commit that references this issue on Jun 28, 2026

    chore(deps): bump org.apache.maven.plugins:maven-assembly-plugin from…

    d6fbaf2
  11. robfrank
    added a commit that references this issue on Aug 14, 2026

    fix: [#1249] recover schema from schema.prev.json backup when schema.…

    e1615a4
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

Bug

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions