Wcf通訊基礎架構方案（四）——橫切日誌

在第一篇文章中已經列出了幾種日誌的概覽：

所有的日誌都有一個最終基類，來看看這個類：

[DataContract(Namespace = "WcfExtension")]    [KnownType(typeof(WcfExceptionInfo))]    [KnownType(typeof(ServerExceptionInfo))]    [KnownType(typeof(ClientExceptionInfo))]    [KnownType(typeof(WcfInvokeInfo))]    [KnownType(typeof(ServerInvokeInfo))]    [KnownType(typeof(ClientInvokeInfo))]    [KnownType(typeof(WcfMessageInfo))]    [KnownType(typeof(ServerMessageInfo))]    [KnownType(typeof(ClientMessageInfo))]    [KnownType(typeof(StartInfo))]    [KnownType(typeof(ServerStartInfo))]    [KnownType(typeof(ClientStartInfo))]    public abstract class AbstractLogInfo    {        [DataMember]        [PersistenceColumn(IsIndex = true)]        public string ID { get; set; }        [DataMember]        [PersistenceColumn(IsIndex = true)]        public string RequestIdentity { get; set; }        [DataMember]        [PersistenceColumn(IsIndex = true)]        public DateTime Time { get; set; }        [DataMember]        [PersistenceColumn(IsIndex = true)]        public string MachineName { get; set; }        [DataMember]        [PersistenceColumn(IsIndex = true)]        public string MachineIP { get; set; }        [DataMember]        public string ExtraInfo { get; set; }        public override string ToString()        {            StringBuilder sb = new StringBuilder();            this.GetType().GetProperties().ToList().ForEach(p =>            {                var o = p.GetValue(this, null);                sb.AppendLine(p.Name + ": " + o);                if (o is Dictionary<string, string>)                {                    var dic = o as Dictionary<string, string>;                    foreach (var key in dic)                    {                        sb.AppendLine(" " + key.Key + ": " + key.Value);                    }                }            });            return sb.ToString();        }    }

值得關注的幾點：

1） 這裡的日誌我們會儲存在Mongodb中，會有一些Attribute告訴Log Service端，欄位是否需要做索引，是否需要分庫等等。

2） 每一條日誌都會有一個GUID作為ID，這個沒什麼特別的。但要注意一點，如果服務端執行方法出現異常的話，會把異常ID在Message裡面返回給用戶端。這個異常ID也就是這條異常日誌的ID。用戶端只能收到有關服務端異常的Message而不會收到更多的堆棧等資訊。原因兩個，一減少Fault訊息大小，二用戶端也不應該知道這麼多服務端的資訊，用戶端也不一定能理解服務端的異常，服務端有自己的異常日誌。

3） 每一條日誌都會有一個RequestIdentity，這是一個請求的上下文關聯欄位。從用戶端發出請求開始，到服務端處理，再到用戶端接收到服務端的反饋訊息。其中所有的調用日誌、異常日誌和訊息日誌都會有相同的RequestIdentity。也就是說在後台通過這個RequestIdentity可以查詢到一條一種類型的日誌關聯的整個請求過程中的其它日誌。打個比方，如果在查看用戶端執行日誌的時候探索方法執行失敗，那麼直接可以查看到對應的服務端失敗的那條執行日誌，以及服務端對應的那個異常日誌和用戶端對應的異常的日誌，如果開啟訊息日誌的話，還可以查到對應的用戶端和服務端收發的訊息。

4） 每條日誌都會有機器名和機器IP地址，以及時間。ExtraInfo存的是一些其它資訊，在這裡我存的是記錄這個日誌的方法名稱。

每一種類型的日誌都會有服務端日誌和用戶端日誌兩種，分別實現兩個介面：

internal interface IServerInfo

{

    string ServiceName { get; set; }

}

internal interface IClientInfo

{

    string ClientTypeName { get; set; }

    string ContractName { get; set; }

}

我認為，服務端日誌需要關注服務的類型，而用戶端日誌關注的是契約的類型，以及調用這個契約所在的類（比如某個頁面的類型名），這樣可以方便定位問題。因為服務的實現位置相對固定，而調用服務介面的地方就五花八門了。

再來看看其它集中日誌類型增加了哪些東西：

    [DataContract(Namespace = "WcfExtension")]    public abstract class WcfExceptionInfo : AbstractLogInfo    {        [DataMember]        [PersistenceColumn(IsIndex = true)]        public string Type { get; set; }        [DataMember]        public string Message { get; set; }        [DataMember]        public string StackTrace { get; set; }    }

異常日誌記錄異常類型、異常訊息和堆棧。

    [DataContract(Namespace = "WcfExtension")]    public abstract class WcfMessageInfo : AbstractLogInfo    {        [DataMember]        public MessageDirection MessageDirection { get; set; }        [DataMember]        public string Message { get; set; }    }}

訊息日誌記錄完整的訊息以及訊息的方向。

    [DataContract(Namespace = "WcfExtension")]    [KnownType(typeof(ApplicationContext))]    public abstract class WcfInvokeInfo : AbstractLogInfo    {        [DataMember]        public long ExecutionTime { get; set; }        [DataMember]        public bool IsSuccessuful { get; set; }        [DataMember]        public string MethodName { get; set; }        [DataMember]        public ApplicationContext ApplicationContext { get; set; }    }

調用訊息記錄方法名、執行方法是否成功、執行時間以及一些上下文資訊。

最後的開機記錄記錄了服務端和啟動和用戶端第一次擷取服務介面的資訊：

    [DataContract(Namespace = "WcfExtension")]    [KnownType(typeof(WcfService))]    public class ServerStartInfo : StartInfo , IServerInfo    {        [DataMember]        public string ServiceName { get; set; }        [DataMember]        public WcfService WcfService { get; set; }    }    [DataContract(Namespace = "WcfExtension")]    public class ClientStartInfo : StartInfo , IClientInfo    {        [DataMember]        public string ContractName { get; set; }        [DataMember]        public string ClientTypeName { get; set; }        [DataMember]        public WcfEndpoint WcfEndpoint { get; set; }    }

在上一篇文章中我們看到了，用戶端的執行日誌、異常日誌是在ServiceRealProxy中實現的，而開機記錄是在WcfServiceClientFactory中的CreateServiceClient方法實現的。那麼訊息日誌在哪裡實現的呢？

internal class ClientMessageInspector : IClientMessageInspector    {        private static Dictionary<string, string> contractVersionCache = new Dictionary<string, string>();        private static object locker = new object();        public void AfterReceiveReply(ref Message reply, object correlationState)        {#if DEBUG            var message = reply.ToString();            Console.WriteLine("用戶端收到訊息：" + message);#endif            ClientApplicationContext.Current = reply.GetApplicationContext<ClientApplicationContext>();                try            {                if (WcfLogManager.Current((correlationState as Type)).MessageInfo.Client.Enabled)                {                    var direct = WcfLogManager.Current((correlationState as Type)).MessageInfo.Client.Direction;                    if (direct == WcfDirection.Both ||                        direct == WcfDirection.Receive)                    {                        var log = WcfLogProvider.GetClientMessageInfo(                          (correlationState as Type).FullName,                          ClientApplicationContext.Current.RequestIdentity,                          "ClientMessageInspector.AfterReceiveReply",                          MessageDirection.Receive,                          reply.ToString());                        WcfServiceLocator.GetLogService().LogWithoutException(log);                    }                }            }            catch (Exception ex)            {                LocalLogService.Log(ex.ToString());            }        }        public object BeforeSendRequest(ref Message request, IClientChannel channel)        {            try            {                var channelType = channel.GetType();                var serverContext = new ServerApplicationContext();                serverContext.RequestIdentity = Guid.NewGuid().ToString();                serverContext.ClientMachineName = WcfLogProvider.MachineName;                if (!contractVersionCache.ContainsKey(channelType.FullName))                {                    lock (locker)                    {                        if (!contractVersionCache.ContainsKey(channelType.FullName))                        {                            contractVersionCache.Add(channelType.FullName, channelType.Assembly.GetName().Version.ToString());                        }                    }                }                serverContext.ClientVersion = contractVersionCache[channelType.FullName];                request.SetApplicationContext(serverContext);                var clientContext = new ClientApplicationContext();                clientContext.RequestIdentity = serverContext.RequestIdentity;                ClientApplicationContext.Current = clientContext;#if DEBUG                var message = request.ToString();                Console.WriteLine("用戶端發出訊息：" + message);#endif                if (WcfLogManager.Current(channel.GetType()).MessageInfo.Client.Enabled)                {                    var direct = WcfLogManager.Current(channel.GetType()).MessageInfo.Client.Direction;                    if (direct == WcfDirection.Both                        || direct == WcfDirection.Send)                    {                        var log = WcfLogProvider.GetClientMessageInfo(                        channelType.FullName,                        ClientApplicationContext.Current.RequestIdentity,                        "ClientMessageInspector.BeforeSendRequest",                        MessageDirection.Send,                        request.ToString());                        WcfServiceLocator.GetLogService().LogWithoutException(log);                    }                }                return channelType;            }            catch (Exception ex)            {                LocalLogService.Log(ex.ToString());            }            return channel.GetType();        }    }

很明顯，通過IClientMessageInspector實現，Wcf的擴充可以總結為以下幾個步驟：

1） 實現Wcf定義的一些介面

2） 把實現通過代碼方式加入XX行為

3） 把XX行為通過代碼方式或設定檔方式加入Wcf內部

那麼這裡的第二步實現如下：

internal class MessageInspectorEndpointBehavior : IEndpointBehavior    {        #region IEndpointBehavior Members        public void AddBindingParameters(ServiceEndpoint endpoint, BindingParameterCollection bindingParameters)        {        }        public void ApplyClientBehavior(ServiceEndpoint endpoint, ClientRuntime clientRuntime)        {            clientRuntime.MessageInspectors.Add(new ClientMessageInspector());        }        public void ApplyDispatchBehavior(ServiceEndpoint endpoint, EndpointDispatcher endpointDispatcher)        {            endpointDispatcher.DispatchRuntime.MessageInspectors.Add(new ServerMessageInspector());        }        public void Validate(ServiceEndpoint endpoint)        {        }        #endregion    }

第三步的實現之前已經看到過了，在建立通道工廠的時候直接加入進去的。再來看一下ClientMessageInspector的實現，有幾個需要注意的地方：

1） 通過WcfLogManager來讀取各種日誌是否要記錄的開關，然後通過WcfLogProvider來擷取各種日誌，最後通過WcfServiceLocator.GetLogService()來擷取Log Service記錄日誌。

2） 在這裡為了效能，為契約對應的版本號碼做了緩衝。這裡要說明一點，由於這些橫切日誌部分是貫穿架構內部的，貫穿每一次方法調用的，所以一要確保高效能，二要確保不出錯，不能為了一些日誌而大幅降低服務的處理效能，甚至影響正常服務的運行。

3） 通過correlationState來返回契約類型，因為在AfterReceiveReply中很難提取契約類型。

再來說說服務端的部分，服務端的方法調用日誌是通過IOperationInvoker實現的，具體實現不給出了。

服務端的訊息日誌很明顯也是通過和IClientMessageInspector對應的IDispatchMessageInspector來實現的。

最後，服務端的異常是通過IErrorHandler來實現的：

internal class ErrorHandler : IErrorHandler    {        public bool HandleError(Exception error)        {            try            {#if DEBUG                Console.WriteLine("服務端出現異常！ Message:{0}, id : {1}", error.Message, error.Data["id"]);#endif                if (WcfLogManager.Current().ExceptionInfo.Server.Enabled)                {                    var exceptionID = error.Data["id"].ToString();                    var log = WcfLogProvider.GetServerExceptionInfo("ErrorHandler.HandleErrer", error);                    log.ID = exceptionID;                    WcfServiceLocator.GetLogService().LogWithoutException(log);                }            }            catch (Exception ex)            {                LocalLogService.Log(ex.ToString());            }            return true;        }        public void ProvideFault(Exception error, MessageVersion version, ref Message fault)        {            try            {                var errorid = Guid.NewGuid().ToString();                error.Data.Add("id", errorid);                ServerApplicationContext.Current.ServerExceptionID = errorid;                FaultException fe = new FaultException(new FaultReason(error.Message));                MessageFault messagefault = fe.CreateMessageFault();                fault = Message.CreateMessage(version, messagefault, "http://www.5173.com");            }            catch (Exception ex)            {                LocalLogService.Log(ex.ToString());            }        }    }

這裡注意兩點：

1） ProvideFault的時候我們會把異常封裝為一個FaultException提供給用戶端。

2） 會把服務端異常的ID在訊息頭中傳給用戶端，這個異常ID就是服務端記錄的異常的ID。

我們可能還注意到，用戶端需要傳給服務端RequestIdentity，服務端需要傳給用戶端異常ID，用戶端需要傳給服務端用戶端契約的版本和用戶端的機器名，而服務端也需要把自己的機器名和契約版本傳給用戶端。這都是通過定義上下文類，在訊息頭中傳遞進行的：

1） 在IClientMessageInspector中，發送訊息之前把服務端需要的上下文準備好，加入頭傳過去，在收到服務端返回的訊息之後建立用戶端的上下文。

2） 在IDispatchMessageInspector中，和1）反過來，收到訊息之後建立服務端上下文，發回複之前把用戶端需要的上下文資料準備好加入頭中。

通過這些豐富的日誌資訊，我們可以：

1） 知道服務的啟動資訊，知道哪些用戶端使用了我們的服務端

2） 知道用戶端調用的資訊，知道服務端執行方法的資訊，知道兩端的版本是否匹配，可以統計用戶端和服務端的機器，知道方法的執行時間

3） 用戶端通過異常可以關聯服務端異常，服務端異常記錄了詳細的出錯堆棧

4） 如果需要進一步跟蹤問題可以開啟訊息記錄（消耗一定的效能）

5） 通過上下文把用戶端和服務端的調用變為一個整體

6） 由雩都記錄了機器名或IP地址，可以統計出有效能問題的機器，遇到問題也可以馬上定位出錯的機器，便於負載平衡環境定位問題

對於分布式的服務來說，服務端可能又會是其他服務的用戶端，錯綜複雜，橫切關注點尤其重要，因為這個架構很大一部分在實現這個。

當然，日誌僅僅是存下來還不夠，還需要有一個強大的查看以及統計後台，用於定位問題發現問題。