arcadedb icon indicating copy to clipboard operation
arcadedb copied to clipboard

Published 20 hours ago • verified publisher icon ArcadeData

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

Open shasaur opened this issue 1 year ago • 1 comments

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([email protected]/Native Method)
	at java.lang.ref.Reference.processPendingReferences([email protected]/Reference.java:241)
	at java.lang.ref.Reference$ReferenceHandler.run([email protected]/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([email protected]/Native Method)
	- waiting on <0x000000070a035ea0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000070a035ea0> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/ReferenceQueue.java:176)
	at java.lang.ref.Finalizer$FinalizerThread.run([email protected]/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([email protected]/Native Method)
	- waiting on <0x000000070a0367c8> (a java.lang.ref.ReferenceQueue$Lock)
	at java.lang.ref.ReferenceQueue.remove([email protected]/ReferenceQueue.java:155)
	- waiting to re-lock in wait() <0x000000070a0367c8> (a java.lang.ref.ReferenceQueue$Lock)
	at jdk.internal.ref.CleanerImpl.run([email protected]/CleanerImpl.java:148)
	at java.lang.Thread.run([email protected]/Thread.java:829)
	at jdk.internal.misc.InnocuousThread.run([email protected]/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([email protected]/Native Method)
	at java.net.PlainSocketImpl.socketAccept([email protected]/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept([email protected]/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept([email protected]/ServerSocket.java:576)
	at java.net.ServerSocket.accept([email protected]/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop([email protected]/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run([email protected]/TCPTransport.java:366)
	at java.lang.Thread.run([email protected]/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([email protected]/Native Method)
	at java.net.PlainSocketImpl.socketAccept([email protected]/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept([email protected]/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept([email protected]/ServerSocket.java:576)
	at java.net.ServerSocket.accept([email protected]/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop([email protected]/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run([email protected]/TCPTransport.java:366)
	at java.lang.Thread.run([email protected]/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([email protected]/Native Method)
	at java.net.PlainSocketImpl.socketAccept([email protected]/PlainSocketImpl.java:159)
	at java.net.AbstractPlainSocketImpl.accept([email protected]/AbstractPlainSocketImpl.java:474)
	at java.net.ServerSocket.implAccept([email protected]/ServerSocket.java:576)
	at java.net.ServerSocket.accept([email protected]/ServerSocket.java:539)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop([email protected]/TCPTransport.java:394)
	at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run([email protected]/TCPTransport.java:366)
	at java.lang.Thread.run([email protected]/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([email protected]/Native Method)
	- waiting on <0x000000070a036f70> (a java.util.TaskQueue)
	at java.lang.Object.wait([email protected]/Object.java:328)
	at java.util.TimerThread.mainLoop([email protected]/Timer.java:527)
	- waiting to re-lock in wait() <0x000000070a036f70> (a java.util.TaskQueue)
	at java.util.TimerThread.run([email protected]/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([email protected]/Native Method)
	- waiting on <0x00000007179b5f18> (a java.util.TaskQueue)
	at java.lang.Object.wait([email protected]/Object.java:328)
	at java.util.TimerThread.mainLoop([email protected]/Timer.java:527)
	- waiting to re-lock in wait() <0x00000007179b5f18> (a java.util.TaskQueue)
	at java.util.TimerThread.run([email protected]/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

shasaur avatar Sep 21 '23 23:09 shasaur

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.

shasaur avatar Sep 22 '23 00:09 shasaur