Actor Method Start/Stop log | Add additional Infor

2020-04-20 12:22发布

问题:

For azure actor services, Actor Method Start Stop logs in Diagnostics window, which looks like below.

How can i add some additional detail such as a Correlation Id every time a method is called ?

{
  "Timestamp": "2016-09-14T19:46:40.9955448+05:30",
  "ProviderName": "Microsoft-ServiceFabric-Actors",
  "Id": 7,
  "Message": "Actor method is being invoked. Method name: IStore.GetStoreById, actor type: Backend.Actor.Store.Store, actor ID: STORE_6.",
  "ProcessId": 30736,
  "Level": "Verbose",
  "Keywords": "0x0000F00000000002",
  "EventName": "ActorMethod/Start",
  "Payload": {
    "methodName": "IStore.GetStoreById",
    "methodSignature": "System.Threading.Tasks.Task`1[Backend.Models.Store.StoreView] GetStoreById(System.String)",
    "actorType": "Backend.Actor.Store.Store",
    "actorId": "STORE_6",
    "actorIdKind": 2,
    "replicaOrInstanceId": 131183360004211655,
    "partitionId": "8af1c125-3666-40d0-b630-e3570c41833b",
    "serviceName": "fabric:/MultiBannerBackend/StoreActorService",
    "applicationName": "fabric:/MultiBannerBackend",
    "serviceTypeName": "StoreActorServiceType",
    "applicationTypeName": "MultiBannerBackendType",
    "nodeName": "_Node_4"
  }
}

回答1:

In order to log custom data for every Actor operation, you can use these methods:

protected override Task OnPreActorMethodAsync(ActorMethodContext c)
protected override Task OnPostActorMethodAsync(ActorMethodContext c)

In order to get the call context, I've found that CallContext.LogicalGetData doesn't work in this situation. The Actor itself fortunately does know about its context. You can get it using some reflection.

For example:

protected override Task OnPreActorMethodAsync(ActorMethodContext c)
        {
            var correlationID = this.GetActorContext() ?? Guid.Empty.ToString("N");
            string message = $"Actor method is being invoked. Method name: {c.MethodName}, actor type: {GetType().FullName}, actor ID: {Id}, CorrelationID:{correlationID}";
            ActorEventSource.Current.ActorMessage(this, message);
            return Task.FromResult(true);
        }

        protected override Task OnPostActorMethodAsync(ActorMethodContext c)
        {
            var correlationID = this.GetActorContext() ?? Guid.Empty.ToString("N");
            string message = $"Actor method has completed. Method name: {c.MethodName}, actor type: {GetType().FullName}, actor ID: {Id}, CorrelationID:{correlationID}";
            ActorEventSource.Current.ActorMessage(this, message);
            return Task.FromResult(true);
        }

Combined with:

public static class ActorContextExtensions
    {
        public static string GetActorContext(this Actor actor)
        {
            var concurrencyLockProperty = GetPropertyInfo("ConcurrencyLock", typeof(ActorBase));
            var concurrencyLockPropertyValue = concurrencyLockProperty.GetValue(actor);

            var currentContextProperty = GetPropertyInfo("Test_CurrentContext", concurrencyLockPropertyValue.GetType());
            string currentContextPropertyValue = (string)currentContextProperty.GetValue(concurrencyLockPropertyValue);
            return currentContextPropertyValue;
        }

        private static PropertyInfo GetPropertyInfo(string propertyName, IReflect owner)
        {
            var property = owner.GetProperty(propertyName, BindingFlags.NonPublic | BindingFlags.Instance);
            if (property == null) throw new InvalidOperationException($"Failed to find property '{propertyName}' on '{owner}'.");
            return property;
        }
    }

Obvious downside of this, is whenever the internals of ActorBase change, you'll need to change your reflection code accordingly.