Skip to content

Commit b3e1a4c

Browse files
Iliya-usovIliya-usov
authored
Merge pull request #449 from JetBrains/trace-messages-usov
Improve logging
2 parents 63d16a6 + e4c1568 commit b3e1a4c

File tree

12 files changed

+45
-16
lines changed

12 files changed

+45
-16
lines changed

‎rd-kt/rd-core/src/main/kotlin/com/jetbrains/rd/util/threading/coroutines/RdCoroutineScope.kt

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -24,10 +24,10 @@ open class RdCoroutineScope : CoroutineScope {
2424
if (!currentHost.compareAndSet(null, host))
2525
throw IllegalStateException("Could not override RdCoroutineHost")
2626

27-
logger.debug { "RdCoroutineHost has been overridden" }
27+
logger.trace { "RdCoroutineHost has been overridden" }
2828
host.coroutineContext.job.invokeOnCompletion {
2929
currentHost.getAndSet(null)
30-
logger.debug { "RdCoroutineHost has been reset" }
30+
logger.trace { "RdCoroutineHost has been reset" }
3131
}
3232
}
3333
}

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/Interfaces.kt

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -98,7 +98,7 @@ interface IMarshaller<T : Any> : ISerializer<T> {
9898
}
9999

100100
val IMarshaller<*>.fqn: String get() {
101-
return if (this is LazyCompanionMarshaller) this.fgn
101+
return if (this is LazyCompanionMarshaller) this.fqn
102102
else _type.qualifiedName ?: _type.jvmName
103103
}
104104

@@ -108,7 +108,7 @@ class LazyCompanionMarshaller<T : Any>(
108108
val fqn: String
109109
) : IMarshaller<T> {
110110
private val lazy = lazy(LazyThreadSafetyMode.PUBLICATION) {
111-
Class.forName(fgn, true, classLoader).getDeclaredField("Companion").get(null) as IMarshaller<T>
111+
Class.forName(fqn, true, classLoader).getDeclaredField("Companion").get(null) as IMarshaller<T>
112112
}
113113

114114
override val _type: KClass<*>

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdMap.kt

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -194,9 +194,11 @@ open class RdMap<K : Any, V : Any> private constructor(
194194
val lifetime = dispatchHelper.lifetime
195195
val definition = tryPreBindValue(lifetime, key, value, true)
196196

197+
logReceived.trace { "onWireReceived:: ${logmsg(op, version, key, value)}" }
198+
197199
dispatchHelper.dispatch {
198200
if (msgVersioned || !master || !isPendingForAck(key)) {
199-
logReceived.trace { logmsg(op, version, key, value) }
201+
logReceived.trace { "dispatched:: ${logmsg(op, version, key, value)}" }
200202

201203
if (value != null) {
202204
val definitions = tryGetBindDefinitions(lifetime)

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdProperty.kt

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -107,9 +107,11 @@ abstract class RdPropertyBase<T>(val valueSerializer: ISerializer<T>) : RdReacti
107107

108108
val definition = tryPreBindValue(dispatchHelper.lifetime, v, true)
109109

110+
logReceived.trace { "onWireReceived:: ${getMessage(version, v)}" }
111+
110112
dispatchHelper.dispatch {
111113
val rejected = master && version < masterVersion
112-
logReceived.trace { "property `$location` ($rdid):: oldver = $masterVersion, newver = $version, value = ${v.printToString()}${rejected.condstr { " >> REJECTED" }}" }
114+
logReceived.trace { "dispatched:: ${getMessage(version, v)}${rejected.condstr { " >> REJECTED" }}" }
113115

114116
if (rejected) {
115117
definition?.terminate()
@@ -124,6 +126,9 @@ abstract class RdPropertyBase<T>(val valueSerializer: ISerializer<T>) : RdReacti
124126
}
125127
}
126128

129+
private fun getMessage(version: Int, v: T) =
130+
"property `$location` ($rdid):: oldver = $masterVersion, newver = $version, value = ${v.printToString()}"
131+
127132
override fun advise(lifetime: Lifetime, handler: (T) -> Unit) {
128133
if (isBound) assertThreading()
129134
property.advise(lifetime, handler)

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSet.kt

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -55,7 +55,9 @@ open class RdSet<T : Any> constructor(val valueSerializer: ISerializer<T>, priva
5555
val kind = buffer.readEnum<AddRemove>()
5656
val v = valueSerializer.read(ctx, buffer)
5757

58+
logReceived.trace { "onWireReceived:: $this :: $kind :: ${v.printToString()}" }
5859
dispatchHelper.dispatch {
60+
logReceived.trace { "dispatched:: $this :: $kind :: ${v.printToString()}" }
5961
when (kind) {
6062
AddRemove.Add -> set.add(v)
6163
AddRemove.Remove -> set.remove(v)

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdSignal.kt

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -27,8 +27,9 @@ class RdSignal<T>(val valueSerializer: ISerializer<T> = Polymorphic<T>()) : RdRe
2727

2828
override fun onWireReceived(proto: IProtocol, buffer: AbstractBuffer, ctx: SerializationCtx, dispatchHelper: IRdWireableDispatchHelper) {
2929
val value = valueSerializer.read(ctx, buffer)
30-
logReceived.trace {"signal `$location` ($rdid):: value = ${value.printToString()}"}
30+
logReceived.trace {"onWireReceived:: signal `$location` ($rdid):: value = ${value.printToString()}"}
3131
dispatchHelper.dispatch(scheduler) {
32+
logReceived.trace {"dispatched:: signal `$location` ($rdid):: value = ${value.printToString()}"}
3233
signal.fire(value)
3334
}
3435
}

‎rd-kt/rd-framework/src/main/kotlin/com/jetbrains/rd/framework/impl/RdTask.kt

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -426,8 +426,10 @@ class RdCall<TReq, TRes>(internal val requestSzr: ISerializer<TReq> = Polymorphi
426426
private fun onWireReceived(proto: IProtocol, ctx: SerializationCtx, buffer: AbstractBuffer, wiredRdTask: EndpointWiredRdTask<TReq, TRes>, dispatchHelper: IRdWireableDispatchHelper) {
427427
val externalCancellation = wiredRdTask.lifetime
428428
val value = requestSzr.read(ctx, buffer)
429-
logReceived.trace { "endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" }
429+
logReceived.trace { "onWireReceived:: endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" }
430430
dispatchHelper.dispatch(handlerScheduler) {
431+
logReceived.trace { "dispatch:: endpoint `$location`::($rdid) taskId=(${wiredRdTask.rdid}) request = ${value.printToString()}" }
432+
431433
val rdTask = try {
432434
val handlerLocal = handler
433435
if (handlerLocal == null) {

‎rd-net/RdFramework/Impl/RdMap.cs

Lines changed: 11 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -194,6 +194,13 @@ protected override void Unbind()
194194
myBindDefinitions = null;
195195
}
196196

197+
private static string getMessage(bool msgVersioned, long version, bool isPut, V? value)
198+
{
199+
return "{this} :: {kind} :: key = {key.PrintToString()}" +
200+
(msgVersioned ? " :: version = " + version : "") +
201+
(isPut ? $" :: value = {value.PrintToString()}" : "");
202+
}
203+
197204
public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, UnsafeReader stream, IRdWireableDispatchHelper dispatchHelper)
198205
{
199206
var header = stream.ReadInt();
@@ -237,14 +244,14 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf
237244
var isPut = kind is AddUpdateRemove.Add or AddUpdateRemove.Update;
238245
var value = isPut ? ReadValueDelegate(ctx, stream) : default;
239246
var definition = TryPreBindValue(lifetime, key, value, true);
247+
248+
ReceiveTrace?.Log($"OnWireReceived:: {getMessage(msgVersioned, version, isPut, value)}");
240249

241250
dispatchHelper.Dispatch(() =>
242251
{
243252
if (msgVersioned || !IsMaster || !IsPendingForAck(key))
244253
{
245-
ReceiveTrace?.Log($"{this} :: {kind} :: key = {key.PrintToString()}" +
246-
(msgVersioned ? " :: version = " + version : "") +
247-
(isPut ? $" :: value = {value.PrintToString()}" : ""));
254+
ReceiveTrace?.Log($"Dispatched:: {getMessage(msgVersioned, version, isPut, value)}");
248255

249256
if (isPut)
250257
{
@@ -271,7 +278,7 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf
271278
}
272279
else
273280
{
274-
ReceiveTrace?.Log(">> CHANGE IGNORED");
281+
ReceiveTrace?.Log($">> CHANGE IGNORED {getMessage(msgVersioned, version, isPut, value)}");
275282
}
276283

277284
if (msgVersioned)

‎rd-net/RdFramework/Impl/RdProperty.cs

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -181,11 +181,13 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf
181181
var lifetime = dispatchHelper.Lifetime;
182182
var definition = TryPreBindValue(lifetime, value, true);
183183

184+
ReceiveTrace?.Log($"OnWireReceived:: {GetMessage(version, value)}");
185+
184186
dispatchHelper.Dispatch(() =>
185187
{
186188
var rejected = IsMaster && version < myMasterVersion;
187189

188-
ReceiveTrace?.Log($"{this} :: oldver = {myMasterVersion}, newver = {version}, value = {value.PrintToString()}{(rejected ? " REJECTED" : "")}");
190+
ReceiveTrace?.Log($"Dispatch:: {GetMessage(version, value)}{(rejected ? " REJECTED" : "")}");
189191

190192
if (rejected)
191193
{
@@ -203,6 +205,11 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf
203205
});
204206
}
205207

208+
private string GetMessage(int version, T value)
209+
{
210+
return $"{this} :: oldver = {myMasterVersion}, newver = {version}, value = {value.PrintToString()}";
211+
}
212+
206213
private LifetimeDefinition? TryPreBindValue(Lifetime lifetime, T value, bool bindAlso)
207214
{
208215
if (OptimizeNested || !value.IsBindable())

‎rd-net/RdFramework/Impl/RdSet.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -94,10 +94,11 @@ public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, Unsaf
9494
{
9595
var kind = (AddRemove) stream.ReadInt();
9696
var value = ReadValueDelegate(ctx, stream);
97-
ReceiveTrace?.Log($"{this} :: {kind} :: {value.PrintToString()}");
97+
ReceiveTrace?.Log($"OnWireReceived:: {this} :: {kind} :: {value.PrintToString()}");
9898

9999
dispatchHelper.Dispatch(() =>
100100
{
101+
ReceiveTrace?.Log($"Dispatched:: {this} :: {kind} :: {value.PrintToString()}");
101102
switch (kind)
102103
{
103104
case AddRemove.Add:

‎rd-net/RdFramework/Impl/RdSignal.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -53,9 +53,10 @@ protected override void PreInit(Lifetime lifetime, IProtocol proto)
5353
public override void OnWireReceived(IProtocol proto, SerializationCtx ctx, UnsafeReader reader, IRdWireableDispatchHelper dispatchHelper)
5454
{
5555
var value = ReadValueDelegate(ctx, reader);
56-
ReceiveTrace?.Log($"{this} :: value = {value.PrintToString()}");
56+
ReceiveTrace?.Log($"OnWireReceived:: {this} :: value = {value.PrintToString()}");
5757
dispatchHelper.Dispatch(Scheduler, () =>
5858
{
59+
ReceiveTrace?.Log($"Dispatched:: {this} :: value = {value.PrintToString()}");
5960
mySignal.Fire(value);
6061
});
6162
}

‎rd-net/RdFramework/Tasks/RdCall.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -88,10 +88,11 @@ private void OnWireReceived(SerializationCtx ctx, UnsafeReader reader, WiredRdTa
8888
{
8989
var externalCancellation = wiredTask.Lifetime;
9090
var value = ReadRequestDelegate(ctx, reader);
91-
ReceiveTrace?.Log($"{wiredTask} :: received request: {value.PrintToString()}");
91+
ReceiveTrace?.Log($"OnWireReceived:: {wiredTask} :: received request: {value.PrintToString()}");
9292

9393
dispatchHelper.Dispatch(myHandlerScheduler, () =>
9494
{
95+
ReceiveTrace?.Log($"Dispatched:: {wiredTask} :: received request: {value.PrintToString()}");
9596
var rdTask = RunHandler(value, externalCancellation, wiredTask);
9697

9798
rdTask.Result.Advise(Lifetime.Eternal, result =>

0 commit comments

Comments
 (0)