search

linagora / james-project

Mirror of Apache James Project
Apache License 2.0
70 stars 63 forks source link

CNB bug: failed EmailSubmission/set #5071

Closed chibenwa closed 6 months ago

chibenwa commented 7 months ago 
java.lang.IllegalArgumentException: EmailSubmissionCreationId(#1df17901-cf03-11ee-b0b5-7726fec72a75) cannot be referenced in current method call
    at org.apache.james.jmap.method.EmailSubmissionSetMethod$CreationResults.$anonfun$resolveMessageId$4(EmailSubmissionSetMethod.scala:128)
    at scala.Option.getOrElse(Option.scala:201)
    at org.apache.james.jmap.method.EmailSubmissionSetMethod$CreationResults.$anonfun$resolveMessageId$2(EmailSubmissionSetMethod.scala:128)
    at org.apache.james.jmap.method.EmailSubmissionSetMethod$CreationResults.$anonfun$resolveMessageId$2$adapted(EmailSubmissionSetMethod.scala:126)
    at scala.util.Either.flatMap(Either.scala:352)
    at org.apache.james.jmap.method.EmailSubmissionSetMethod$CreationResults.resolveMessageId(EmailSubmissionSetMethod.scala:126)
    at org.apache.james.jmap.method.EmailSubmissionSetMethod.$anonfun$doProcess$4(EmailSubmissionSetMethod.scala:190)
    at org.apache.james.jmap.mail.EmailSubmissionSetRequest.$anonfun$resolveOnSuccessUpdateEmail$2(EmailSubmissionSet.scala:69)
    at scala.collection.immutable.List.map(List.scala:246)
    at org.apache.james.jmap.mail.EmailSubmissionSetRequest.$anonfun$resolveOnSuccessUpdateEmail$1(EmailSubmissionSet.scala:68)
    at scala.Option.map(Option.scala:242)
    at org.apache.james.jmap.mail.EmailSubmissionSetRequest.resolveOnSuccessUpdateEmail(EmailSubmissionSet.scala:67)
    at org.apache.james.jmap.mail.EmailSubmissionSetRequest.implicitEmailSetRequest(EmailSubmissionSet.scala:52)
    at org.apache.james.jmap.method.EmailSubmissionSetMethod.$anonfun$doProcess$1(EmailSubmissionSetMethod.scala:190)
    at reactor.core.scala.publisher.package$.$anonfun$scalaFunction2JavaFunction$1(package.scala:51)
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onNext(MonoFlatMapMany.java:163)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:245)
    at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305)
    at reactor.core.publisher.Operators$MonoSubscriber.complete(Operators.java:1865)
    at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.signalCached(MonoCacheTime.java:337)
    at reactor.core.publisher.MonoCacheTime$CoordinatorSubscriber.onNext(MonoCacheTime.java:354)
    at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onNext(FluxHide.java:137)
    at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
    at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122)
    at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
    at reactor.core.publisher.Operators$ScalarSubscription.request(Operators.java:2571)
    at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.set(Operators.java:2367)
    at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onSubscribe(FluxOnErrorResume.java:74)
    at reactor.core.publisher.MonoJust.subscribe(MonoJust.java:55)
    at reactor.core.publisher.Mono.subscribe(Mono.java:4512)
    at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103)
    at reactor.core.publisher.FluxMap$MapSubscriber.onError(FluxMap.java:134)
    at reactor.core.publisher.Operators.error(Operators.java:198)
    at reactor.core.publisher.MonoError.subscribe(MonoError.java:53)
    at reactor.core.publisher.Mono.subscribe(Mono.java:4512)
    at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:205)
    at reactor.core.publisher.MonoFlatMap.subscribeOrReturn(MonoFlatMap.java:53)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:63)
    at reactor.core.publisher.MonoCacheTime.subscribeOrReturn(MonoCacheTime.java:143)
    at reactor.core.publisher.InternalMonoOperator.subscribe(InternalMonoOperator.java:63)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onNext(MonoFlatMap.java:165)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.completePossiblyEmpty(Operators.java:2097)
    at reactor.core.publisher.MonoReduceSeed$ReduceSeedSubscriber.onComplete(MonoReduceSeed.java:163)
    at reactor.core.publisher.FluxIterable$IterableSubscription.fastPath(FluxIterable.java:424)
    at reactor.core.publisher.FluxIterable$IterableSubscription.request(FluxIterable.java:291)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.request(Operators.java:2067)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.request(MonoFlatMap.java:194)
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onSubscribe(MonoFlatMapMany.java:141)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.onSubscribe(MonoFlatMap.java:117)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.onSubscribe(Operators.java:2051)
    at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:201)
    at reactor.core.publisher.FluxIterable.subscribe(FluxIterable.java:83)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.publisher.FluxFlatMap.trySubscribeScalarMap(FluxFlatMap.java:202)
    at reactor.core.publisher.MonoFlatMapMany.subscribeOrReturn(MonoFlatMapMany.java:49)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8762)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.FluxUsing.subscribe(FluxUsing.java:114)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onNext(MonoFlatMapMany.java:195)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.completePossiblyEmpty(Operators.java:2097)
    at reactor.core.publisher.MonoTakeLastOne$TakeLastOneSubscriber.onComplete(MonoTakeLastOne.java:162)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onComplete(FluxMapFuseable.java:152)
    at reactor.core.publisher.FluxReplay$UnboundedReplayBuffer.replayNormal(FluxReplay.java:602)
    at reactor.core.publisher.FluxReplay$UnboundedReplayBuffer.replay(FluxReplay.java:709)
    at reactor.core.publisher.FluxReplay$ReplayInner.request(FluxReplay.java:1712)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.request(FluxMapFuseable.java:171)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.request(Operators.java:2067)
    at reactor.core.publisher.MonoFlatMapMany$FlatMapManyMain.onSubscribe(MonoFlatMapMany.java:141)
    at reactor.core.publisher.Operators$BaseFluxToMonoOperator.onSubscribe(Operators.java:2051)
    at reactor.core.publisher.FluxMapFuseable$MapFuseableSubscriber.onSubscribe(FluxMapFuseable.java:96)
    at reactor.core.publisher.FluxReplay.subscribeOrReturn(FluxReplay.java:1181)
    at reactor.core.publisher.FluxReplay.subscribe(FluxReplay.java:1153)
    at reactor.core.publisher.FluxAutoConnectFuseable.subscribe(FluxAutoConnectFuseable.java:61)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.FluxFromMonoOperator.subscribe(FluxFromMonoOperator.java:85)
    at reactor.core.publisher.FluxReplay.connect(FluxReplay.java:1141)
    at reactor.core.publisher.FluxAutoConnectFuseable.subscribe(FluxAutoConnectFuseable.java:63)
    at reactor.core.publisher.Flux.subscribe(Flux.java:8777)
    at reactor.core.scala.publisher.SFlux.subscribe(SFlux.scala:909)
    at reactor.core.scala.publisher.SFlux.subscribe$(SFlux.scala:909)
    at reactor.core.scala.publisher.ReactiveSFlux.subscribe(ReactiveSFlux.scala:8)
    at reactor.core.publisher.FluxSource.subscribe(FluxSource.java:71)
    at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.drain(FluxConcatMap.java:451)
    at reactor.core.publisher.FluxConcatMap$ConcatMapImmediate.innerComplete(FluxConcatMap.java:296)
    at reactor.core.publisher.FluxConcatMap$ConcatMapInner.onComplete(FluxConcatMap.java:887)
    at reactor.core.publisher.FluxReplay$UnboundedReplayBuffer.replayNormal(FluxReplay.java:602)
    at reactor.core.publisher.FluxReplay$UnboundedReplayBuffer.replay(FluxReplay.java:709)
    at reactor.core.publisher.FluxReplay$ReplaySubscriber.onComplete(FluxReplay.java:1373)
    at reactor.core.publisher.FluxMap$MapSubscriber.onComplete(FluxMap.java:144)
    at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:2231)
    at reactor.core.publisher.FluxUsing$UsingSubscriber.onComplete(FluxUsing.java:236)
    at reactor.core.publisher.Operators$MultiSubscriptionSubscriber.onComplete(Operators.java:2231)
    at reactor.core.publisher.FluxPeek$PeekSubscriber.onComplete(FluxPeek.java:260)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:246)
    at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305)
    at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondComplete(MonoFlatMap.java:245)
    at reactor.core.publisher.MonoFlatMap$FlatMapInner.onNext(MonoFlatMap.java:305)
    at reactor.core.publisher.FluxHide$SuppressFuseableSubscriber.onNext(FluxHide.java:137)
    at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122)
    at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122)
    at reactor.core.publisher.FluxSwitchIfEmpty$SwitchIfEmptySubscriber.onNext(FluxSwitchIfEmpty.java:74)
    at reactor.core.publisher.FluxMap$MapSubscriber.onNext(FluxMap.java:122)
    at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onNext(FluxOnErrorResume.java:79)
    at reactor.core.publisher.MonoNext$NextSubscriber.onNext(MonoNext.java:82)
    at com.datastax.dse.driver.internal.core.cql.reactive.ReactiveResultSetSubscription.doOnNext(ReactiveResultSetSubscription.java:364)
    at com.datastax.dse.driver.internal.core.cql.reactive.ReactiveResultSetSubscription.drain(ReactiveResultSetSubscription.java:236)
    at com.datastax.dse.driver.internal.core.cql.reactive.ReactiveResultSetSubscription.lambda$fetchNextPageAndEnqueue$2(ReactiveResultSetSubscription.java:358)
    at java.base/java.util.concurrent.CompletableFuture$UniAccept.tryFire(Unknown Source)
    at java.base/java.util.concurrent.CompletableFuture.postComplete(Unknown Source)
    at java.base/java.util.concurrent.CompletableFuture.complete(Unknown Source)
    at com.datastax.oss.driver.internal.core.cql.CqlRequestHandler.setFinalResult(CqlRequestHandler.java:324)
    at com.datastax.oss.driver.internal.core.cql.CqlRequestHandler.access$1500(CqlRequestHandler.java:95)
    at com.datastax.oss.driver.internal.core.cql.CqlRequestHandler$NodeResponseCallback.onResponse(CqlRequestHandler.java:655)
    at com.datastax.oss.driver.internal.core.channel.InFlightHandler.channelRead(InFlightHandler.java:257)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
    at io.netty.handler.timeout.IdleStateHandler.channelRead(IdleStateHandler.java:286)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:442)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
    at io.netty.handler.codec.MessageToMessageDecoder.channelRead(MessageToMessageDecoder.java:103)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
    at io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:346)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:318)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:444)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:412)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:440)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:420)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:788)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:724)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:650)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:562)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.base/java.lang.Thread.run(Unknown Source)

TODO try to understand / reproduce

chibenwa commented 7 months ago

Race condition with the "move from Outbox to sent" ?

chibenwa commented 7 months ago

Also try to see the JSON done by the mobile application

vttranlina commented 6 months ago

It comes from "incorrect" clientId in JSON request (client side). How to reproduce: https://github.com/apache/james-project/commit/a46778c8dec184848a4043f9a286cd6b2815ee90

Document related: https://jmap.io/spec-mail.html 7.5.1 Example Wrong clientId of onSuccessUpdateEmail

chibenwa commented 6 months ago

Did you open a twake mail frontend issue @vttranlina ?

Did you succeed to reproduce on the front?

vttranlina commented 6 months ago

Did you open a twake mail frontend issue @vttranlina ?

Did you succeed to reproduce on the front?

No, I tried to front, but can not reproduce

vttranlina commented 6 months ago

One more case can reproduce: Try to add onSuccessUpdateEmail on the failed EmailSubmission/set creation request. https://github.com/apache/james-project/commit/52de246c5fd272c798be31ecaafa86baafdb3ece

In this case => we should filter "success created" before doing onSuccessUpdateEmail , let me create a PR for that

updated: The jmap document does not explain details for this case, it just write:

onSuccessUpdateEmail: Id[PatchObject]|null A map of EmailSubmission id to an object containing properties to update on the Email object referenced by the EmailSubmission if the create/update/destroy succeeds.

https://jmap.io/spec-mail.html

vttranlina commented 6 months ago

we should filter "success created" before doing onSuccessUpdateEmail , let me create a PR for that

pr https://github.com/apache/james-project/pull/2041

vttranlina commented 6 months ago

Note: Checked MDNSend method (that also has onSuccessUpdateEmail). We don't get the same issue