使用 OpenTracing - Jaeger

前言

隨著系統逾來逾大、逾複雜，為了維運方便，可能會將這些拆分成不同的 Service 。
但從使用者一個 Request 進來後，從前端、後端各 Service 再到 Database，如果有效能問題時，大家要如何查找問題呢? SQL Profiler, Fiddler, 寫 Log ? 或是使用一些工具來查看效能問題，例如 Dynatrace ?
現在大家有另外一個好選擇，就是使用 OpenTracing , 在程式中加入一些 Tracing 的資料(使用 OpenTracing 訂的 api，再看您要使用那一個 Support OpenTracing 的 Tracer 去註冊它。
到時候就可以透過時間軸的角度來看到底那裡有效能問題，那裡有錯誤。

以下筆者將使用 JAEGER 來 Demo。

Why OpenTracing?

因為 OpenTracing 提供一個與平台無關，與廠商無關的 API，所以開發人員只要使用標準的 API，可以很輕易地更換不同的 追踪系統 ，只要它們都有 Support OpenTracing API。

安裝

因為JAEGER是 Cloud Native Computing Foundation(CNCF)，所以您可以透過 Docker 或是直接執行它的執行檔。

使用 Docker 執行 (Mac)

1
2
3
4
5
6
7
8
9
10
docker run -d --name jaeger \
  -e COLLECTOR_ZIPKIN_HTTP_PORT=9411 \
  -p 5775:5775/udp \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 14268:14268 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.8

要停止可以下

1
docker stop jaeger

要再啟動，就下

1
docker start jaeger

直接執行 (Windows)

將下載的 jaeger-1.8.0-windows-amd64.tar.gz 解壓縮到 jaeger-1.8.0-windows-amd64 目錄，然後在 Command 視窗中執行

1
jaeger-all-in-one --collector.zipkin.http-port=9411

然後開啟 Browser 輸入 http://localhost:16686 應該就可以看到 Jaeger UI ，如下，

  • 註: 其他平台也可以直接這樣執行哦 :)

使用

.net core (以 BFv4 為範例)

一開始加入 OpenTracing.Contrib.NetCore 及 Jaeger NuGet 套件，如下，

然後在 Startup.cs 中的 ConfigureServices 設定使用 OpenTracing ，如下，

1
2
3
4
5
6
7
8
9
10
11
12
13
//加入 OpenTracing
services.AddOpenTracing();
services.AddSingleton<ITracer>(serviceProvider =>
{
    string serviceName = "亂馬客BOT";
    var tracer = new Tracer.Builder(serviceName)
        .WithSampler(new ConstSampler(true))
        .Build();
    //註冊 Jaeger tracer
    GlobalTracer.Register(tracer);

    return tracer;
});

那要如何使用呢? 我們可以在 OnTurnAsync 時，從 GlobalTracer 取出 ITracer 來用。
請注意，這裡用的都是 OpenTracing 的 Interface ，所以將來如何要換別的 Tracer 就在 Startup.cs 中給別的 tracer 就可以了。
以下的 Code ，如果輸入 rainmaker 的話，就等個 10 秒再回，
如果輸入 rm 就會產生 Exception ，可以用 Tags.Error.Set(scope.Span, true) 來設定 error。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
public class Bot : IBot
{
    public async Task OnTurnAsync(ITurnContext turnContext, CancellationToken cancellationToken = default(CancellationToken))
    {
        //從 GlobalTracer.Instance 取出 Tracer
        var tracer = GlobalTracer.Instance;
        using (IScope scope = tracer.BuildSpan($"OnTurnAsync:{ActivityTypes.Message}").StartActive(finishSpanOnDispose: true))
        {
            if (turnContext.Activity.Type == ActivityTypes.Message)
            {
                var userInput = turnContext.Activity.Text;
                try
                {
                    using (var scopeMessage = tracer.BuildSpan(ActivityTypes.Message).StartActive(finishSpanOnDispose: true))
                    {
                        ProcessUserInput(userInput);
                        await turnContext.SendActivityAsync($"You said '{turnContext.Activity.Text}'");
                    }
                }
                catch (Exception ex)
                {
                    Tags.Error.Set(scope.Span, true);
                    tracer.ActiveSpan.Log(new Dictionary<string, object>
                    {
                        [LogFields.Event] = "error",
                        ["value"] = userInput,
                        ["error"] = ex.ToString()
                    });
                }
            }
        }
    }

    private void ProcessUserInput(string userInput)
    {
        var tracer = GlobalTracer.Instance;
        var eventName = "ProcessUserInput";
        using (var scope = tracer.BuildSpan(eventName).StartActive(finishSpanOnDispose: true))
        {
            tracer.ActiveSpan.Log(new Dictionary<string, object>
            {
                [LogFields.Event] = eventName,
                ["value"] = userInput
            });
            if (userInput == "rainmaker") Thread.Sleep(10000);
            if (userInput == "rm") throw new Exception("rm throw errrors!");
        }
    }
}

這時我們開啟 Emulator 來測試，分別輸入 hello, rainmaker, rm ，如下，

執行過後，我們可以透過 Jaeger UI http://localhost:16686，可以發現 Service 可以選到 亂馬客 BOT 了(在 Startup.cs 中設定的)，

按下 Find Traces Button 後，可以發現我們寫入的 Trace 資料，

這時我們可以點進花費時間 10 秒的 Trace ，可以發現在 ProcessUserInput 這個 Span 花了 10 秒的時間，如下，

點進 Error 的內容，可以查到錯誤的相關資訊，如下，

.net framework (以 BFv3 訂便當 Bot 為範例)

  • 建置 .net framework 的 Jaeger Client

    請到 jaeger-client-csharp 下載，並使用 VS.NET 2017 (因為它是 .net standard 2.0 專案)開啟來建置，建置完成後，就會在 src\Jaeger\bin\Debug\netstandard2.0 目錄中產生 Jaeger Client 的 DLL。

  • 專案中使用 (必需升到 .net 4.6.1 (含)以上版本)

    請先將專案升到 .net 4.6.1 (含)以上版本，並從 NuGet 套件中加入 OpenTracing, NETStandard.Library, Microsoft.Extensions.Logging.Abstractions(請跟 Jaeger Client 專案引用的版本相同，目前是 2.0.2)，如下圖，




加入 Jaeger Client 專案 src\Jaeger\bin\Debug\netstandard2.0 目錄中的 Jaeger.dll。

  • 專案中使用 OpenTracing

    在 Global.asax.cs 的 Application_Start 透過 Autofac 去設定使用的

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
protected void Application_Start()
{
    // Update Coversation Container
    Conversation.UpdateContainer(builder =>
    {
        // other ... BFv3 設定 Autofac ...
        // using Opentracing
        var tracer = new Tracer.Builder("亂馬客BOTBFv3")
						.WithSampler(new ConstSampler(true))
						.Build();
        GlobalTracer.Register(tracer);
        // using Opentracing
        // other ... BFv3 設定 Autofac ...
    });
    GlobalConfiguration.Configure(WebApiConfig.Register);
}

在 RootDialog 的 MessageReceivedAsync Method 中可以加入 Span ，如下，

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
private async Task MessageReceivedAsync(IDialogContext context, IAwaitable<IMessageActivity> result)
{
    var message = await result;
    var tracer = GlobalTracer.Instance;
    using (var tscope = tracer.BuildSpan("RootDialog").StartActive(finishSpanOnDispose: true))
    {

        // bot 原本的 code ...
        // Log 一些資訊
        tracer.ActiveSpan.Log(new Dictionary<string, object>
        {
            [LogFields.Event] = "MessageReceivedAsync",
            ["actionValue"] = message.Value?.ToString(),
            ["messageText"] = message.Text
        });
        // bot 原本的 code ...
    }
}

其他 Method 使用上也是一樣，都是從 GlobalTracer.Instance 取出 tracer，如下，

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
public async static Task DoActionAsync(BotAction botAction, IDialogContext context)
{
    var tracer = GlobalTracer.Instance;
    var eventName = "DoActionAsync";
    using (var childScope = tracer.BuildSpan(eventName).StartActive(finishSpanOnDispose: true))
    {
        // bot 原本的 code ...
        // Log 一些資訊
        tracer.ActiveSpan.Log(new Dictionary<string, object>
        {
            [LogFields.Event] = eventName,
            ["actionType"] = botAction.ActionType.ToString()
        });
        // bot 原本的 code ...
    }
}

在 Emulator 執行畫面為，

執行過後，我們可以透過 Jaeger UI http://localhost:16686，可以發現 Service 可以選到 亂馬客 BOTBFv3 了(在 Application_Start 中設定的)，

點進去可以發現各 Span 寫的 Log 及執行所花費的時間，如下，


結論

只要加入 OPENTRACING，再加入要使用的 Tracer Client 套件，就可以快速來記錄資訊，真的很簡單也很方便。當系統很多時，您就不需要苦苦地查找許多的 Log 檔。

參考資源

OPENTRACING
JAEGER
opentracing-tutorial
jaeger-client-csharp/examples/(含.net core 和 .net framework)
OpenTracing C#
dotnet/standard

  • 研究過程中，非常感謝同事 Marty 的討論與幫助。

tag:

    缺失模块。
    1、请确保node版本大于6.2
    2、在博客根目录（注意不是yilia根目录）执行以下命令：
    npm i hexo-generator-json-content --save

    3、在根目录_config.yml里添加配置： 

      jsonContent:
    meta: false
    pages: false
    posts:
      title: true
      date: true
      path: true
      text: false
      raw: false
      content: false
      slug: false
      updated: false
      comments: false
      link: false
      permalink: false
      excerpt: false
      categories: false
      tags: true

大家好，我是亂馬客 Rainmaker，目前任職於叡揚資訊，大家也都叫我 RM 。 平常負責開發公司各產品線的加值、共用的軟體，例如 Azure, OpenAI, Chatbot, Database ... 同時 Support 公司各種技術及資安修改問題。 Blog中的內容也是個人的看法， 如果有需要討論的地方， 可以留言，或是 mail 給我 :) rainmaker_ho@gss.com.tw