orientechnologies / orientdb

OrientDB is the most versatile DBMS supporting Graph, Document, Reactive, Full-Text and Geospatial models in one Multi-Model product. OrientDB can run distributed (Multi-Master), supports SQL, ACID Transactions, Full-Text indexing and Reactive Queries.
https://orientdb.dev
Apache License 2.0
4.73k stars 869 forks source link

Getting ODistributedRecordLockedException creating edge in distributed mode #5012

Closed stefomak closed 7 years ago

stefomak commented 8 years ago

Hi, I have orientdb 2.1-SNAPSHOT running with the -cluster option, but I have only one node running (to make it simpler). When my java application tries to commit a transaction that involves creations of vertices and edges I get:

Error on transaction commit com.orientechnologies.orient.server.distributed.task.ODistributedRecordLockedException at com.orientechnologies.orient.server.distributed.task.OTxTask.execute(OTxTask.java:102) at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.executeOnLocalNode(OHazelcastPlugin.java:805) at com.orientechnologies.orient.server.hazelcast.ODistributedWorker.onMessage(ODistributedWorker.java:296) at com.orientechnologies.orient.server.hazelcast.ODistributedWorker.run(ODistributedWorker.java:119)

In the last three days I tried a lot of combination in order to isolate the problem. I found out that if the transaction creates only vertices (no edges!!) it doesn't fire any exception.

Do you know any workaround, please? I'm getting crazy...............

stefomak commented 8 years ago

....Thank you!

lvca commented 8 years ago

ODistributedRecordLockedException is raised when a concurrent operation is executed on that record. is this your case? What level of concurrency do you have?

In case of TX, it' automatically repeated up to 10 times (by default, setting "distributed.concurrentTxMaxAutoRetry"), so to receive that message seems you have high contention on the same vertices. Can you confirm?

stefomak commented 8 years ago

Hi Luca, my java application tries to commit a transaction that involves creations of vertices and edges: vertex A and other stuff. I found out that I do something else in a hook. In the afterCreate method I create a new vertex B and an edge between A e B. Then I discovered that I need to set DISTRIBUTED_EXECUTION_MODE. I tried the three options, but only TARGET_NODE works without exceptions. But doing so, and in distributed mode, I get a new vertex B in the first node of the cluster with a rid different from the rid of the new vertex B in the second node of the cluster. This solutions doesn't work fine because in this scenario it's impossible to delete the vertex. I got another exception about quorum... I guess the right DISTRIBUTED_EXECUTION_MODE should be BOTH, but it doesn't work.

Thanks Stefano

stefomak commented 8 years ago

Hi, any idea?

jack18jack commented 8 years ago

@stefomak @lvca i got this error too.i try to use spark-orientdb-connector to access distributed orientdb 2.1.12 with two nodes.i raise a question in their github page.do u guys have any findings? https://github.com/metreta/spark-orientdb-connector/issues/4

nishantkumar1292 commented 7 years ago

I got this error too. And as @lvca pointed out that this error is raised when a concurrent operation is executed on that record. I have Vertex A connected to Vertex B1 and Vertex B2 with the same edge class. My objective is to delete edge between both and I am doing this in loop. First this is executed. DELETE EDGE FROM #13:438 TO #12:65377 Works fine. Then when executing this DELETE EDGE FROM #13:438 TO #12:65375 gives error: com.orientechnologies.orient.server.distributed.task.ODistributedRecordLockedException: Timeout (3756ms) on acquiring lock on record #13:438 on server 'node2'. It is locked by request 0.10791....

Any idea how to solve this?

lvca commented 7 years ago

@nishantkumar1292 what release?

nishantkumar1292 commented 7 years ago

I am running two server nodes in distributed mode in OrientDB 2.2.17 .

lvca commented 7 years ago

Please use v2.2.21.

nishantkumar1292 commented 7 years ago

Started using v2.2.21 but now I am not able to start the server nodes. Every node starts as master and the members list does not show the other server. The distributed mode was running fine in 2.2.17. I have the same hazelcast.xml file. Am I missing something? Error: 2017-06-13 08:21:49:839 INFO OrientDB Server is active v2.2.21 (build 491997a502b8b90210b269824755c56981765034). [OServer] 2017-06-13 08:23:51:712 INFO [172.87.45.743]:2434 [orientdb] [3.6.5] Could not connect to:/172.31.75.96:2435. Reason: SocketException[Connection timed out to address /172.31.75.96:2435] [InitConnectionTask] 2017-06-13 08:23:51:712 INFO [172.87.45.743]:2434 [orientdb] [3.6.5] Could not connect to: /[ip]:2434. Reason: SocketException[Connection timed out to address /[172.31.75.96]:2434] [InitConnectionTask] ...and this continues. The same is happening for the other server as well.

lvca commented 7 years ago

Please check the network configuration in config/hazelcast.xml and config/orientdb-server-config.xml

nishantkumar1292 commented 7 years ago

The servers and connections are working fine. However I am still getting the ODistributedRecordLockedException error.

Error: com.orientechnologies.orient.server.distributed.task.ODistributedRecordLockedException: Timeout (5000ms) on acquiring lock on record #12:84870 on server 'node1'. It is locked by request 0.90132. DB name="db_development" DB name="db_development"

I am running REPAIR DATABASE --fix-graph -skipEdges=5673222 command in console.

Any idea why is it happening?

lvca commented 7 years ago

@nishantkumar1292 Was that exception given during REPAIR DATABASE?

nishantkumar1292 commented 7 years ago

yes

roots-ai commented 7 years ago

+1 @nishantkumar1292 @Ivca! We plan to use orientdb, in production, where there would be ~10,000 requests/sec. ~ 1M Nodes ~ 6M Edges We couldn't find any way to resolve ODistributedRecordLockedException error while even working with only 2 parallel requests on a node, unsure how this is going to scale up.

Is this a bug with Orientdb 2.2.21, or any other way to get this resolved?

lvca commented 7 years ago

Hi guys, OrientDB has an optimistic approach avoiding locks as much as possible. Only in this way you can scale up massively. In the case there is a concurrent write operation on the same vertices, the infamous ODistributedRecordLockedException is thrown. It's not a bug, this exception extends ONeedRetryException that means it has to be managed on the client side.

All the client code should be like:

for( int retry = 0; retry < 10; ++retry ){
 try {
  // EXECUTE YOUR COMMAND
  break;

 } catch( ONeedRetryException e ){
   // CONTINUE
 }
}

In this way any concurrent operation will be retried (in this case up to 10 times).

nishantkumar1292 commented 7 years ago

We are getting this error when executing delete command over an edge class DELETE EDGE edge_class_name through OrientDB studio. Error: com.orientechnologies.orient.server.distributed.task.ODistributedRecordLockedException: Timeout (592ms) on acquiring lock on record #13:3 on server 'node1'. It is locked by request 0.26 DB name=db_development Even 10 minutes minutes after this error, we are not able to execute update command on #13:3. Firstly, how do we solve this? Secondly, is there a way to figure out which request is locking the node as the error mentions request 0.26. How do we know what is request 0.26?

roots-ai commented 7 years ago

@lvca Can you please reply?

lvca commented 7 years ago

@roots-ai can you execute a kill -5 <pid> to get from the system output the internal status of the server?

nishantkumar1292 commented 7 years ago

The command kill -5 <pid> gave below output.

2017-07-10 12:47:07:741 WARNI Received signal: SIGTRAP [OSignalHandler]
OrientDB 2.2.21 (build 491997a502b8b90210b269824755c56981765034) configuration dump:
- ENVIRONMENT
  + environment.dumpCfgAtStartup = false
  + environment.concurrent = true
  + environment.lockManager.concurrency.level = 64
  + environment.allowJVMShutdown = true
- SCRIPT
  + script.pool.maxSize = 20
- MEMORY
  + memory.useUnsafe = true
  + memory.chunk.size = 2147483647
  + memory.directMemory.safeMode = true
  + memory.directMemory.trackMode = false
  + memory.directMemory.onlyAlignedMemoryAccess = true
- JVM
  + jvm.gc.delayForOptimize = 600
- STORAGE
  + storage.openFiles.limit = 512
  + storage.componentsLock.cache = 10000
  + storage.diskCache.pinnedPages = 20
  + storage.diskCache.bufferSize = 26200
  + storage.diskCache.writeCachePart = 15
  + storage.diskCache.writeCachePageTTL = 86400
  + storage.diskCache.writeCachePageFlushInterval = 25
  + storage.diskCache.writeCacheFlushInactivityInterval = 60000
  + storage.diskCache.writeCacheFlushLockTimeout = -1
  + storage.diskCache.diskFreeSpaceCheckInterval = 5
  + storage.diskCache.diskFreeSpaceCheckIntervalInPages = 2048
  + storage.diskCache.keepState = true
  + storage.diskCache.checksumMode = Store
  + storage.configuration.syncOnUpdate = true
  + storage.compressionMethod = nothing
  + storage.encryptionMethod = nothing
  + storage.encryptionKey = <hidden>
  + storage.makeFullCheckpointAfterCreate = false
  + storage.makeFullCheckpointAfterOpen = true
  + storage.makeFullCheckpointAfterClusterCreate = true
  + storage.trackChangedRecordsInWAL = true
  + storage.useWAL = true
  + storage.wal.syncOnPageFlush = true
  + storage.wal.cacheSize = 3000
  + storage.wal.fileAutoCloseInterval = 10
  + storage.wal.maxSegmentSize = 128
  + storage.wal.maxSize = 4096
  + storage.wal.commitTimeout = 1000
  + storage.wal.shutdownTimeout = 10000
  + storage.wal.fuzzyCheckpointInterval = 300
  + storage.wal.reportAfterOperationsDuringRestore = 10000
  + storage.wal.restore.batchSize = 50000
  + storage.wal.readCacheSize = 1000
  + storage.wal.fuzzyCheckpointShutdownWait = 600
  + storage.wal.fullCheckpointShutdownTimeout = 600
  + storage.wal.path = null
  + storage.diskCache.pageSize = 64
  + storage.diskCache.diskFreeSpaceLimit = 256
  + storage.lowestFreeListBound = 16
  + storage.lockTimeout = 0
  + storage.record.lockTimeout = 2000
  + storage.useTombstones = false
- RECORD
  + record.downsizing.enabled = true
- OBJECT
  + object.saveOnlyDirty = false
- DB
  + db.pool.min = 1
  + db.pool.max = 50
  + db.pool.idleTimeout = 0
  + db.pool.idleCheckDelay = 0
  + db.mvcc.throwfast = false
  + db.validation = true
- NONTX
  + nonTX.recordUpdate.synch = false
  + nonTX.clusters.sync.immediately = manindex
- TX
  + tx.trackAtomicOperations = false
  + tx.pageCacheSize = 12
- INDEX
  + index.embeddedToSbtreeBonsaiThreshold = 40
  + index.sbtreeBonsaiToEmbeddedThreshold = -1
- HASHTABLE
  + hashTable.slitBucketsBuffer.length = 1500
- INDEX
  + index.auto.synchronousAutoRebuild = true
  + index.auto.lazyUpdates = 10000
  + index.flushAfterCreate = true
  + index.manual.lazyUpdates = 1
  + index.durableInNonTxMode = true
  + index.ignoreNullValuesDefault = false
  + index.txMode = FULL
  + index.cursor.prefetchSize = 500000
- SBTREE
  + sbtree.maxDepth = 64
  + sbtree.maxKeySize = 10240
  + sbtree.maxEmbeddedValueSize = 40960
- SBTREEBONSAI
  + sbtreebonsai.bucketSize = 2
  + sbtreebonsai.linkBagCache.size = 100000
  + sbtreebonsai.linkBagCache.evictionSize = 1000
  + sbtreebonsai.freeSpaceReuseTrigger = 0.5
- RIDBAG
  + ridBag.embeddedDefaultSize = 4
  + ridBag.embeddedToSbtreeBonsaiThreshold = 2147483647
  + ridBag.sbtreeBonsaiToEmbeddedToThreshold = 2147483647
- COLLECTIONS
  + collections.preferSBTreeSet = false
- FILE
  + file.trackFileClose = false
  + file.lock = true
  + file.deleteDelay = 10
  + file.deleteRetry = 50
- SECURITY
  + security.userPasswordSaltIterations = 65536
  + security.userPasswordSaltCacheSize = 500
  + security.userPasswordDefaultAlgorithm = PBKDF2WithHmacSHA256
- NETWORK
  + network.maxConcurrentSessions = 1000
  + network.socketBufferSize = 0
  + network.lockTimeout = 15000
  + network.socketTimeout = 15000
  + network.requestTimeout = 3600000
  + network.retry = 5
  + network.retryDelay = 500
  + network.binary.loadBalancing.enabled = false
  + network.binary.loadBalancing.timeout = 2000
  + network.binary.maxLength = 16384
  + network.binary.readResponse.maxTimes = 20
  + network.binary.debug = false
  + network.http.installDefaultCommands = true
  + network.http.serverInfo = OrientDB Server v.2.2.21 (build 491997a502b8b90210b269824755c56981765034)
  + network.http.maxLength = 1000000
  + network.http.streaming = false
  + network.http.charset = utf-8
  + network.http.jsonResponseError = true
  + network.http.jsonp = false
  + network.http.sessionExpireTimeout = 300
  + network.http.useToken = false
  + network.token.secretKey = 
  + network.token.encryptionAlgorithm = HmacSHA256
  + network.token.expireTimeout = 60
- PROFILER
  + profiler.enabled = false
  + profiler.config = null
  + profiler.autoDump.interval = 0
  + profiler.maxValues = 200
  + profiler.memoryCheckInterval = 120000
- SEQUENCE
  + sequence.maxRetry = 100
  + sequence.retryDelay = 200
- STORAGEPROFILER
  + storageProfiler.intervalBetweenSnapshots = 100
  + storageProfiler.cleanUpInterval = 5000
- LOG
  + log.console.level = info
  + log.file.level = info
- CLASS
  + class.minimumClusters = 0
- LOG
  + log.console.ansi = auto
- CACHE
  + cache.local.impl = com.orientechnologies.orient.core.cache.ORecordCacheWeakRefs
- COMMAND
  + command.timeout = 0
  + command.cache.enabled = false
  + command.cache.evictStrategy = PER_CLUSTER
  + command.cache.minExecutionTime = 10
  + command.cache.maxResultsetSize = 500
- QUERY
  + query.parallelAuto = false
  + query.parallelMinimumRecords = 300000
  + query.parallelResultQueueSize = 20000
  + query.scanPrefetchPages = 20
  + query.scanBatchSize = 1000
  + query.scanThresholdTip = 50000
  + query.limitThresholdTip = 10000
  + query.live.support = true
- STATEMENT
  + statement.cacheSize = 100
- SQL
  + sql.graphConsistencyMode = tx
- CLIENT
  + client.channel.maxPool = 100
  + client.connectionPool.waitTimeout = 5000
  + client.channel.dbReleaseWaitTimeout = 10000
  + client.ssl.enabled = false
  + client.ssl.keyStore = null
  + client.ssl.keyStorePass = null
  + client.ssl.trustStore = null
  + client.ssl.trustStorePass = null
- SERVER
  + server.openAllDatabasesAtStartup = false
  + server.channel.cleanDelay = 5000
  + server.cache.staticFile = false
  + server.log.dumpClientExceptionLevel = FINE
  + server.log.dumpClientExceptionFullStackTrace = false
- DISTRIBUTED
  + distributed.dumpStatsEvery = 0
  + distributed.crudTaskTimeout = 10000
  + distributed.maxStartupDelay = 10000
  + distributed.commandTaskTimeout = 120000
  + distributed.commandQuickTaskTimeout = 5000
  + distributed.commandLongTaskTimeout = 86400000
  + distributed.deployDbTaskTimeout = 1200000
  + distributed.deployChunkTaskTimeout = 15000
  + distributed.deployDbTaskCompression = 7
  + distributed.asynchQueueSize = 0
  + distributed.asynchResponsesTimeout = 15000
  + distributed.purgeResponsesTimerDelay = 15000
  + distributed.conflictResolverRepairerChain = quorum,content,majority,version
  + distributed.conflictResolverRepairerCheckEvery = 5000
  + distributed.conflictResolverRepairerBatch = 50
  + distributed.txAliveTimeout = 30000
  + distributed.requestChannels = 1
  + distributed.responseChannels = 1
  + distributed.heartbeatTimeout = 10000
  + distributed.checkHealthCanOfflineServer = false
  + distributed.checkHealthEvery = 10000
  + distributed.autoRemoveOfflineServers = 0
  + distributed.publishNodeStatusEvery = 10000
  + distributed.localQueueSize = 10000
  + distributed.dbWorkerThreads = 8
  + distributed.queueMaxSize = 10000
  + distributed.backupDirectory = ../backup/databases
  + distributed.backupTryIncrementalFirst = true
  + distributed.concurrentTxMaxAutoRetry = 10
  + distributed.atomicLockTimeout = 50
  + distributed.concurrentTxAutoRetryDelay = 10
- DB
  + db.document.serializer = ORecordSerializerBinary
- CLIENT
  + client.krb5.config = null
  + client.krb5.ccname = null
  + client.krb5.ktname = null
  + client.credentialinterceptor = null
  + client.ci.keyalgorithm = AES
  + client.ci.ciphertransform = AES/CBC/PKCS5Padding
  + client.ci.keystore.file = null
  + client.ci.keystore.password = null
- SECURITY
  + security.createDefaultUsers = true
- SERVER
  + server.security.file = null
- JNA
  + jna.disable.system.library = true
- DISTRIBUTED
  + distributed.queueTimeout = 500000
- DB
  + db.makeFullCheckpointOnIndexChange = true
  + db.makeFullCheckpointOnSchemaChange = true
- CLIENT
  + client.session.tokenBased = true
- OAUTH2
  + oauth2.secretkey = 
- STORAGE
  + storage.cluster.usecrc32 = false
- LAZYSET
  + lazyset.workOnStream = true
- DB
  + db.mvcc = true
  + db.use.distributedVersion = false
- MVRBTREE
  + mvrbtree.timeout = 0
  + mvrbtree.nodePageSize = 256
  + mvrbtree.loadFactor = 0.7
  + mvrbtree.optimizeThreshold = 100000
  + mvrbtree.entryPoints = 64
  + mvrbtree.optimizeEntryPointsFactor = 1.0
  + mvrbtree.entryKeysInMemory = false
  + mvrbtree.entryValuesInMemory = false
  + mvrbtree.ridBinaryThreshold = -1
  + mvrbtree.ridNodePageSize = 64
  + mvrbtree.ridNodeSaveMemory = false
- TX
  + tx.commit.synch = false
  + tx.autoRetry = 1
  + tx.log.fileType = classic
  + tx.log.synch = false
  + tx.useLog = true
- INDEX
  + index.auto.rebuildAfterNotSoftClose = true
- CLIENT
  + client.channel.minPool = 1
- STORAGE
  + storage.keepOpen = true
- CACHE
  + cache.local.enabled = true

OrientDB Memory profiler: HEAP=3.20GB of 3.94GB - DISKCACHE (2 dbs)=3.44GB of 51.17GB - OS=21.08GB of 31.42GB - FS=15.84GB of 98.30GB

THREAD DUMP
"SIGTRAP handler" id=3722975 
   java.lang.Thread.State: RUNNABLE
        at sun.management.ThreadImpl.getThreadInfo1(Native Method)
        at sun.management.ThreadImpl.getThreadInfo(ThreadImpl.java:178)
        at com.orientechnologies.common.profiler.OAbstractProfiler.threadDump(OAbstractProfiler.java:432)
        at com.orientechnologies.orient.core.OSignalHandler.handle(OSignalHandler.java:76)
        at sun.misc.Signal$1.run(Signal.java:212)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB HTTP Connection /127.0.0.1:2480<-/127.0.0.1:53258" id=3722974 
   java.lang.Thread.State: RUNNABLE
        at java.lang.Object.notifyAll(Native Method)
        at com.orientechnologies.orient.core.sql.query.OConcurrentResultSet.notifyNewItem(OConcurrentResultSet.java:372)
        at com.orientechnologies.orient.core.sql.query.OConcurrentResultSet.add(OConcurrentResultSet.java:258)
        at com.orientechnologies.orient.core.sql.query.OSQLSynchQuery.result(OSQLSynchQuery.java:68)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.addSingleResult(OMatchStatement.java:937)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.addResult(OMatchStatement.java:921)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:573)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:656)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:656)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContextFromCandidates(OMatchStatement.java:546)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.calculateMatch(OMatchStatement.java:532)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.execute(OMatchStatement.java:269)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.execute(OMatchStatement.java:244)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.iterator(OMatchStatement.java:1348)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetDelegate.iterator(OCommandExecutorSQLResultsetDelegate.java:44)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:220)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:526)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:508)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.iterator(OCommandExecutorSQLSelect.java:447)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetDelegate.iterator(OCommandExecutorSQLResultsetDelegate.java:44)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:220)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:526)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:508)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:484)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:74)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3200)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3138)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.command(ODistributedStorage.java:280)
        at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
        at com.orientechnologies.orient.server.network.protocol.http.command.post.OServerCommandPostBatch.execute(OServerCommandPostBatch.java:171)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.service(ONetworkProtocolHttpAbstract.java:169)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:621)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"OrientDB HTTP Connection /127.0.0.1:2480<-/127.0.0.1:53256" id=3722973 
   java.lang.Thread.State: RUNNABLE
        at java.lang.Object.notifyAll(Native Method)
        at com.orientechnologies.orient.core.sql.query.OConcurrentResultSet.notifyNewItem(OConcurrentResultSet.java:372)
        at com.orientechnologies.orient.core.sql.query.OConcurrentResultSet.add(OConcurrentResultSet.java:258)
        at com.orientechnologies.orient.core.sql.query.OSQLSynchQuery.result(OSQLSynchQuery.java:68)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.addSingleResult(OMatchStatement.java:937)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.addResult(OMatchStatement.java:921)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:573)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:656)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContext(OMatchStatement.java:656)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.processContextFromCandidates(OMatchStatement.java:546)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.calculateMatch(OMatchStatement.java:532)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.execute(OMatchStatement.java:269)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.execute(OMatchStatement.java:244)
        at com.orientechnologies.orient.core.sql.parser.OMatchStatement.iterator(OMatchStatement.java:1348)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetDelegate.iterator(OCommandExecutorSQLResultsetDelegate.java:44)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:220)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:526)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:508)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.iterator(OCommandExecutorSQLSelect.java:447)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetDelegate.iterator(OCommandExecutorSQLResultsetDelegate.java:44)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:220)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:526)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:508)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:484)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:74)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3200)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3138)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.command(ODistributedStorage.java:280)
        at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
        at com.orientechnologies.orient.server.network.protocol.http.command.post.OServerCommandPostBatch.execute(OServerCommandPostBatch.java:171)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.service(ONetworkProtocolHttpAbstract.java:169)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:621)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"OrientDB HTTP Connection /127.0.0.1:2480<-/127.0.0.1:52850" id=3722770 
   java.lang.Thread.State: RUNNABLE
        at com.orientechnologies.orient.core.record.impl.ODocument.field(ODocument.java:823)
        at com.orientechnologies.orient.server.distributed.ODistributedConfiguration.getClusterConfiguration(ODistributedConfiguration.java:754)
        at com.orientechnologies.orient.server.distributed.ODistributedConfiguration.getQuorum(ODistributedConfiguration.java:787)
        at com.orientechnologies.orient.server.distributed.ODistributedConfiguration.getReadQuorum(ODistributedConfiguration.java:708)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.readRecord(ODistributedStorage.java:757)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx$SimpleRecordReader.readRecord(ODatabaseDocumentTx.java:3361)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.executeReadRecord(ODatabaseDocumentTx.java:2012)
        at com.orientechnologies.orient.core.tx.OTransactionNoTx.loadRecord(OTransactionNoTx.java:106)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:1729)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.load(ODatabaseDocumentTx.java:102)
        at com.orientechnologies.orient.core.id.ORecordId.getRecord(ORecordId.java:329)
        at com.tinkerpop.blueprints.impls.orient.OrientVertexIterator.getGraphElementRecord(OrientVertexIterator.java:92)
        at com.orientechnologies.orient.core.iterator.OLazyWrapperIterator.hasNext(OLazyWrapperIterator.java:103)
        at com.orientechnologies.common.collection.OMultiCollectionIterator.hasNextInternal(OMultiCollectionIterator.java:97)
        at com.orientechnologies.common.collection.OMultiCollectionIterator.hasNext(OMultiCollectionIterator.java:78)
        at com.orientechnologies.common.collection.OMultiValue.toSet(OMultiValue.java:824)
        at com.orientechnologies.orient.core.sql.functions.coll.OSQLFunctionIntersect.intersectWith(OSQLFunctionIntersect.java:106)
        at com.orientechnologies.orient.core.sql.functions.coll.OSQLFunctionIntersect.execute(OSQLFunctionIntersect.java:87)
        at com.orientechnologies.orient.core.sql.functions.OSQLFunctionRuntime.execute(OSQLFunctionRuntime.java:128)
        at com.orientechnologies.orient.core.sql.ORuntimeResult.applyRecord(ORuntimeResult.java:141)
        at com.orientechnologies.orient.core.sql.ORuntimeResult.getProjectionResult(ORuntimeResult.java:255)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.addResult(OCommandExecutorSQLSelect.java:703)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.handleResult(OCommandExecutorSQLSelect.java:669)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearchRecord(OCommandExecutorSQLSelect.java:626)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.serialIterator(OCommandExecutorSQLSelect.java:1615)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.fetchFromTarget(OCommandExecutorSQLSelect.java:1562)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:521)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.iterator(OCommandExecutorSQLSelect.java:447)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetDelegate.iterator(OCommandExecutorSQLResultsetDelegate.java:44)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLResultsetAbstract.assignTarget(OCommandExecutorSQLResultsetAbstract.java:220)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.assignTarget(OCommandExecutorSQLSelect.java:526)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.executeSearch(OCommandExecutorSQLSelect.java:508)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLSelect.execute(OCommandExecutorSQLSelect.java:484)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:74)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3200)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3138)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.command(ODistributedStorage.java:280)
        at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
        at com.orientechnologies.orient.server.network.protocol.http.command.post.OServerCommandPostBatch.execute(OServerCommandPostBatch.java:171)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.service(ONetworkProtocolHttpAbstract.java:169)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:621)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"OrientDB HTTP Connection /127.0.0.1:2480<-/127.0.0.1:49330" id=3721010 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedTransactionManager.acquireMultipleRecordLocks(ODistributedTransactionManager.java:546)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedTransactionManager.acquireMultipleRecordLocks(ODistributedTransactionManager.java:512)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedTransactionManager.commit(ODistributedTransactionManager.java:108)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.commit(ODistributedStorage.java:1419)
        at com.orientechnologies.orient.core.tx.OTransactionOptimistic.doCommit(OTransactionOptimistic.java:541)
        at com.orientechnologies.orient.core.tx.OTransactionOptimistic.commit(OTransactionOptimistic.java:99)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2886)
        at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.commit(ODatabaseDocumentTx.java:2855)
        at com.tinkerpop.blueprints.impls.orient.OrientTransactionalGraph.commit(OrientTransactionalGraph.java:182)
        at com.orientechnologies.orient.graph.sql.OGraphCommandExecutorSQLFactory.runInConfiguredTxMode(OGraphCommandExecutorSQLFactory.java:265)
        at com.orientechnologies.orient.graph.sql.OCommandExecutorSQLCreateEdge.execute(OCommandExecutorSQLCreateEdge.java:143)
        at com.orientechnologies.orient.core.sql.OCommandExecutorSQLDelegate.execute(OCommandExecutorSQLDelegate.java:74)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.executeCommand(OAbstractPaginatedStorage.java:3200)
        at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.command(OAbstractPaginatedStorage.java:3138)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage.command(ODistributedStorage.java:260)
        at com.orientechnologies.orient.core.command.OCommandRequestTextAbstract.execute(OCommandRequestTextAbstract.java:69)
        at com.orientechnologies.orient.server.network.protocol.http.command.post.OServerCommandPostBatch.execute(OServerCommandPostBatch.java:171)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.service(ONetworkProtocolHttpAbstract.java:169)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:621)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"cached12" id=3712842 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
        at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

"cached1" id=3205580 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
        at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

"OrientDB (/172.31.4.100:2424) <- BinaryClient (/172.31.17.48:51610)" id=3056174 
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at java.io.DataInputStream.readByte(DataInputStream.java:265)
        at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:68)
        at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.execute(ONetworkProtocolBinary.java:189)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"cached9" id=3036212 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:458)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.take(SynchronousQueue.java:924)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
        at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

"OrientDB HTTP Connection /172.31.4.100:2480<-/182.71.117.210:48594" id=2876562 
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at com.orientechnologies.orient.enterprise.channel.text.OChannelText.read(OChannelText.java:61)
        at com.orientechnologies.orient.server.network.protocol.http.ONetworkProtocolHttpAbstract.execute(ONetworkProtocolHttpAbstract.java:565)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"OrientDB Distributed asynch ops node=node1 db=db_development" id=2284840 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedStorage$1.run(ODistributedStorage.java:136)

"OrientDB Write Cache Flush Task (db_development)" id=2284837 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB WAL Flush Task (db_development)" id=2284836 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"WAL Closer Task (db_development)" id=2284835 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB (/172.31.4.100:2424) <- BinaryClient (/172.31.17.48:56562)" id=2284829 
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
        at java.net.SocketInputStream.read(SocketInputStream.java:171)
        at java.net.SocketInputStream.read(SocketInputStream.java:141)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
        at java.io.DataInputStream.readByte(DataInputStream.java:265)
        at com.orientechnologies.orient.enterprise.channel.binary.OChannelBinary.readByte(OChannelBinary.java:68)
        at com.orientechnologies.orient.server.network.protocol.binary.ONetworkProtocolBinary.execute(ONetworkProtocolBinary.java:189)
        at com.orientechnologies.common.thread.OSoftThread.run(OSoftThread.java:77)

"hz._hzInstance_1_root.IO.thread-Acceptor" id=2284812 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:101)
        at com.hazelcast.nio.tcp.SocketAcceptorThread.acceptLoop(SocketAcceptorThread.java:92)
        at com.hazelcast.nio.tcp.SocketAcceptorThread.run(SocketAcceptorThread.java:78)

"hz._hzInstance_1_root.IOBalancerThread" id=2284811 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at com.hazelcast.nio.tcp.nonblocking.iobalancer.IOBalancerThread.run(IOBalancerThread.java:53)

"hz._hzInstance_1_root.IO.thread-out-2" id=2284810 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"hz._hzInstance_1_root.IO.thread-out-1" id=2284809 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"hz._hzInstance_1_root.IO.thread-out-0" id=2284808 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"hz._hzInstance_1_root.IO.thread-in-2" id=2284807 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"hz._hzInstance_1_root.IO.thread-in-1" id=2284806 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"hz._hzInstance_1_root.IO.thread-in-0" id=2284805 
   java.lang.Thread.State: RUNNABLE
        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:93)
        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.selectLoop(NonBlockingIOThread.java:232)
        at com.hazelcast.nio.tcp.nonblocking.NonBlockingIOThread.run(NonBlockingIOThread.java:187)

"OrientDB DistributedWorker node=node1 db=db_development id=7" id=73 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=6" id=72 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=5" id=71 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=4" id=70 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=3" id=69 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=2" id=68 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=1" id=67 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=0" id=66 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=-4" id=65 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=db_development id=-3" id=64 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=7" id=63 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=6" id=62 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=5" id=61 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=4" id=60 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=3" id=59 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=2" id=58 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=1" id=57 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=0" id=56 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=-4" id=55 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"OrientDB DistributedWorker node=node1 db=OSystem id=-3" id=54 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ArrayBlockingQueue.poll(ArrayBlockingQueue.java:418)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.nextMessage(ODistributedWorker.java:252)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.readRequest(ODistributedWorker.java:229)
        at com.orientechnologies.orient.server.distributed.impl.ODistributedWorker.run(ODistributedWorker.java:93)

"hz._hzInstance_1_root.HealthMonitor" id=53 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at com.hazelcast.internal.monitors.HealthMonitor$HealthMonitorThread.run(HealthMonitor.java:135)

"hz._hzInstance_1_root.generic-operation.thread-0" id=30 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at com.hazelcast.spi.impl.operationexecutor.classic.DefaultScheduleQueue.take(DefaultScheduleQueue.java:84)
        at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.doRun(OperationThread.java:112)
        at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.run(OperationThread.java:99)

"hz._hzInstance_1_root.partition-operation.thread-0" id=29 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at com.hazelcast.spi.impl.operationexecutor.classic.DefaultScheduleQueue.take(DefaultScheduleQueue.java:84)
        at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.doRun(OperationThread.java:112)
        at com.hazelcast.spi.impl.operationexecutor.classic.OperationThread.run(OperationThread.java:99)

"hz._hzInstance_1_root.migration" id=34 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at com.hazelcast.partition.impl.InternalPartitionServiceImpl$MigrationThread.doRun(InternalPartitionServiceImpl.java:2137)
        at com.hazelcast.partition.impl.InternalPartitionServiceImpl$MigrationThread.run(InternalPartitionServiceImpl.java:2101)

"hz._hzInstance_1_root.wait-notify" id=33 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.DelayQueue.poll(DelayQueue.java:259)
        at com.hazelcast.spi.impl.waitnotifyservice.impl.WaitNotifyServiceImpl$ExpirationTask.doRun(WaitNotifyServiceImpl.java:311)
        at com.hazelcast.spi.impl.waitnotifyservice.impl.WaitNotifyServiceImpl$ExpirationTask.run(WaitNotifyServiceImpl.java:296)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
        at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)

"hz._hzInstance_1_root.event-1" id=32 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at com.hazelcast.util.executor.StripedExecutor$Worker.run(StripedExecutor.java:170)

"hz._hzInstance_1_root.SlowOperationDetectorThread" id=31 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:386)
        at com.hazelcast.spi.impl.operationexecutor.slowoperationdetector.SlowOperationDetector$DetectorThread.sleepInterval(SlowOperationDetector.java:287)
        at com.hazelcast.spi.impl.operationexecutor.slowoperationdetector.SlowOperationDetector$DetectorThread.run(SlowOperationDetector.java:151)

"hz._hzInstance_1_root.response" id=28 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at com.hazelcast.spi.impl.operationservice.impl.AsyncResponsePacketHandler$ResponseThread.doRun(AsyncResponsePacketHandler.java:110)
        at com.hazelcast.spi.impl.operationservice.impl.AsyncResponsePacketHandler$ResponseThread.run(AsyncResponsePacketHandler.java:99)

"hz._hzInstance_1_root.InvocationMonitorThread" id=27 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Thread.sleep(Native Method)
        at com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor$MonitorThread.sleep(InvocationMonitor.java:145)
        at com.hazelcast.spi.impl.operationservice.impl.InvocationMonitor$MonitorThread.run(InvocationMonitor.java:134)

"scheduled" id=26 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)
        at com.hazelcast.util.executor.HazelcastManagedThread.executeRun(HazelcastManagedThread.java:76)
        at com.hazelcast.util.executor.HazelcastManagedThread.run(HazelcastManagedThread.java:92)
"pool-2-thread-2" id=25 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1088)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"pool-2-thread-1" id=24 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB Write Cache Flush Task (OSystem)" id=21 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB WAL Flush Task (OSystem)" id=20 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"WAL Closer Task (OSystem)" id=19 
   java.lang.Thread.State: TIMED_WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:748)

"OrientDB ONetworkProtocolHttpDb listen at 0.0.0.0:2480-2490" id=17 
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
        at java.net.ServerSocket.implAccept(ServerSocket.java:545)
        at java.net.ServerSocket.accept(ServerSocket.java:513)
        at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:189)

"OrientDB ONetworkProtocolBinary listen at 0.0.0.0:2424-2430" id=15 
   java.lang.Thread.State: RUNNABLE
        at java.net.PlainSocketImpl.socketAccept(Native Method)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:409)
        at java.net.ServerSocket.implAccept(ServerSocket.java:545)
        at java.net.ServerSocket.accept(ServerSocket.java:513)
        at com.orientechnologies.orient.server.network.OServerNetworkListener.run(OServerNetworkListener.java:189)

"Timer-0" id=12 
   java.lang.Thread.State: TIMED_WAITING
        at java.lang.Object.wait(Native Method)
        at java.util.TimerThread.mainLoop(Timer.java:552)
        at java.util.TimerThread.run(Timer.java:505)
"Thread-0" id=10 
   java.lang.Thread.State: WAITING
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.doAcquireSharedInterruptibly(AbstractQueuedSynchronizer.java:997)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireSharedInterruptibly(AbstractQueuedSynchronizer.java:1304)
        at java.util.concurrent.CountDownLatch.await(CountDownLatch.java:231)
        at com.orientechnologies.orient.server.OServer.waitForShutdown(OServer.java:528)
        at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:47)

"Signal Dispatcher" id=4 
   java.lang.Thread.State: RUNNABLE

"Finalizer" id=3 
   java.lang.Thread.State: WAITING
        at java.lang.Object.wait(Native Method)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Reference Handler" id=2 
   java.lang.Thread.State: WAITING
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:502)
        at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"main" id=1 
   java.lang.Thread.State: WAITING
        at java.lang.Object.wait(Native Method)
        at java.lang.Thread.join(Thread.java:1252)
        at java.lang.Thread.join(Thread.java:1326)
        at com.orientechnologies.orient.server.OServerMain.main(OServerMain.java:57)

REPLICATION LATENCY AVERAGE (in milliseconds)
+-------+------+-----+
|Servers|node1*|node2|
+-------+------+-----+
|node1* |      | 0.73|
|node2  |  0.67|     |
+-------+------+-----+

REPLICATION MESSAGE COUNTERS (servers: source on the row and destination on the column)
+-------+---------+----------+----------+
|Servers|   node1*|     node2|     TOTAL|
+-------+---------+----------+----------+
|node1* |         |12,162,352|12,162,352|
|node2  |1,896,763|          | 1,896,763|
+-------+---------+----------+----------+
|TOTAL  |1,896,763|12,162,352|14,059,115|
+-------+---------+----------+----------+

REPLICATION MESSAGE CURRENT NODE STATS
+------+-------+-------+--------+---------+----------+----------+-----------+------------+-------------+-------------+-------------+-------------+--------------+
|    tx|Servers| gossip|exc_lock|deploy_db|upd_db_cfg|     TOTAL|command_sql|tx-completed|record_update|copy_db_chunk|record_create|repair_record|deploy_delta_d|
+------+-------+-------+--------+---------+----------+----------+-----------+------------+-------------+-------------+-------------+-------------+--------------+
|34,744|node1* | 53,792|       8|        2|         4|12,162,559|          1|      38,676|   12,026,216|          234|        4,948|        3,932|             2|
|    18|node2  | 53,896|       2|         |         2| 3,445,070|          1|          21|    3,391,126|             |             |            3|             1|
+------+-------+-------+--------+---------+----------+----------+-----------+------------+-------------+-------------+-------------+-------------+--------------+
|34,762|TOTAL  |107,688|      10|        2|         6|15,607,629|          2|      38,697|   15,417,342|          234|        4,948|        3,935|             3|
+------+-------+-------+--------+---------+----------+----------+-----------+------------+-------------+-------------+-------------+-------------+--------------+

DATABASE 'db_development' ON SERVER 'node1'
- HA RESOURCE LOCKS FOR SERVER 'node1'
- HA RECORD LOCKS FOR DATABASE 'db_development'
+----------+------+-----------------------+----------+-----------+
|rid       |server|acquiredOn             |reqId     |threadCount|
+----------+------+-----------------------+----------+-----------+
|#12:5470  |node1 |2017-07-10 04:48:06:735|0.17009966|1          |
|#12:5544  |node1 |2017-07-10 04:33:02:517|0.14821725|1          |
|#12:5760  |node1 |2017-07-10 04:27:25:125|0.13881368|1          |
|#12:7498  |node1 |2017-07-09 17:00:58:168|0.12585373|1          |
|#12:8981  |node1 |2017-07-07 17:01:40:835|0.10516242|1          |
|#12:271967|node1 |2017-07-10 12:47:07:750|0.24484296|1          |
|#12:443953|node1 |2017-07-10 12:07:22:760|0.24458014|1          |
|#13:111   |node1 |2017-07-10 12:13:29:786|0.24468003|1          |
+----------+------+-----------------------+----------+-----------+

- MESSAGES IN QUEUES:
 - QUEUE LOCK EXECUTING: null
 - QUEUE UNLOCK EXECUTING: null
 - QUEUE 0 EXECUTING: null
 - QUEUE 1 EXECUTING: null
 - QUEUE 2 EXECUTING: null
 - QUEUE 3 EXECUTING: null
 - QUEUE 4 EXECUTING: null
 - QUEUE 5 EXECUTING: null
 - QUEUE 6 EXECUTING: null
 - QUEUE 7 EXECUTING: null

@lvca Can you please look at the log and tell us where are we going wrong.

We added the following code as you suggested:

for( int retry = 0; retry < 10; ++retry ){
 try {
  // EXECUTE YOUR COMMAND
  break;

 } catch( ONeedRetryException e ){
   // CONTINUE
 }
}

But the retry continues for indefinite time and the record is not unlocked. So this does not solve our issue.

roots-ai commented 7 years ago

Hi @lvca ! We've shared the output above, please help.

nishantkumar1292 commented 7 years ago

We also have another major issue here!! The contents of our database get erased without our knowledge and this is happening frequently. This generally happens when there is the database is not shut down properly or heavy query is run on the database. Also sometimes, the query gets interrupted due to some reason and when we restart the server, the database folder is empty. @lvca ..What is happening here?

lvca commented 7 years ago

@nishantkumar1292 what do you mean for erased? What content? Records, Clusters or the entire database? I'm sure in the log you can find the reason why the folder is empty, no space left on device or lack of permissions to the directory? Please send logs, otherwise it's impossible to receive help.

lvca commented 7 years ago

About this issue, I see there is a problem here:

+----------+------+-----------------------+----------+-----------+
|rid       |server|acquiredOn             |reqId     |threadCount|
+----------+------+-----------------------+----------+-----------+
|#12:5470  |node1 |2017-07-10 04:48:06:735|0.17009966|1          |
|#12:5544  |node1 |2017-07-10 04:33:02:517|0.14821725|1          |
|#12:5760  |node1 |2017-07-10 04:27:25:125|0.13881368|1          |
|#12:7498  |node1 |2017-07-09 17:00:58:168|0.12585373|1          |
|#12:8981  |node1 |2017-07-07 17:01:40:835|0.10516242|1          |
|#12:271967|node1 |2017-07-10 12:47:07:750|0.24484296|1          |
|#12:443953|node1 |2017-07-10 12:07:22:760|0.24458014|1          |
|#13:111   |node1 |2017-07-10 12:13:29:786|0.24468003|1          |
+----------+------+-----------------------+----------+-----------+

The locks are kept for way too much time causing this problem. It looks like the background thread that checks the timeout is not working. I'm investigating it.

lvca commented 7 years ago

Question: is it possible you're running some commands non in transaction?

nishantkumar1292 commented 7 years ago

@lvca Answer to your question: Earlier we were running the queries with transaction=true but later to solve ODistributedRecordLockedException we made transaction=false. So currently we are running commands not in transaction.

About emptying of database: The database folder gets erased - all the contents of the folder. The folder is there but the contents are erased.

2017-07-11 13:06:59:773 INFO  Loading configuration from: /home/ubuntu/orientdb-community-2.2.21/config/orientdb-server-config.xml... [OServerConfigurationLoaderXml]
2017-07-11 13:06:59:950 INFO  OrientDB Server v2.2.21 (build 491997a502b8b90210b269824755c56981765034) is starting up... [OServer]
2017-07-11 13:06:59:955 INFO  Databases directory: /home/ubuntu/data/databases [OServer]
2017-07-11 13:06:59:993 INFO  OrientDB auto-config DISKCACHE=26,200MB (heap=3,925MB direct=524,288MB os=32,174MB) [OMemoryAndLocalPaginatedEnginesInitializer]
2017-07-11 13:07:00:123 INFO  Listening binary connections on 0.0.0.0:2424 (protocol v.36, socket=default) [OServerNetworkListener]
2017-07-11 13:07:00:126 INFO  Listening http connections on 0.0.0.0:2480 (protocol v.10, socket=default) [OServerNetworkListener]
2017-07-11 13:07:00:132 INFO  Installing dynamic plugin 'orientdb-studio-2.2.21.zip'... [OServerPluginManager]
2017-07-11 13:07:00:135 INFO  ODefaultPasswordAuthenticator is active [ODefaultPasswordAuthenticator]
2017-07-11 13:07:00:136 INFO  OServerConfigAuthenticator is active [OServerConfigAuthenticator]
2017-07-11 13:07:00:136 INFO  OSystemUserAuthenticator is active [OSystemUserAuthenticator]
2017-07-11 13:07:00:151 INFO  Installed GREMLIN language v.2.6.0 - graph.pool.max=50 [OGraphServerHandler]$ANSI{green {db=OSystem}} Exception `1FC53E33` in storage `OSystem`
com.orientechnologies.orient.core.exception.OStorageException: Cannot open local storage '/home/ubuntu/data/databases/OSystem' with mode=rw
    DB name="OSystem"
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:299)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.open(ODatabaseDocumentTx.java:258)
    at com.orientechnologies.orient.server.OServer.openDatabaseBypassingSecurity(OServer.java:980)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:947)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:932)
    at com.orientechnologies.orient.server.OSystemDatabase.openSystemDatabase(OSystemDatabase.java:92)
    at com.orientechnologies.orient.server.OSystemDatabase.execute(OSystemDatabase.java:99)
    at com.orientechnologies.orient.server.security.ODefaultServerSecurity.getSystemUser(ODefaultServerSecurity.java:284)
    at com.orientechnologies.orient.server.security.authenticator.OSystemUserAuthenticator.getUser(OSystemUserAuthenticator.java:126)
    at com.orientechnologies.orient.server.security.ODefaultServerSecurity.getUser(ODefaultServerSecurity.java:411)
    at com.orientechnologies.orient.server.OServer.getUser(OServer.java:773)
    at com.orientechnologies.orient.server.distributed.impl.ODistributedAbstractPlugin.config(ODistributedAbstractPlugin.java:172)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.config(OHazelcastPlugin.java:107)
    at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1233)
    at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
    at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)
Caused by: com.orientechnologies.orient.core.exception.OStorageException: Can not open storage it is acquired by other process
    DB name="OSystem"
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.lockFile(OPaginatedStorageDirtyFlag.java:96)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.open(OPaginatedStorageDirtyFlag.java:129)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.preOpenSteps(OLocalPaginatedStorage.java:395)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:250)
    ... 15 more

2017-07-11 13:07:00:207 SEVER getUser() Exception: Cannot open local storage '/home/ubuntu/data/databases/OSystem' with mode=rw
    DB name="OSystem" [OSystemUserAuthenticator]
2017-07-11 13:07:00:247 INFO  Configuring Hazelcast from '/home/ubuntu/orientdb-community-2.2.21/config/hazelcast.xml'. [FileSystemXmlConfig]
2017-07-11 13:07:00:283 WARNI Name of the hazelcast schema location incorrect using default [AbstractXmlConfigHelper]
2017-07-11 13:07:00:502 INFO  [LOCAL] [root] [3.6.5] Interfaces is disabled, trying to pick one address from TCP-IP config addresses: [10.2.2.2, 10.1.1.1] [DefaultAddressPicker]
2017-07-11 13:07:00:502 INFO  [LOCAL] [root] [3.6.5] Prefer IPv4 stack is true. [DefaultAddressPicker]
2017-07-11 13:07:00:508 INFO  [LOCAL] [root] [3.6.5] Picked Address[10.1.1.1]:2481, using socket ServerSocket[addr=/0:0:0:0:0:0:0:0,localport=2481], bind any local is true [DefaultAddressPicker]
2017-07-11 13:07:00:518 INFO  [10.1.1.1]:2481 [root] [3.6.5] Hazelcast 3.6.5 (20160823 - e4af3d9) starting at Address[10.1.1.1]:2481 [system]
2017-07-11 13:07:00:518 INFO  [10.1.1.1]:2481 [root] [3.6.5] Copyright (c) 2008-2016, Hazelcast, Inc. All Rights Reserved. [system]
2017-07-11 13:07:00:518 INFO  [10.1.1.1]:2481 [root] [3.6.5] Configured Hazelcast Serialization version : 1 [system]
2017-07-11 13:07:00:660 INFO  [10.1.1.1]:2481 [root] [3.6.5] Backpressure is disabled [OperationService]
2017-07-11 13:07:00:678 INFO  [10.1.1.1]:2481 [root] [3.6.5] Starting with 1 generic operation threads and 1 partition operation threads. [ClassicOperationExecutor]
2017-07-11 13:07:00:979 INFO  [10.1.1.1]:2481 [root] [3.6.5] Creating TcpIpJoiner [Node]
2017-07-11 13:07:00:980 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.1.1.1]:2481 is STARTING [LifecycleService]
2017-07-11 13:07:01:048 INFO  [10.1.1.1]:2481 [root] [3.6.5] TcpIpConnectionManager configured with Non Blocking IO-threading model: 3 input threads and 3 output threads [NonBlockingIOThreadingModel]
2017-07-11 13:07:01:066 INFO  [10.1.1.1]:2481 [root] [3.6.5] Connecting to /10.2.2.2:2482, timeout: 0, bind-any: true [InitConnectionTask]
2017-07-11 13:07:01:067 INFO  [10.1.1.1]:2481 [root] [3.6.5] Connecting to /10.2.2.2:2481, timeout: 0, bind-any: true [InitConnectionTask]
2017-07-11 13:07:01:067 INFO  [10.1.1.1]:2481 [root] [3.6.5] Connecting to /10.1.1.1:2480, timeout: 0, bind-any: true [InitConnectionTask]
2017-07-11 13:07:01:067 INFO  [10.1.1.1]:2481 [root] [3.6.5] Connecting to /10.2.2.2:2480, timeout: 0, bind-any: true [InitConnectionTask]
2017-07-11 13:07:01:068 INFO  [10.1.1.1]:2481 [root] [3.6.5] Connecting to /10.1.1.1:2482, timeout: 0, bind-any: true [InitConnectionTask]
2017-07-11 13:07:01:068 INFO  [10.1.1.1]:2481 [root] [3.6.5] Could not connect to: /10.2.2.2:2480. Reason: SocketException[Connection refused to address /10.2.2.2:2480] [InitConnectionTask]
2017-07-11 13:07:01:068 INFO  [10.1.1.1]:2481 [root] [3.6.5] Could not connect to: /10.1.1.1:2482. Reason: SocketException[Connection refused to address /10.1.1.1:2482] [InitConnectionTask]
2017-07-11 13:07:01:069 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.1.1.1]:2482 is added to the blacklist. [TcpIpJoiner]
2017-07-11 13:07:01:069 INFO  [10.1.1.1]:2481 [root] [3.6.5] Could not connect to: /10.2.2.2:2482. Reason: SocketException[Connection refused to address /10.2.2.2:2482] [InitConnectionTask]
2017-07-11 13:07:01:069 INFO  [10.1.1.1]:2481 [root] [3.6.5] Could not connect to: /10.2.2.2:2481. Reason: SocketException[Connection refused to address /10.2.2.2:2481] [InitConnectionTask]
2017-07-11 13:07:01:069 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.2.2.2]:2481 is added to the blacklist. [TcpIpJoiner]
2017-07-11 13:07:01:070 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.2.2.2]:2482 is added to the blacklist. [TcpIpJoiner]
2017-07-11 13:07:01:070 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.2.2.2]:2480 is added to the blacklist. [TcpIpJoiner]
2017-07-11 13:07:01:074 INFO  [10.1.1.1]:2481 [root] [3.6.5] Established socket connection between /10.1.1.1:57901 and /10.1.1.1:2480 [TcpIpConnectionManager]
2017-07-11 13:07:06:062 INFO  [10.1.1.1]:2481 [root] [3.6.5] 

Members [1] {
    Member [10.1.1.1]:2481 this
}
 [TcpIpJoiner]
2017-07-11 13:07:06:062 WARNI [10.1.1.1]:2481 [root] [3.6.5] Config seed port is 2480 and cluster size is 1. Some of the ports seem occupied! [Node]
2017-07-11 13:07:06:085 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.1.1.1]:2481 is STARTED [LifecycleService]
2017-07-11 13:07:06:086 INFO  Starting distributed server 'node1' (hzID=6898f945-c104-4980-9b05-3f516b7c627c)... [OHazelcastPlugin]
2017-07-11 13:07:06:089 INFO  Distributed cluster time=Tue Jul 11 13:07:06 UTC 2017 (delta from local node=0)... [OHazelcastPlugin]
2017-07-11 13:07:06:109 INFO  [10.1.1.1]:2481 [root] [3.6.5] Initializing cluster partition table arrangement... [InternalPartitionService]
2017-07-11 13:07:06:170 INFO  [node1] Registered local server with nodeId=0 [OHazelcastPlugin]
2017-07-11 13:07:06:187 INFO  Distributed Lock Manager server is 'node1' [OHazelcastPlugin]
2017-07-11 13:07:06:194 INFO  [node1] Loaded configuration for database 'OSystem' from disk: /home/ubuntu/orientdb-community-2.2.21/config/default-distributed-db-config.json [ODistributedStorage]
2017-07-11 13:07:06:203 INFO  [node1] Servers in cluster: [node1] [OHazelcastPlugin]
2017-07-11 13:07:06:207 INFO  [node1] Opening database 'db_development'... [OHazelcastPlugin]
2017-07-11 13:07:06:209 INFO  [node1] Loaded configuration for database 'db_development' from disk: /home/ubuntu/data/databases/db_development/distributed-config.json [ODistributedStorage]
2017-07-11 13:07:06:222 INFO  [node1] Distributed servers status (*=current @=lockmgr[node1]):

+-----------+--------+---------+-----+---------+-----------------+-----------------+-----------------------+
|Name       |Status  |Databases|Conns|StartedOn|Binary           |HTTP             |UsedMemory             |
+-----------+--------+---------+-----+---------+-----------------+-----------------+-----------------------+
|node1(*)(@)|STARTING|         |1    |13:07:00 |10.1.1.1:2424    |10.1.1.1:2480    |355.14MB/3.83GB (9.05%)|
+-----------+--------+---------+-----+---------+-----------------+-----------------+-----------------------+
 [OHazelcastPlugin]
2017-07-11 13:07:06:224 INFO  [node1] Current node started as MASTER for database 'db_development' [OHazelcastPlugin$6]$ANSI{green {db=db_development}} Exception `6880A525` in storage `db_development`
com.orientechnologies.orient.core.exception.OStorageException: Cannot open local storage '/home/ubuntu/data/databases/db_development' with mode=rw
    DB name="db_development"
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:299)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.open(ODatabaseDocumentTx.java:258)
    at com.orientechnologies.orient.server.OServer.openDatabaseBypassingSecurity(OServer.java:980)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:947)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:932)
    at com.orientechnologies.orient.server.distributed.impl.ODistributedAbstractPlugin.reassignClustersOwnership(ODistributedAbstractPlugin.java:733)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin$6.call(OHazelcastPlugin.java:740)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin$6.call(OHazelcastPlugin.java:727)
    at com.orientechnologies.orient.server.distributed.impl.ODistributedAbstractPlugin.executeInDistributedDatabaseLock(ODistributedAbstractPlugin.java:1649)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.loadLocalDatabases(OHazelcastPlugin.java:727)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:254)
    at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
    at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
    at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)
Caused by: com.orientechnologies.orient.core.exception.OStorageException: Can not open storage it is acquired by other process
    DB name="db_development"
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.lockFile(OPaginatedStorageDirtyFlag.java:96)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.open(OPaginatedStorageDirtyFlag.java:129)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.preOpenSteps(OLocalPaginatedStorage.java:395)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:250)
    ... 13 more
[node1] Error on starting distributed plugin
com.orientechnologies.orient.core.exception.OStorageException: Cannot open local storage '/home/ubuntu/data/databases/db_development' with mode=rw
    DB name="db_development"
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:299)
    at com.orientechnologies.orient.core.db.document.ODatabaseDocumentTx.open(ODatabaseDocumentTx.java:258)
    at com.orientechnologies.orient.server.OServer.openDatabaseBypassingSecurity(OServer.java:980)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:947)
    at com.orientechnologies.orient.server.OServer.openDatabase(OServer.java:932)
    at com.orientechnologies.orient.server.distributed.impl.ODistributedAbstractPlugin.reassignClustersOwnership(ODistributedAbstractPlugin.java:733)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin$6.call(OHazelcastPlugin.java:740)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin$6.call(OHazelcastPlugin.java:727)
    at com.orientechnologies.orient.server.distributed.impl.ODistributedAbstractPlugin.executeInDistributedDatabaseLock(ODistributedAbstractPlugin.java:1649)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.loadLocalDatabases(OHazelcastPlugin.java:727)
    at com.orientechnologies.orient.server.hazelcast.OHazelcastPlugin.startup(OHazelcastPlugin.java:254)
    at com.orientechnologies.orient.server.OServer.registerPlugins(OServer.java:1242)
    at com.orientechnologies.orient.server.OServer.activate(OServer.java:397)
    at com.orientechnologies.orient.server.OServerMain$1.run(OServerMain.java:46)
Caused by: com.orientechnologies.orient.core.exception.OStorageException: Can not open storage it is acquired by other process
    DB name="db_development"
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.lockFile(OPaginatedStorageDirtyFlag.java:96)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OPaginatedStorageDirtyFlag.open(OPaginatedStorageDirtyFlag.java:129)
    at com.orientechnologies.orient.core.storage.impl.local.paginated.OLocalPaginatedStorage.preOpenSteps(OLocalPaginatedStorage.java:395)
    at com.orientechnologies.orient.core.storage.impl.local.OAbstractPaginatedStorage.open(OAbstractPaginatedStorage.java:250)
    ... 13 more

2017-07-11 13:07:12:363 WARNI Received signal: SIGINT [OSignalHandler]
2017-07-11 13:07:12:364 INFO  [10.1.1.1]:2481 [root] [3.6.5] Running shutdown hook... Current state: ACTIVE [Node]
2017-07-11 13:07:12:364 INFO  [10.1.1.1]:2481 [root] [3.6.5] Address[10.1.1.1]:2481 is SHUTTING_DOWN [LifecycleService]
2017-07-11 13:07:12:364 WARNI [10.1.1.1]:2481 [root] [3.6.5] Terminating forcefully... [Node]
2017-07-11 13:07:12:364 INFO  [10.1.1.1]:2481 [root] [3.6.5] Shutting down connection manager... [Node]
lvca commented 7 years ago

About the original error, I found a bug with non-tx locks. Fixed in 2.2.x branch. About the other error, during the installation of the database, something went wrong, but it should be in the logs. Do you still have them?

nishantkumar1292 commented 7 years ago

This was the latest log I had which was related to the issue from the logs folder. Are database installation logs stored separately? If no, then I might not have it. Any way fix this issue.. @lvca . We are using Ruby and active-orient to enter data and hitting other queries into OrientDB. Moreover for the original locks error, do I have to update my OrientDB or will it be released with the next 2.2.x version? We have to use this in production so cant use OrientDB from development branch.

nishantkumar1292 commented 7 years ago

Hi @lvca ...any updates how do we resolve the ODistributedRecordLockedException bug on our end?

lvca commented 7 years ago

@nishantkumar1292 this bug has been fixed. You can try with last 2.2.x snapshot.

decebal commented 6 years ago

I still get this in 2.2.29. I am more than happy to conclude my investigation by switching to saving all my edges in transactions. It looks like in my case it's the right solution to get around this one.

Just wondering what other people think of this, should I wait for this bug to be fix or make sure that the codebase uses transations whenever I save my edges ?

decebal commented 6 years ago

Nope, sorry won't work. I can't of want to blame this commit for all my problems: https://github.com/orientechnologies/orientdb/commit/07c48dc9a9a74b227d7dbd98d280503d320e4067

tglman commented 6 years ago

hi @decebal,

This commit refer to 3.0.0 SNAPSHOT, you don't have this change in 2.2.29.

Regards