使用 OpenTracing - Jaeger (BFv3 使用 Fody)

前言

在前一篇 使用 OpenTracing - Jaeger (BFv3 使用 Dynamic Proxy) 中，我們透過 Dynamic Proxy 的方式去封裝那些需要記錄的物件。
雖然使用 Dynamic Proxy 的方式，可以讓我們將那些 OpenTracing 的範本程式碼抽離出來，但是在專案還是需要做一些調整，例如使用 Autofac, 修改 Method 為 virtual methods 。 這對於沒有使用 Dependency Injection 的系統來說，是一個負擔。 那是否可以做到像 dynaTrace 這樣，直接寫到 bytecode 之中呢?

研究

FODY

上網 Search 後，除了可以透過 .NET Profiling API 外，還可以透過 IL Rewriting 的方式，可以讓我們在 Compile 時，動態地把程式寫到我們註記的地方, 運作方式如下，

.NET Source Code => Compiler => Managed assembly(CIL) => Fody => CIL weaving => modified CIL
所以它會拿我們 Build 好的 DLL 去加程式碼後，再產出一個新的 DLL 蓋掉原本的。

FODY ADDINS

Fody 目前有蠻多的 FODY ADDINS，大家只要從 Nuget 加入它們，然後在 FodyWeavers.xml 中設定要用的 Addin ，再依 Addin 需要的 程式碼及在程式中加入 Addins 的 Attribute ，重新建置就可以了。
常用的有 ToString.Fody, NullGuard.Fody, PropertyChanged.Fody 及 Janitor.Fody。
大家可以看看 FODY ADDINS 中，有沒有想要用在專案之中的哦!
而針對 Opentracing 這樣子的行為，有看到 MethodBoundaryAspect.Fody 蠻適合拿來用的，所以我們就用它來實作。

使用 MethodBoundaryAspect.Fody

規劃流程

我們的 OpenTracing 的程式碼都是很固定的，所以可以將它們分別放到 MethodBoundaryAspect.Fody 中的 OnEntry, OnExit 及 OnException 這 3 個 Methods 之中。
再來就是要考量的是，如何接由 Bot Connector 傳進來的 Jaeger Http Header 資料。 所以可以在 Global.asax 的 Application_BeginRequest 中接收，然後指定給 Addin 屬性中的 static AsyncLocal 的變數，當然在 Call 外部 api 時，也要將目前的 ActiveSpan 放到 Http Header 之中。

實作

加入 OPENTRACING JAEGER CLIENT

這部份請參考 使用 OpenTracing - Jaeger - .NET FRAMEWORK (以 BFV3 訂便當 BOT 為範例) 區段的介紹，加入需要的 Nuget 套件及 Jaeger Client DLL 後，在 Globa.asax.cs 的 Application_Start Method 去註冊 Jaeger，如下，

// using Opentracing

var tracer = new Jaeger.Tracer.Builder("訂便當Bot")

    .WithSampler(new ConstSampler(true))

    .Build();



GlobalTracer.Register(tracer);

加入 MethodBoundaryAspect.Fody

從 Nuget 中加入 MethodBoundaryAspect.Fody ，

然後在 FodyWeavers.xml 中加入 MethodBoundaryAspect.Fody ，如下，

<?xml version="1.0" encoding="utf-8"?>
<Weavers xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:noNamespaceSchemaLocation="FodyWeavers.xsd"
         VerifyAssembly="true">
  <MethodBoundaryAspect />
</Weavers>

使用 VerifyAssembly=”true” 的原因是因為我們想要在插入 IL 時，檢查看看是否有錯誤，才不會在執行時發生System.InvalidProgramException: Common Language Runtime detected an invalid program.的錯誤訊息。

實作 OPENTRACINGLOGATTRIBUTE

繼承自 OnMethodBoundaryAspect ，在 OnEntry, OnExit 及 OnException 這 3 個 Methods 之中寫入 Opentracing 的程式碼，其中包含 async 的處理，如下，

public class OpenTracingLogAttribute : OnMethodBoundaryAspect
{
    //接由外部 service 傳入的 Header 資料
    public static AsyncLocal<Dictionary<string, string>> TracerHttpHeaders =
        new AsyncLocal<Dictionary<string, string>>();

    /// <summary>
    /// 判斷是否要 Log 到 OpenTracing 之中
    /// </summary>
    /// <param name="operationName"></param>
    /// <returns></returns>
    /// <remarks>
    /// 有些 async 的Method 並不想要記錄，所以在此判斷
    /// </remarks>
    private bool IsNeedLog(string operationName)
    {

        string[] ignoreMethodNames = new string[]
        {
            "SetStateMachine.<",
            "MoveNext.<"
        };
        var result = !ignoreMethodNames.Any(ig => operationName.StartsWith(ig));
        return result;
    }


    public override void OnEntry(MethodExecutionArgs args)
    {
        if (!GlobalTracer.IsRegistered()) return;
        var operationName = $"{args.Method.Name}.{args.Method.ReflectedType.Name}";
        if (!IsNeedLog(operationName)) return;

        var tracer = GlobalTracer.Instance;
        var spanBuilder = tracer.BuildSpan(operationName);
        if (tracer.ActiveSpan != null)
        {
            spanBuilder.AsChildOf(tracer.ActiveSpan);
        }
        else if (TracerHttpHeaders.Value != null)
        {
            // check http
            var parentSpanCtx = tracer.Extract(BuiltinFormats.HttpHeaders, new TextMapExtractAdapter(TracerHttpHeaders.Value));
            spanBuilder.AsChildOf(parentSpanCtx);
        }
        var activeScope = spanBuilder.StartActive(true);
        args.MethodExecutionTag = activeScope;

    }

    public override void OnExit(MethodExecutionArgs args)
    {
        if (!GlobalTracer.IsRegistered()) return;
        var operationName = $"{args.Method.Name}.{args.Method.ReflectedType.Name}";
        if (!IsNeedLog(operationName)) return;

        var returnTask = args.ReturnValue as Task;
        if (returnTask != null)
        {
            //async 要加在後面
            returnTask.ContinueWith(task => LogOnExit(args));
        }
        else
        {
            LogOnExit(args);
        }

    }

    public override void OnException(MethodExecutionArgs args)
    {
        if (!GlobalTracer.IsRegistered()) return;
        var operationName = $"{args.Method.Name}.{args.Method.ReflectedType.Name}";
        if (!IsNeedLog(operationName)) return;

        var returnTask = args.ReturnValue as Task;
        //如果是 Task 在 OnExit 中處理
        if (returnTask == null)
        {
            //這裡處理同步的部份
            var activeScope = args.MethodExecutionTag as IScope;
            Tags.Error.Set(activeScope.Span, true);
            activeScope.Span.Log(new Dictionary<string, object> { ["error"] = args.Exception.ToString() });
            activeScope.Dispose();
        }

    }

    private void LogOnExit(MethodExecutionArgs args)
    {
        var activeScope = args.MethodExecutionTag as IScope;
        var operationName = $"{args.Method.Name}.{args.Method.ReflectedType.Name}";
        var returnTask = args.ReturnValue as Task;
        if (returnTask != null && returnTask.IsFaulted)
        {
            //exception for async
            Tags.Error.Set(activeScope.Span, true);
            var exIndex = 0;
            foreach (var ex in returnTask.Exception.InnerExceptions)
            {
                activeScope.Span.Log(new Dictionary<string, object> { [$"error{exIndex++}"] = ex.ToString() });
            }
        }
        activeScope.Dispose();

    }
}

接收外部傳入的 JAEGER HTTP HEADER

在 Global.asax.cs 中 Application_BeginRequest 中加入取得 Jaeger Http Header 然後指定給 OpenTracingLogAttribute 的 TracerHttpHeaders 屬性，如下，

protected void Application_BeginRequest(object sender, EventArgs e)
{
    //處理外部送進來的 opentracing data
    var headerDict = new Dictionary<string, string>();
    var headers = base.Context.Request.Headers;
    foreach (var k in headers.AllKeys)
    {
        headerDict.Add(k, headers[k]);
    }
    if (headerDict.Count > 0)
    {
        OpenTracingLogAttribute.TracerHttpHeaders.Value = headerDict;
    }
    else
    {
        OpenTracingLogAttribute.TracerHttpHeaders.Value = null;
    }
}

呼叫外部 SERVICE 加入 JAEGER HTTP HEADER

我們要在呼叫 外部 Service 地方，加入 Jaeger Http Header，所以建議在生成 httpClient 時，可以統一由 Factory 來生成，如下，

//add opentracing
if (GlobalTracer.IsRegistered())
{
    var tracer = GlobalTracer.Instance;
    var dictionary = new Dictionary<string, string>();
    var span = tracer.ActiveSpan;
    if (span != null)
    {
        tracer.Inject(span.Context, BuiltinFormats.HttpHeaders, new TextMapInjectAdapter(dictionary));
        foreach (var entry in dictionary)
            HttpClient.DefaultRequestHeaders.Add(entry.Key, entry.Value);
    }
}

在需要記錄的 CLASS 中設定 OPENTRACINGLOG 屬性

所以我們可以在 MessagesController, RootDialog 及需要記錄的 Class or Method 加入 [OpenTracingLog] 屬性就可以了 。

測試

當順利在 Class 或 Method 上加入 [OpenTracingLog] 屬性後，就可以把 Jaeger 開起來，並執行程式跑看看，我一樣使用 訂便當 BOT 來測試。
執行後，可以順利從 Jaeger Search UI 中看到從 Bot Connector => Bot => Bot Connector 都串起來了，如下，

• 註 1: 除了加在 Class or Method 上，也可以針對整個 Assembly 去設定，可以在 AssemblyInfo.cs 中設定，它會加入到 public method & properties 之中，如下，

• 註 2: 目前 MethodBoundaryAspect.Fody 只 Support 整個 assembly, class 、 methods 及屬性，還不 Support 一些 Filters。
• 註 3: PEVerify of the assembly failed. jmp / exception into the middle of an instruction.
  如果在建置過程中有出現上面的 PEVerify 錯誤，請查看一下那個 Method 是不是為 async ，在最後少了 await Task.CompletedTask; 或是 return await Task.FromResult(null); 。
  我的狀況是因為有 if { … await } else { … await } 而它無法正確地找到對的地方把程式碼放進去。錯誤訊息為，

Error Fody: PEVerify of the assembly failed.
[IL]: Error: [xxx.dll : EasyLifeBot.Actions.AccountActionStrategy+d__3::\$_executor_MoveNext][offset 0x000001d7] jmp / exception into the middle of an instruction.(Error: 0x80131847)

• 註 4:一開始建議是先加在入口的地方，有需要再往後加。
• 註 5: MethodBoundaryAspect.Fody使用上如果不是很順手的話，也可以參考使用 PostSharp試看看。

雖然還是要寫一點點程式碼及設定，但是往自動化又進步了一些哦:)

參考資料

Fody
MethodBoundaryAspect.Fody
DynamicProxy
List of .Net Profilers: 3 Different Types and Why You Need All of Them
.NET Profilers and IL Rewriting - DDD Melbourne 2
Monitoring and Observability in the .NET Runtime
How to mock sealed classes and static methods
.NET Profiling API
PostSharp