diff --git a/rd-kt/rd-core/src/main/kotlin/com/jetbrains/rd/util/threading/coroutines/RdCoroutineScope.kt b/rd-kt/rd-core/src/main/kotlin/com/jetbrains/rd/util/threading/coroutines/RdCoroutineScope.kt index 1b386ffda..71d490741 100644 --- a/rd-kt/rd-core/src/main/kotlin/com/jetbrains/rd/util/threading/coroutines/RdCoroutineScope.kt +++ b/rd-kt/rd-core/src/main/kotlin/com/jetbrains/rd/util/threading/coroutines/RdCoroutineScope.kt @@ -24,10 +24,10 @@ open class RdCoroutineScope : CoroutineScope { if (!currentHost.compareAndSet(null, host)) throw IllegalStateException("Could not override RdCoroutineHost") - logger.debug { "RdCoroutineHost has been overridden" } + logger.trace { "RdCoroutineHost has been overridden" } host.coroutineContext.job.invokeOnCompletion { currentHost.getAndSet(null) - logger.debug { "RdCoroutineHost has been reset" } + logger.trace { "RdCoroutineHost has been reset" } } } } diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/Interfaces.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/Interfaces.kt index 577a793f4..d5f975c8d 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/Interfaces.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/Interfaces.kt @@ -98,7 +98,7 @@ interface IMarshaller : ISerializer { } val IMarshaller<*>.fqn: String get() { - return if (this is LazyCompanionMarshaller) this.fgn + return if (this is LazyCompanionMarshaller) this.fqn else _type.qualifiedName ?: _type.jvmName } @@ -108,7 +108,7 @@ class LazyCompanionMarshaller( val fqn: String ) : IMarshaller { private val lazy = lazy(LazyThreadSafetyMode.PUBLICATION) { - Class.forName(fgn, true, classLoader).getDeclaredField("Companion").get(null) as IMarshaller + Class.forName(fqn, true, classLoader).getDeclaredField("Companion").get(null) as IMarshaller } override val _type: KClass<*> diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdMap.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdMap.kt index 11cf54735..d78d8245e 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdMap.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdMap.kt @@ -194,9 +194,11 @@ open class RdMap private constructor( val lifetime = dispatchHelper.lifetime val definition = tryPreBindValue(lifetime, key, value, true) + logReceived.trace { "onWireReceived:: ${logmsg(op, version, key, value)}" } + dispatchHelper.dispatch { if (msgVersioned || !master || !isPendingForAck(key)) { - logReceived.trace { logmsg(op, version, key, value) } + logReceived.trace { "dispatched:: ${logmsg(op, version, key, value)}" } if (value != null) { val definitions = tryGetBindDefinitions(lifetime) diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdProperty.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdProperty.kt index 0b93567bf..ce1b517fc 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdProperty.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdProperty.kt @@ -107,9 +107,11 @@ abstract class RdPropertyBase(val valueSerializer: ISerializer) : RdReacti val definition = tryPreBindValue(dispatchHelper.lifetime, v, true) + logReceived.trace { "onWireReceived:: ${getMessage(version, v)}" } + dispatchHelper.dispatch { val rejected = master && version < masterVersion - logReceived.trace { "property `$location` ($rdid):: oldver = $masterVersion, newver = $version, value = ${v.printToString()}${rejected.condstr { " >> REJECTED" }}" } + logReceived.trace { "dispatched:: ${getMessage(version, v)}${rejected.condstr { " >> REJECTED" }}" } if (rejected) { definition?.terminate() @@ -124,6 +126,9 @@ abstract class RdPropertyBase(val valueSerializer: ISerializer) : RdReacti } } + private fun getMessage(version: Int, v: T) = + "property `$location` ($rdid):: oldver = $masterVersion, newver = $version, value = ${v.printToString()}" + override fun advise(lifetime: Lifetime, handler: (T) -> Unit) { if (isBound) assertThreading() property.advise(lifetime, handler) diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSet.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSet.kt index b042fac35..3855a1147 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSet.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSet.kt @@ -55,7 +55,9 @@ open class RdSet constructor(val valueSerializer: ISerializer, priva val kind = buffer.readEnum() val v = valueSerializer.read(ctx, buffer) + logReceived.trace { "onWireReceived:: $this :: $kind :: ${v.printToString()}" } dispatchHelper.dispatch { + logReceived.trace { "dispatched:: $this :: $kind :: ${v.printToString()}" } when (kind) { AddRemove.Add -> set.add(v) AddRemove.Remove -> set.remove(v) diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSignal.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSignal.kt index 0dca099f5..977469216 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSignal.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSignal.kt @@ -27,8 +27,9 @@ class RdSignal(val valueSerializer: ISerializer = Polymorphic()) : RdRe override fun onWireReceived(proto: IProtocol, buffer: AbstractBuffer, ctx: SerializationCtx, dispatchHelper: IRdWireableDispatchHelper) { val value = valueSerializer.read(ctx, buffer) - logReceived.trace {"signal `$location` ($rdid):: value = ${value.printToString()}"} + logReceived.trace {"onWireReceived:: signal `$location` ($rdid):: value = ${value.printToString()}"} dispatchHelper.dispatch(scheduler) { + logReceived.trace {"dispatched:: signal `$location` ($rdid):: value = ${value.printToString()}"} signal.fire(value) } } diff --git a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdTask.kt b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdTask.kt index d9e196061..b7802d6d5 100644 --- a/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdTask.kt +++ b/rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdTask.kt @@ -426,8 +426,10 @@ class RdCall(internal val requestSzr: ISerializer = Polymorphi private fun onWireReceived(proto: IProtocol, ctx: SerializationCtx, buffer: AbstractBuffer, wiredRdTask: EndpointWiredRdTask, dispatchHelper: IRdWireableDispatchHelper) { val externalCancellation = wiredRdTask.lifetime val value = requestSzr.read(ctx, buffer) - logReceived.trace { "endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" } + logReceived.trace { "onWireReceived:: endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" } dispatchHelper.dispatch(handlerScheduler) { + logReceived.trace { "dispatch:: endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" } + val rdTask = try { val handlerLocal = handler if (handlerLocal == null) { diff --git a/rd-net/RdFramework/Impl/RdMap.cs b/rd-net/RdFramework/Impl/RdMap.cs index 67d297b1e..30d81c960 100644 --- a/rd-net/RdFramework/Impl/RdMap.cs +++ b/rd-net/RdFramework/Impl/RdMap.cs @@ -194,6 +194,13 @@ protected override void Unbind() myBindDefinitions = null; } + private static string getMessage(bool msgVersioned, long version, bool isPut, V? value) + { + return "{this} :: {kind} :: key = {key.PrintToString()}" + + (msgVersioned ? " :: version = " + version : "") + + (isPut ? $" :: value = {value.PrintToString()}" : ""); + } + public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, UnsafeReader stream, IRdWireableDispatchHelper dispatchHelper) { var header = stream.ReadInt(); @@ -237,14 +244,14 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf var isPut = kind is AddUpdateRemove.Add or AddUpdateRemove.Update; var value = isPut ? ReadValueDelegate(ctx, stream) : default; var definition = TryPreBindValue(lifetime, key, value, true); + + ReceiveTrace?.Log($"OnWireReceived:: {getMessage(msgVersioned, version, isPut, value)}"); dispatchHelper.Dispatch(() => { if (msgVersioned || !IsMaster || !IsPendingForAck(key)) { - ReceiveTrace?.Log($"{this} :: {kind} :: key = {key.PrintToString()}" + - (msgVersioned ? " :: version = " + version : "") + - (isPut ? $" :: value = {value.PrintToString()}" : "")); + ReceiveTrace?.Log($"Dispatched:: {getMessage(msgVersioned, version, isPut, value)}"); if (isPut) { @@ -271,7 +278,7 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf } else { - ReceiveTrace?.Log(">> CHANGE IGNORED"); + ReceiveTrace?.Log($">> CHANGE IGNORED {getMessage(msgVersioned, version, isPut, value)}"); } if (msgVersioned) diff --git a/rd-net/RdFramework/Impl/RdProperty.cs b/rd-net/RdFramework/Impl/RdProperty.cs index a9cfd7cb7..d3ac9226c 100644 --- a/rd-net/RdFramework/Impl/RdProperty.cs +++ b/rd-net/RdFramework/Impl/RdProperty.cs @@ -181,11 +181,13 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf var lifetime = dispatchHelper.Lifetime; var definition = TryPreBindValue(lifetime, value, true); + ReceiveTrace?.Log($"OnWireReceived:: {GetMessage(version, value)}"); + dispatchHelper.Dispatch(() => { var rejected = IsMaster && version < myMasterVersion; - ReceiveTrace?.Log($"{this} :: oldver = {myMasterVersion}, newver = {version}, value = {value.PrintToString()}{(rejected ? " REJECTED" : "")}"); + ReceiveTrace?.Log($"Dispatch:: {GetMessage(version, value)}{(rejected ? " REJECTED" : "")}"); if (rejected) { @@ -203,6 +205,11 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf }); } + private string GetMessage(int version, T value) + { + return $"{this} :: oldver = {myMasterVersion}, newver = {version}, value = {value.PrintToString()}"; + } + private LifetimeDefinition? TryPreBindValue(Lifetime lifetime, T value, bool bindAlso) { if (OptimizeNested || !value.IsBindable()) diff --git a/rd-net/RdFramework/Impl/RdSet.cs b/rd-net/RdFramework/Impl/RdSet.cs index b92a3d1a9..f7e82d96b 100644 --- a/rd-net/RdFramework/Impl/RdSet.cs +++ b/rd-net/RdFramework/Impl/RdSet.cs @@ -94,10 +94,11 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf { var kind = (AddRemove) stream.ReadInt(); var value = ReadValueDelegate(ctx, stream); - ReceiveTrace?.Log($"{this} :: {kind} :: {value.PrintToString()}"); + ReceiveTrace?.Log($"OnWireReceived:: {this} :: {kind} :: {value.PrintToString()}"); dispatchHelper.Dispatch(() => { + ReceiveTrace?.Log($"Dispatched:: {this} :: {kind} :: {value.PrintToString()}"); switch (kind) { case AddRemove.Add: diff --git a/rd-net/RdFramework/Impl/RdSignal.cs b/rd-net/RdFramework/Impl/RdSignal.cs index 7b51e72e9..537f9d27c 100644 --- a/rd-net/RdFramework/Impl/RdSignal.cs +++ b/rd-net/RdFramework/Impl/RdSignal.cs @@ -53,9 +53,10 @@ protected override void PreInit(Lifetime lifetime, IProtocol proto) public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, UnsafeReader reader, IRdWireableDispatchHelper dispatchHelper) { var value = ReadValueDelegate(ctx, reader); - ReceiveTrace?.Log($"{this} :: value = {value.PrintToString()}"); + ReceiveTrace?.Log($"OnWireReceived:: {this} :: value = {value.PrintToString()}"); dispatchHelper.Dispatch(Scheduler, () => { + ReceiveTrace?.Log($"Dispatched:: {this} :: value = {value.PrintToString()}"); mySignal.Fire(value); }); } diff --git a/rd-net/RdFramework/Tasks/RdCall.cs b/rd-net/RdFramework/Tasks/RdCall.cs index c219bcc8e..4de1ab633 100644 --- a/rd-net/RdFramework/Tasks/RdCall.cs +++ b/rd-net/RdFramework/Tasks/RdCall.cs @@ -88,10 +88,11 @@ private void OnWireReceived(SerializationCtx ctx, UnsafeReader reader, WiredRdTa { var externalCancellation = wiredTask.Lifetime; var value = ReadRequestDelegate(ctx, reader); - ReceiveTrace?.Log($"{wiredTask} :: received request: {value.PrintToString()}"); + ReceiveTrace?.Log($"OnWireReceived:: {wiredTask} :: received request: {value.PrintToString()}"); dispatchHelper.Dispatch(myHandlerScheduler, () => { + ReceiveTrace?.Log($"Dispatched:: {wiredTask} :: received request: {value.PrintToString()}"); var rdTask = RunHandler(value, externalCancellation, wiredTask); rdTask.Result.Advise(Lifetime.Eternal, result =>