mesh icon indicating copy to clipboard operation
mesh copied to clipboard

Async Processing of Events can cause Errors

Open Jotschi opened this issue 4 years ago • 0 comments

I'm seeing the following errors in the log

Aug 20 14:03:15 redacted java[16344]: 2019-08-20 14:03:15:924 WARNI Record (#86:2986) is null [OrientEdgeIterator]14:03:15.925 [] ERROR [vert.x-worker-thread-44] - Error while handling event mesh.node.updated with body {
Aug 20 14:03:15 redacted java[16344]: "uuid" : "61bb2f68723211e9a3af005056bd2479",
Aug 20 14:03:15 redacted java[16344]: "project" : {
Aug 20 14:03:15 redacted java[16344]: "name" : "redacted",
Aug 20 14:03:15 redacted java[16344]: "uuid" : "e99e6176536a11e8904c005056bd2479"
Aug 20 14:03:15 redacted java[16344]: },
Aug 20 14:03:15 redacted java[16344]: "type" : "DRAFT",
Aug 20 14:03:15 redacted java[16344]: "branchUuid" : "24487a81e1804e73887a81e1806e736e",
Aug 20 14:03:15 redacted java[16344]: "languageTag" : "en",
Aug 20 14:03:15 redacted java[16344]: "schema" : {
Aug 20 14:03:15 redacted java[16344]: "name" : "kl_binary_content",
Aug 20 14:03:15 redacted java[16344]: "uuid" : "f80ebbcafa1340028ebbcafa13300202",
Aug 20 14:03:15 redacted java[16344]: "version" : "1.0",
Aug 20 14:03:15 redacted java[16344]: "versionUuid" : "121cb3c7490843919cb3c74908c39170"
Aug 20 14:03:15 redacted java[16344]: }
Aug 20 14:03:15 redacted java[16344]: }
Aug 20 14:03:15 redacted java[16344]: java.lang.NullPointerException: null
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.index.node.NodeContainerTransformer.addSchema(NodeContainerTransformer.java:89)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.index.node.NodeContainerTransformer.toDocument(NodeContainerTransformer.java:511)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.entity.NodeMeshEntity.lambda$getDocument$0(NodeMeshEntity.java:33)
Aug 20 14:03:15 redacted java[16344]: at java.util.Optional.map(Optional.java:215)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.entity.NodeMeshEntity.getDocument(NodeMeshEntity.java:33)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.eventhandler.node.NodeContentEventHandler.lambda$upsertNodes$2(NodeContentEventHandler.java:98)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.madl.tx.TxFactory.lambda$tx$1(TxFactory.java:71)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.graphdb.OrientDBDatabase.tx(OrientDBDatabase.java:351)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.madl.tx.TxFactory.tx(TxFactory.java:70)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.eventhandler.node.NodeContentEventHandler.upsertNodes(NodeContentEventHandler.java:98)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.eventhandler.node.NodeContentEventHandler.lambda$handle$0(NodeContentEventHandler.java:71)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDefer.subscribeActual(FlowableDefer.java:35)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14583)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onNext(FlowableFlatMap.java:163)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFromIterable$IteratorSubscription.slowPath(FlowableFromIterable.java:236)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFromIterable$BaseRangeSubscription.request(FlowableFromIterable.java:124)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFlatMap$MergeSubscriber.onSubscribe(FlowableFlatMap.java:117)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFromIterable.subscribe(FlowableFromIterable.java:69)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFromIterable.subscribeActual(FlowableFromIterable.java:47)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableFlatMap.subscribeActual(FlowableFlatMap.java:53)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14583)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableRepeatWhen$WhenReceiver.onNext(FlowableRepeatWhen.java:100)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableRetryWhen.subscribeActual(FlowableRetryWhen.java:62)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach.subscribeActual(FlowableDoOnEach.java:50)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14636)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Flowable.subscribe(Flowable.java:14583)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableConcatMap$ConcatMapImmediate.drain(FlowableConcatMap.java:340)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableConcatMap$BaseConcatMapSubscriber.onNext(FlowableConcatMap.java:159)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onNext(FlowableDoOnEach.java:92)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableRetryPredicate$RetrySubscriber.onNext(FlowableRetryPredicate.java:74)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableOnBackpressureBuffer$BackpressureBufferSubscriber.drain(FlowableOnBackpressureBuffer.java:187)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableOnBackpressureBuffer$BackpressureBufferSubscriber.onNext(FlowableOnBackpressureBuffer.java:112)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.flowable.FlowableDoOnEach$DoOnEachSubscriber.onNext(FlowableDoOnEach.java:92)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.processors.PublishProcessor$PublishSubscription.onNext(PublishProcessor.java:360)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.processors.PublishProcessor.onNext(PublishProcessor.java:243)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.ElasticsearchProcessVerticle.lambda$null$2(ElasticsearchProcessVerticle.java:108)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.observers.ConsumerSingleObserver.onSuccess(ConsumerSingleObserver.java:62)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.observable.ObservableElementAtSingle$ElementAtObserver.onNext(ObservableElementAtSingle.java:89)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.observable.ObservableFilter$FilterObserver.onNext(ObservableFilter.java:52)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.util.NotificationLite.accept(NotificationLite.java:246)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.subjects.BehaviorSubject$BehaviorDisposable.test(BehaviorSubject.java:569)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.subjects.BehaviorSubject$BehaviorDisposable.emitFirst(BehaviorSubject.java:530)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.subjects.BehaviorSubject.subscribeActual(BehaviorSubject.java:239)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Observable.subscribe(Observable.java:12197)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.observable.ObservableFilter.subscribeActual(ObservableFilter.java:30)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Observable.subscribe(Observable.java:12197)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.internal.operators.observable.ObservableElementAtSingle.subscribeActual(ObservableElementAtSingle.java:37)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Single.subscribe(Single.java:3495)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Single.subscribe(Single.java:3481)
Aug 20 14:03:15 redacted java[16344]: at io.reactivex.Single.subscribe(Single.java:3452)
Aug 20 14:03:15 redacted java[16344]: at com.gentics.mesh.search.verticle.ElasticsearchProcessVerticle.lambda$null$3(ElasticsearchProcessVerticle.java:105)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.eventbus.impl.HandlerRegistration.deliver(HandlerRegistration.java:276)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.eventbus.impl.HandlerRegistration.handle(HandlerRegistration.java:254)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.eventbus.impl.EventBusImpl$InboundDeliveryContext.next(EventBusImpl.java:578)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.eventbus.impl.EventBusImpl.lambda$deliverToHandler$5(EventBusImpl.java:537)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.impl.ContextImpl.executeTask(ContextImpl.java:369)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.impl.WorkerContext.lambda$wrapTask$0(WorkerContext.java:35)
Aug 20 14:03:15 redacted java[16344]: at io.vertx.core.impl.TaskQueue.run(TaskQueue.java:76)
Aug 20 14:03:15 redacted java[16344]: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
Aug 20 14:03:15 redacted java[16344]: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
Aug 20 14:03:15 redacted java[16344]: at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
Aug 20 14:03:15 redacted java[16344]: at java.lang.Thread.run(Thread.java:748)

Jotschi avatar Aug 20 '19 12:08 Jotschi