[Bug] Migration issues from ES to Cassandra

[crackytsi]

Request Type

Bug

Work Environment

Question	Answer
OS version (server)	Debian
OS version (client)	10
TheHive version / git hash	4.0 RC2
Package Type	DEB
Elasticsearch	5.6.10

Problem Description

I have several problems with the migration.
I haven't done any modification in elasticsearch, so this is a simple TheHive system that has just performed several updates after migrations from version 2 up to latest 3 version.

Except the issue, that the migration is very slow (see other issue, this are 250 MB) , there are several failures.
After 4 days with just some demo data migration stopped with this error message:

[error] o.t.t.m.t.DBConfiguration - ElasticSearch request failure: POST:/_search/scroll?
StringEntity({"scroll":"36000000ms","scroll_id":"DnF1ZXJ5VGhlbkZldGNoBQAAAAAAAMErFi1NWmZ5RGVRVFItTWF4SHZHWl9qaWcAAAAAAADBLBYtTVpmeURlUVRSLU1heEh2R1pfamlnAAAAAAAAwS0WLU1aZnlEZVFUUi1NYXhIdkdaX2ppZwAAAAAAAMEuFi1NWmZ5RGVRVFItTWF4SHZHWl9qaWcAAAAAAADBLxYtTVpmeURlUVRSLU1heEh2R1pfamln"},Some(application/json))
 => ElasticError(search_phase_execution_exception,all shards failed,None,None,None,List(ElasticError(search_context_missing_exception,No search context found for id [49455],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [49452],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [49451],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [49454],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [49453],None,None,None,null,None)),Some(CausedBy(search_context_missing_exception,No search context found for id [49453],Map())))
[warn] o.t.t.m.t.SearchWithScroll - Search error
org.thp.scalligraph.SearchError: all shards failed
        at org.thp.thehive.migration.th3.DBConfiguration.$anonfun$execute$2(DBConfiguration.scala:147)
        at scala.concurrent.Future.$anonfun$flatMap$1(Future.scala:307)
        at scala.concurrent.impl.Promise.$anonfun$transformWith$1(Promise.scala:41)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
        at org.thp.scalligraph.ContextPropagatingDisptacher$$anon$1.$anonfun$execute$2(ContextPropagatingDisptacher.scala:57)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
        at org.thp.scalligraph.DiagnosticContext$.$anonfun$withDiagnosticContext$2(ContextPropagatingDisptacher.scala:92)
        at org.thp.scalligraph.DiagnosticContext$.saveDiagnosticContext(ContextPropagatingDisptacher.scala:107)
        at org.thp.scalligraph.DiagnosticContext$.withDiagnosticContext(ContextPropagatingDisptacher.scala:90)
        at org.thp.scalligraph.DiagnosticContext$$anon$2.withContext(ContextPropagatingDisptacher.scala:75)
[error] o.t.t.m.t.DBConfiguration - ElasticSearch request failure: DELETE:/_search/scroll/?
StringEntity({"scroll_id":["DnF1ZXJ5VGhlbkZldGNoBQAAAAAAAMEmFi1NWmZ5RGVRVFItTWF4SHZHWl9qaWcAAAAAAADBKBYtTVpmeURlUVRSLU1heEh2R1pfamlnAAAAAAAAwSoWLU1aZnlEZVFUUi1NYXhIdkdaX2ppZwAAAAAAAMEnFi1NWmZ5RGVRVFItTWF4SHZHWl9qaWcAAAAAAADBKRYtTVpmeURlUVRSLU1heEh2R1pfamln"]},Some(application/json))
 => ElasticError(404,404,None,None,None,List(),None)
[error] o.t.s.u.Retry - uncaught error, not retrying
java.lang.IllegalStateException: Cannot access element because its enclosing transaction is closed and unbound
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.getNextTx(StandardJanusGraphTx.java:305)
        at org.janusgraph.graphdb.vertices.AbstractVertex.it(AbstractVertex.java:53)
        at org.janusgraph.graphdb.vertices.AbstractVertex.it(AbstractVertex.java:37)
        at org.janusgraph.graphdb.internal.AbstractElement.isRemoved(AbstractElement.java:141)
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.isDeleted(StandardJanusGraphTx.java:1261)
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.isDeleted(StandardJanusGraphTx.java:1188)
        at org.janusgraph.graphdb.query.QueryProcessor.lambda$getFilterIterator$2(QueryProcessor.java:133)
        at com.google.common.collect.Iterators$5.computeNext(Iterators.java:637)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
[error] o.t.s.m.Database - Exception raised, rollback (Cannot access element because its enclosing transaction is closed and unbound)
[error] o.t.t.m.Migrate - InputObservable creation failure
java.lang.IllegalStateException: Cannot access element because its enclosing transaction is closed and unbound
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.getNextTx(StandardJanusGraphTx.java:305)
        at org.janusgraph.graphdb.vertices.AbstractVertex.it(AbstractVertex.java:53)
        at org.janusgraph.graphdb.vertices.AbstractVertex.it(AbstractVertex.java:37)
        at org.janusgraph.graphdb.internal.AbstractElement.isRemoved(AbstractElement.java:141)
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.isDeleted(StandardJanusGraphTx.java:1261)
        at org.janusgraph.graphdb.transaction.StandardJanusGraphTx$3.isDeleted(StandardJanusGraphTx.java:1188)
        at org.janusgraph.graphdb.query.QueryProcessor.lambda$getFilterIterator$2(QueryProcessor.java:133)
        at com.google.common.collect.Iterators$5.computeNext(Iterators.java:637)
        at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141)
        at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136)
[info] o.t.t.m.t.Output - Create observable %UserProfile%\AppData\Roaming\[victim_id].pek in alert 207847504
[warn] o.j.d.i.ConsistentKeyIDAuthority - Temporary storage exception while acquiring id block - retrying in PT0.6S: {}
org.janusgraph.diskstorage.TemporaryBackendException: Temporary failure in storage backend
        at io.vavr.API$Match$Case0.apply(API.java:3174)
        at io.vavr.API$Match.of(API.java:3137)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.lambda$static$0(CQLKeyColumnValueStore.java:123)
        at io.vavr.control.Try.getOrElseThrow(Try.java:671)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:290)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Could not send request, session is closed
        at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:552)
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:513)
        at io.vavr.control.Try.of(Try.java:62)
        at io.vavr.concurrent.FutureImpl.lambda$run$2(FutureImpl.java:199)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        ... 4 common frames omitted
Caused by: java.lang.IllegalStateException: Could not send request, session is closed
        at com.datastax.driver.core.SessionManager.execute(SessionManager.java:693)
        at com.datastax.driver.core.SessionManager.executeAsync(SessionManager.java:143)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:282)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:255)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[warn] o.j.d.i.ConsistentKeyIDAuthority - Temporary storage exception while acquiring id block - retrying in PT1.2S: {}
org.janusgraph.diskstorage.TemporaryBackendException: Temporary failure in storage backend
        at io.vavr.API$Match$Case0.apply(API.java:3174)
        at io.vavr.API$Match.of(API.java:3137)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.lambda$static$0(CQLKeyColumnValueStore.java:123)
        at io.vavr.control.Try.getOrElseThrow(Try.java:671)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:290)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Could not send request, session is closed
        at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:552)
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:513)
        at io.vavr.control.Try.of(Try.java:62)
        at io.vavr.concurrent.FutureImpl.lambda$run$2(FutureImpl.java:199)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        ... 4 common frames omitted
Caused by: java.lang.IllegalStateException: Could not send request, session is closed
        at com.datastax.driver.core.SessionManager.execute(SessionManager.java:693)
        at com.datastax.driver.core.SessionManager.executeAsync(SessionManager.java:143)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:282)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:255)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[warn] o.j.d.i.ConsistentKeyIDAuthority - Temporary storage exception while acquiring id block - retrying in PT2.4S: {}
org.janusgraph.diskstorage.TemporaryBackendException: Temporary failure in storage backend
        at io.vavr.API$Match$Case0.apply(API.java:3174)
        at io.vavr.API$Match.of(API.java:3137)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.lambda$static$0(CQLKeyColumnValueStore.java:123)
        at io.vavr.control.Try.getOrElseThrow(Try.java:671)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:290)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
Caused by: java.util.concurrent.ExecutionException: java.lang.IllegalStateException: Could not send request, session is closed
        at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:552)
        at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:513)
        at io.vavr.control.Try.of(Try.java:62)
        at io.vavr.concurrent.FutureImpl.lambda$run$2(FutureImpl.java:199)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        ... 4 common frames omitted
Caused by: java.lang.IllegalStateException: Could not send request, session is closed
        at com.datastax.driver.core.SessionManager.execute(SessionManager.java:693)
        at com.datastax.driver.core.SessionManager.executeAsync(SessionManager.java:143)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.getSlice(CQLKeyColumnValueStore.java:282)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.lambda$getCurrentID$0(ConsistentKeyIDAuthority.java:172)
        at org.janusgraph.diskstorage.util.BackendOperation.execute(BackendOperation.java:147)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getCurrentID(ConsistentKeyIDAuthority.java:171)
        at org.janusgraph.diskstorage.idmanagement.ConsistentKeyIDAuthority.getIDBlock(ConsistentKeyIDAuthority.java:232)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:288)
        at org.janusgraph.graphdb.database.idassigner.StandardIDPool$IDBlockGetter.call(StandardIDPool.java:255)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)

During import several times errors like this appeared:

^[[31merror^[[0m] o.t.t.m.t.Input - Alert observable read failure:List(
 - : JsonValidationError(List('attachment' is undefined on object: {"tlp":2,"remoteAttachment":{"filename":"20171114-ELF-2.png","reference":"194081","type":"attachment"},"tags":["MISP:type=attachment","MISP:category=External analysis","src:misp-malware-sharing-prod","misp"],"message":"An overview of the malware’s operation.","dataType":"file","startDate":1512310223000}),WrappedArray()))

[^[[31merror^[[0m] o.t.t.m.t.Input - Alert observable read failure:List(
 - : JsonValidationError(List('attachment' is undefined on object: {"tlp":2,"remoteAttachment":{"filename":"tizi1.png","reference":"194158","type":"attachment"},"tags":["MISP:type=attachment","MISP:category=Payload delivery","src:misp-malware-sharing-prod","misp"],"message":"Here is an example social media post promoting a Tizi-infected app","dataType":"file","startDate":1512299720000}),WrappedArray()))

Can you please help here?

[To-om]

This commit should fix your general problem and improve performance of migration.
Regarding the missing attachment, this is an old observable format from MISP alert (before TheHive 2.13.0).
This kind of attachment is not downloaded from MISP during alert creation but when the alert is imported into case.
I'm sorry to say that I can't migrate these kind of observable into TheHive 4.

[mamoedo]

It keeps failing on RC3

Question	Answer
OS version (server)	Ubuntu
OS version (client)	18.04
TheHive version / git hash	4.0 RC3
Package Type	DEB
Elasticsearch	6.7.0

[info] o.t.t.m.t.Output - Create task [1234] Sensitive info in case 177868816
[error] o.t.s.u.Retry - uncaught error, not retrying
org.thp.scalligraph.NotFoundError: User user@org.com not found
        at org.thp.scalligraph.services.VertexSrv.$anonfun$getOrFail$1(VertexSrv.scala:33)
        at scala.Option.fold(Option.scala:251)
        at org.thp.scalligraph.services.VertexSrv.getOrFail(VertexSrv.scala:33)
        at org.thp.thehive.migration.th4.Output.$anonfun$createCaseTask$4(Output.scala:337)
        at scala.Option.map(Option.scala:230)
        at org.thp.thehive.migration.th4.Output.$anonfun$createCaseTask$2(Output.scala:337)
        at org.thp.thehive.migration.th4.Output.$anonfun$authTransaction$1(Output.scala:161)
        at org.thp.scalligraph.janus.JanusDatabase.$anonfun$tryTransaction$10(JanusDatabase.scala:160)
        at scala.util.Try$.apply(Try.scala:213)
        at org.thp.scalligraph.janus.JanusDatabase.$anonfun$tryTransaction$8(JanusDatabase.scala:160)
[error] o.t.s.m.Database - Exception raised, rollback (User user@org.com not found)
[error] o.t.t.m.Migrate - Case/Task creation failure: org.thp.scalligraph.NotFoundError: User user@org.com not found
[error] o.t.t.m.t.DBConfiguration - ElasticSearch request failure: POST:/_search/scroll?
StringEntity({"scroll":"82800000ms","scroll_id":"DnF1ZXJ5VGhlbkZldGNoBAAAAAAAAACXFjdzaTEtXzY1UVgyZFN6SGdqTnBKVncAAAAAAAAAmBY3c2kxLV82NVFYMmRTekhnak5wSlZ3AAAAAAAAAJkWN3NpMS1fNjVRWDJkU3pIZ2pOcEpWdwAAAAAAAACaFjdzaTEtXzY1UVgyZFN6SGdqTnBKVnc="},Some(application/json))
 => ElasticError(search_phase_execution_exception,all shards failed,None,None,None,List(ElasticError(search_context_missing_exception,No search context found for id [151],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [152],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [153],None,None,None,null,None), ElasticError(search_context_missing_exception,No search context found for id [154],None,None,None,null,None)),Some(CausedBy(search_context_missing_exception,No search context found for id [154],Map())))
[warn] o.t.t.m.t.SearchWithScroll - Search error
org.thp.scalligraph.SearchError: all shards failed
        at org.thp.thehive.migration.th3.DBConfiguration.$anonfun$execute$2(DBConfiguration.scala:147)
        at scala.concurrent.Future.$anonfun$flatMap$1(Future.scala:307)
        at scala.concurrent.impl.Promise.$anonfun$transformWith$1(Promise.scala:41)
        at scala.concurrent.impl.CallbackRunnable.run(Promise.scala:64)
        at org.thp.scalligraph.ContextPropagatingDisptacher$$anon$1.$anonfun$execute$2(ContextPropagatingDisptacher.scala:57)
        at scala.runtime.java8.JFunction0$mcV$sp.apply(JFunction0$mcV$sp.java:23)
        at org.thp.scalligraph.DiagnosticContext$.$anonfun$withDiagnosticContext$2(ContextPropagatingDisptacher.scala:92)
        at org.thp.scalligraph.DiagnosticContext$.saveDiagnosticContext(ContextPropagatingDisptacher.scala:107)
        at org.thp.scalligraph.DiagnosticContext$.withDiagnosticContext(ContextPropagatingDisptacher.scala:90)
        at org.thp.scalligraph.DiagnosticContext$$anon$2.withContext(ContextPropagatingDisptacher.scala:75)
Exception in thread "main" org.thp.scalligraph.SearchError: Request terminated early or timed out
        at org.thp.thehive.migration.th3.SearchWithScroll$$anon$1$$anon$2.$anonfun$onPull$1(DBFind.scala:197)
        at org.thp.thehive.migration.th3.SearchWithScroll$$anon$1$$anon$2.$anonfun$onPull$1$adapted(DBFind.scala:177)
        at akka.stream.impl.fusing.GraphInterpreter.runAsyncInput(GraphInterpreter.scala:466)
        at akka.stream.impl.fusing.GraphInterpreterShell$AsyncInput.execute(ActorGraphInterpreter.scala:497)
        at akka.stream.impl.fusing.GraphInterpreterShell.processEvent(ActorGraphInterpreter.scala:599)
        at akka.stream.impl.fusing.ActorGraphInterpreter.akka$stream$impl$fusing$ActorGraphInterpreter$$processEvent(ActorGraphInterpreter.scala:768)
        at akka.stream.impl.fusing.ActorGraphInterpreter$$anonfun$receive$1.applyOrElse(ActorGraphInterpreter.scala:783)
        at akka.actor.Actor.aroundReceive(Actor.scala:534)
        at akka.actor.Actor.aroundReceive$(Actor.scala:532)
        at akka.stream.impl.fusing.ActorGraphInterpreter.aroundReceive(ActorGraphInterpreter.scala:690)
        at akka.actor.ActorCell.receiveMessage(ActorCell.scala:573)
        at akka.actor.ActorCell.invoke(ActorCell.scala:543)
        at akka.dispatch.Mailbox.processMailbox(Mailbox.scala:269)
        at akka.dispatch.Mailbox.run(Mailbox.scala:230)
        at akka.dispatch.Mailbox.exec(Mailbox.scala:242)
        at java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:289)
        at java.util.concurrent.ForkJoinPool$WorkQueue.runTask(ForkJoinPool.java:1056)
        at java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1692)
        at java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:157)
[warn] o.t.t.m.t.Output - User user@org.com not found, use system user
[info] o.t.t.m.t.Output - Create audit update on Some(Case) Some(177868816)

[To-om]

The first error (User user@org.com not found) is partially fixed by #1374.
Then I'll prevent failure if user is not found.
I'll also investigate the "Search error"