日誌系統實戰(三)-分佈式跟蹤的Net實現

時間 2019-11-26

標籤日誌系統實戰分佈式跟蹤實現欄目系統架構简体版

原文原文鏈接

介紹

在大型系統開發調試中，跨系統之間聯調開始變得很差使了。莫名其妙一個錯誤爆出來了，日誌雖然有記錄，但究竟是哪裏出問題了呢？前端

是Ios端參數傳的不對？仍是A系統或B系統提供的接口致使？相信有很多人遇到這種狀況，大多數問題每每不大，但排查起來比較費勁。程序員

下面介紹下怎麼經過上下文跟蹤的方法，最快定位到其問題。web

閱讀目錄：

概述

簡單介紹就是，經過一個TraceId把整個業務請求邏輯相關聯起來，根據時間順序造成一個完整的調用鏈。sql

這樣不管任何地方報錯，只要拿TraceId去日誌系統簡查下，根據上下文的順序就知道是哪一步、哪一個函數、哪一個參數出錯了，能以最快速度定位處理BUG。mongodb

如圖以博客園爲例。當博客園收到一個請求後，自動爲生產個惟一ID 1000，以後全部處理工做都是用這個1000。數據庫

每一個處理模塊都維持一個上下文ID自增，rpcid++。安全

其處理模塊能夠是函數級，邏輯層級，服務器級等均可以。服務器

一旦發現有異常後，自動將TraceId發給博客園。這樣程序員們，就能根據TraceId最快定位問題了。網絡

關於各類環境下具體的代碼實現：多線程

web環境

定義跟蹤日誌須要的參數，進行上下文傳遞。

   public class LogBody
    {
        /// <summary>
        /// 跟蹤ID
        /// </summary>
        public string TraceId { get; set; }
        /// <summary>
        /// 上下文ID
        /// </summary>
        public int RpcId { get; set; }
        /// <summary>
        /// 處理時間
        /// </summary>
        public DateTime LastTime { get; set; }
    }

在global.asax全局Application_BeginRequest函數中，使用HttpContext.Current上下文，開始進行埋點(跟蹤)，設置rpc 0。

   void Application_BeginRequest(object sender, EventArgs e)
        {
            var lb = new LogBody();
            lb.TraceId = Guid.NewGuid().ToString("N");
            lb.RpcId=0;
            lb.LastTime = DateTime.Now;
            HttpContext.Current.Response.AppendHeader("traceID", lb.TraceId);
            HttpContext.Current.Items.Add(lb.TraceId, lb);
            //記錄日誌，例：用戶請求參數，userAgent等。
        }

在default頁開始業務邏輯，設置rpc 1。

 protected void Page_Load(object sender, EventArgs e)
        {
            var traceID = HttpContext.Current.Response.Headers["traceID"];
            LogBody logbody = HttpContext.Current.Items[traceID] as LogBody;
            logbody.RpcId++;
            logbody.LastTime = DateTime.Now;
            //業務邏輯。
            //記錄日誌。。。
        }

如上就完成上下文的傳遞。

Application_BeginRequest 中在實際使用中，只須要對有用的頁面(例:aspx，ashx)進行埋點。

日誌記錄的時候，能夠把logbody都存儲起來。

存儲到Headers可讓前端經過JS也能拿到TraceId，方便去排查問題。

LastTime這個字段，能夠與上一次的相減，這樣就得出中間邏輯處理所花費的時間了。

多線程環境

在web程序中能夠用httpcontext的上下文傳遞。

在單線程的程序中,按照線性順序便可。

多線程中利用用threadlocal傳遞。

  public static ThreadLocal<LogBody> Body = new ThreadLocal<LogBody>();
        static void Main(string[] args)
        {
            var t1 = new Thread(() =>
            {
                Body.Value = new LogBody()
                {
                    LastTime = DateTime.Now,
                    RpcId = 0,
                    TraceId = Guid.NewGuid().ToString("N")
                };
                //業務1
                Console.WriteLine("Thread1 log record:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);

                Thread.Sleep(5000);

                Body.Value.RpcId++;
                Body.Value.LastTime = DateTime.Now;
                //業務2
                Console.WriteLine("Thread1 log record:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);
            });
            t1.Start();

            var t2 = new Thread(() =>
            {
                Body.Value = new LogBody()
                {
                    LastTime = DateTime.Now,
                    RpcId = 0,
                    TraceId = Guid.NewGuid().ToString("N")
                };
                //業務1
                Console.WriteLine("Thread2 log record:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);

                Thread.Sleep(5000);
                Body.Value.RpcId++;
                Body.Value.LastTime = DateTime.Now;
                //業務2
                Console.WriteLine("Thread2 log record:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);
            });
            t2.Start();
        }

運行以下：

異步環境

每每在生產環境中，會有大量的異步操做。若是有異步行爲的話，打亂上下文怎麼辦？這時候須要引入另一個概念，父節點Id。

這樣異步操做的行爲就父節點之下，最終在日誌後臺展現的是一個倒着的樹形結構。

如圖能夠看到業務2異步派生出來的子節點。

把上下文rpcid修改爲double類型。

 static void Main(string[] args)
        {
            var t2 = new Thread(() =>
            {
                Body.Value = new LogBody()
                {
                    LastTime = DateTime.Now,
                    RpcId = 1,
                    TraceId = Guid.NewGuid().ToString("N")
                };
                var t1 = new Thread((lb) =>
                {
                    var temp = lb as LogBody;
                    Body.Value = new LogBody()
                    {
                        LastTime = DateTime.Now,
                        RpcId = temp.RpcId,
                        TraceId = temp.TraceId
                    };
                    Body.Value.RpcId += 0.1;
                    //業務x
                    Console.WriteLine("async Thread:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime );

                    Thread.Sleep(5000);

                    Body.Value.RpcId+=0.1;
                    Body.Value.LastTime = DateTime.Now;
                    //業務y
                    Console.WriteLine("async Thread:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);
                });
                t1.Start(Body.Value);


                //業務1
                Console.WriteLine("sync Thread:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);

                Thread.Sleep(2000);
                Body.Value.RpcId+=1;
                Body.Value.LastTime = DateTime.Now;
                //業務2
                Console.WriteLine("sync Thread:" + Body.Value.TraceId + "-" + Body.Value.RpcId + "-" + Body.Value.LastTime);
            });
            t2.Start();
        }

代碼中用參數傳遞給了異步線程中，運行以下：