diff --git a/LogStudy.DiagnosticLog.Next/LogStudy.DiagnosticLog.Next.csproj b/LogStudy.DiagnosticLog.Next/LogStudy.DiagnosticLog.Next.csproj new file mode 100644 index 0000000..74abf5c --- /dev/null +++ b/LogStudy.DiagnosticLog.Next/LogStudy.DiagnosticLog.Next.csproj @@ -0,0 +1,10 @@ + + + + Exe + net6.0 + enable + enable + + + diff --git a/LogStudy.DiagnosticLog.Next/Program.cs b/LogStudy.DiagnosticLog.Next/Program.cs new file mode 100644 index 0000000..99bae83 --- /dev/null +++ b/LogStudy.DiagnosticLog.Next/Program.cs @@ -0,0 +1,10 @@ +namespace LogStudy.DiagnosticLog.Next +{ + internal class Program + { + static void Main(string[] args) + { + Console.WriteLine("======== 高级诊断日志学习 ========"); + } + } +} \ No newline at end of file diff --git a/LogStudy.EventLog.Next/Program.cs b/LogStudy.EventLog.Next/Program.cs index 5a7889a..22b7065 100644 --- a/LogStudy.EventLog.Next/Program.cs +++ b/LogStudy.EventLog.Next/Program.cs @@ -1,10 +1,12 @@ -namespace LogStudy.EventLog.Next +using System.Diagnostics.Tracing; + +namespace LogStudy.EventLog.Next { internal class Program { static void Main(string[] args) { - Console.WriteLine("Hello, World!"); + Console.WriteLine("======== 高级事件日志学习 ========"); } } } \ No newline at end of file diff --git a/LogStudy.EventLog.Next/学习教程.md b/LogStudy.EventLog.Next/学习教程.md new file mode 100644 index 0000000..4366e15 --- /dev/null +++ b/LogStudy.EventLog.Next/学习教程.md @@ -0,0 +1,577 @@ +高级事件日志学习教程 +==================== + +基于EventSource 的日志架最初是为 Windows的ETW(Event Tracing for Windows)设计的。由于采用了发布订阅的设计思想,所以这个日志框架在日志生产和消费上是互相独立的。 +对于 EventSource 发出的日志事件,ETW 并非唯一的消费者,我们可以通过创建的EventListener对象来订阅感兴趣的日志事件,并对得到的日志消息进行针对性处理。 + +## EventSource + +在大部分情况下,我们倾向于定义一个派生于 EventSource 的子类型,并将日志事件的发送实现在某个方法中,不过这项工作也可以直接由创建的 EventSource 对象来完成。 +鉴于这两种不同的编程模式,EventSource定义了两组(Protected和 Public)构造函数 + +```csharp +public class EventSource : IDisposable +{ + public string Name {get;set;} + public Guid Guid {get;set;} + public Exception ConstructionException {get;} + public EventSourceSettings Settings {get;} + + protected EventSource(); + protected EventSource(bool throwOnEventWriteErrors); + protected EventSource(EventSourceSettings settings); + protected EventSource(EventSourceSettings settings, params stringl] traits); + + public EventSource(string eventSourceName); + public EventSource(string eventSourceName, EventSourceSettings config); + public EventSource(string eventSourceName, EventSourceSettings config, params stringl] traits); +} + +``` + +一个 EventSource 对象要求具有一个明确的名称,所以调用公共的构造函数时必须显式指定比名称。 +对于 EventSource 的派生类来说,如果类型上没有通过标注的EventSourceAttribute特生对名称进行显式设置,则类型的名称将会作为EventSource的名称。 +一个 EventSource 对象还要求被赋予一个GUID作为唯一标识。 +对于直接创建的 EventSource 对象来说,该标识是由指定的名称计算出来的,EventSource的派生类型则可以通过标注的EventSourceAttribute特性来对这个标识进行显式设置。 +EventSource的Settings 属性用于返回一个EventSourceSettings对象,这是一个标注了FlagsAttribute特性的枚举。该枚举对象针对EventSource的“设置”(Settings)主要体现在两个方法:指定输出日志的格式(Manifest或者Manifest Self-Describing),以及决定是否应该抛出日志写入过程中出现的异常的设置。 + +```csharp +[Flags] +public enum EventSourceSettings +{ + Default =0, + ThrowOnEventWriteErrors =1, + EtwManifestEventFormat =4, + EtwSelfDescribingEventFormat =8 +} +``` + +如果没有显式设置,则EventSource的派生类型的 Settings 属性默认为 EtwManifestEventFormat,调用公共构造函数创建的EventSource 对象的 Settings 属性为EtwSelfDescribingEventFormat。除了上述只读属性,EventSource还有一个 ConstructionException属性用于返回构造函数执行过程中抛出的异常。 +在定义 EventSource 派生类时,虽然类型名称会默认作为 EventSource 的名称,但是通过在类型上标注 EventSourceAttribute特性对名称进行显式设置依然是推荐的做法。这样不但可以定义一个标准的名称(如采用公司和项目或者组件名称作为前缀),而目类刑改名后也不会造成任何影响。 +如下面的代码片段所示,除了指定EventSource的名称,通过标注EventSourceAttribute特性还可以设置作为唯一标识的GUID,以及用于本地化的字符串资源。 + +```csharp +[AttributeUsage(AttributeTargets.Class)] +public sealed class EventSourceAttribute: Attribute +{ + public string Name ( get; set;) + public string Guid ( get; set;) + public string LocalizationResources ( get; set;) +} +``` + +对于EventSource派生类来说,它可以通过调用基类的WriteEvent方法来发送日志事件。 +我们在调用 WriteEvent方法时必须指定日志事件的ID(必需)和内容载荷(可选)。 +如下面的代马片段所示,EventSource定义了一系列的WriteEvent重载方法来提供具有成员结构的内容载荷 + +```csharp +public class EventSource : IDisposable +{ + protected void WriteEvent(int eventId); + protected void WriteEvent(int eventId, int argl); + protected void WriteEvent(int eventId, long argl); + protected void WriteEvent(int eventId, string arg1); + protected void WriteEvent(int eventId, bytel] argl); + protected void WriteEvent(int eventId, int argl, int arg2); + protected void WriteEvent(int eventId, int argl, string arg2); + protected void WriteEvent(int eventId, long argl, long arg2); + protected void WriteEvent(int eventId, long arg1, string arg2); + protected void WriteEvent(int eventId, long argl, bytell arg2); + protected void WriteEvent(int eventId, string argl, int arg2); + protected void WriteEvent(int eventId, string argl, long arg2); + protected void WriteEvent(int eventId, string argl, string arg2); + protected void WriteEvent(int eventId, int argl, int arg2, int arg3); + protected void WriteEvent(int eventId, long argl, long arg2, long arg3);protected void WriteEvent(int eventId, string argl, int arg2, int arg3);protected void WriteEvent(int eventId, string argl, string arg2, string arg3); + protected void WriteEvent(int eventId, params objectl] args); +} +``` + +由于拥有最后一个 WriteEvent重载方法,所以我们可以采用一个或者多个任意类型的对象作为内容载荷,这个特性被称为“Rich Event Payload”。 +虽然这个特性可以使EventSource的日志编程变得很简洁,但是在高频日志写入的应用场景下应该尽可能避免调用这个WriteEvent 方去,因为涉及一个对象数组的创建及对值类型对象的装箱(如果指定值类型参数)。 +虽然没有硬性规定,但是我们应该尽可能将EventSource派生类定义成封闭类型,并且采用单例的方式来使用它,这也是出于性能的考虑。 +除非显式标注了NonEventAttribute特性,否则定义在 EventSource派生类中返回类型为 void 的公共实例方法都将作为日志事件方法。 +每个这样的方法关联着固定的事件 ID,如果没有利用标注的EventAttribute特性对事件 ID进行显式设置,则方法在类型成员中的序号会作为此ID。在调用上面这些 WriteEvent方法时指定的事件ID必须与当前日志事件方法对应的ID保持一致。 +除了利用标注的EventAttribute特性指定事件ID,还可以利用这个特性进行一些额外的设置。 +如下面的代码片段所示,我们可以通过该特性设置日志等级、消息、版本等信息。 +```csharp +[AttributeUsage(AttributeTargets.Method)] +public sealed class EventAttribute :Attribute +{ + public int EventId {get; private set;} + public EventLevel Level {get; set;} + public string Message {get; set;} + public byte Version {get; set;} + public EventOpcode Opcode {get; set;} + public EventTask Task {get; set;} + public EventKeywords Keywords {get; set;} + public EventTags Tags {get; set;} + public EventChannel Channel {get; set;} + public EventActivityOptions ActivityOptions {get; set;} + + public EventAttribute(int eventId); +} + +``` + +由 EventSource 对象发出的日志事件同样具有等级之分,具体的日志等级可以通过EventLevel枚举来表示,从高到低划分为Critical、Error、Warning、Informational和Verbose这5个等级。 +如果没有通过 EventAttribute 特性对日志等级进行显式设置,则日志事件方法采用的默认等级被设置为Verbose。 + +```csharp +public enum EventLevel +{ + LogAlways, + Critical, + Error, + Warning, + Informational, + Verbose +} +``` + +如果对日志内容具有可读性要求,则最好提供一个完整的消息文本来描述当前事件,EventAttribute的Message提供了一个生成此消息文本的模板。 +消息模板可以采用(0,1,...n这样的占位符,而调用日志事件方法传入的参数将作为替换它们的参数。 +EventAttribute特性的Opcode 属性用于返回一个 EventOpcode类型的枚举,该枚举表示日志事件对应操作的代码(Code)。 +我们将定义在EventOpcode枚举中的操作代码分成如下几组: +第1组的4个操作代码与活动(Activity)有关,分别表示活动的开始(Start)、结束(Stop)、中止(Suspend)和恢复(Resume); +第2组的两个操作代码基于数据收集的活动; +第3组的3个操作代码描述的是与消息交换相关的事件,分别表示消息的发送(Send)、接收(Receive)和回复(Reply); +第4组是Info和Extension,前者表示一般性的信息的输出,后者表示一个扩展事件。 + +```csharp +public enum EventOpcode +{ + Start =1, + Stop =2, + Resume =7, + Suspend =8, + + DataCollectionStart =3, + DataCollectionStop =4, + + Send =9, + Receive =240, + Reply =6, + + Info =0, + Extension =5, +} +``` + +如果日志事件关联某项任务(Task),就可以用Task属性对它进行描述。 +我们还可以通过eywords属性和Tags属性为日志事件关联一些关键字(Keyword)与标签(Tag)。 +一般来说,件是根据订阅发送的,如果待发送的日志事件没有订阅者,该事件就不应该被发出,所以日事件的订阅原则是尽可能缩小订阅的范围,这样就可以将日志导致的性能影响降到最低。 +如为某个日志事件定义了关键字,我们就可以对该关键字进行精准的订阅。 +如果当前事件的日具有特殊的输出渠道,就可以利用其Channel属性来承载输出渠道信息。 +这些属性的返回类都是枚举,如下所示的代码片段展示了这些枚举类型的定义。 + +```csharp +[Flags] +public enum EventKeywords : long +{ + A11 = -1L, + None = OL, + AuditFailure = 0x10000000000000L, + AuditSuccess = 0x20000000000000L, + CorrelationHint = 0x10000000000000L, + EventLogClassic = 0x80000000000000L + MicrosoftTelemetry = 0x2000000000000L, + Sqm = 0x8000000000000L + WdiContext = 0x2000000000000L, + WdiDiagnostic = 0x4000000000000L +} + +public enum EventChannel :byte +{ + None =0, + Admin =10, + Operational =11 + Analytic 12, + Debug =13 +} + +[Flags] +bublic enum EventTask +{ + None +} + +[Flags] +public enum EventTags +{ + None +} + +``` + +从上面的代码片段可以看出,枚举类型 EventTask 和 EventTags 并没有定义任何有意义的枚举选项(只定义了一个None选项)。 +因为枚举的基础类型都是整型,所以日志事件订阅者最终接收的这些数据都是相应的数字,至于不同的数值具有什么样的语义则完全可以由具体的应用来决定,所以我们可以完全不用关心这些枚举的预定义选项。 +EventAttribute特性之所以将这些属性定义成枚举,并不是要求我们使用预定义的选项,而是提供一种强类型的编程方式。 +例如,我们可以采用如下形式定义4个EventTags常量来表示4种数据库类型。除了 EventTask和EventTags,表示关键字的EventKeywords也可以采用这种方式进行自由定义。 + +```csharp +public class Tags +{ + public const EventTags MSSql =(EventKeywords)1; + public const EventTags Oracle = (EventKeywords)2; + public const EventTags Redis =(EventKeywords)4; + public const EventTags Mongodb =(EventKeywords)8; +} +``` + +在大部分情况下,单一事件的日志数据往往没有实际意义,只有将在某个上下文中记录下来的一组相关日志进行聚合分析才能得到有价值的结果,采用基于“活动”(Activity)的跟踪是关联单一日志事件的常用手段。 +一个所谓的活动是具有严格的开始和结束边界,并且需要耗费一定时间才能完成的操作。活动具有标准的状态机,状态之间的转换可以通过对应的事件来表示,一个活动的生命周期介于开始事件和结束事件之间。 +EventSource日志框架对基于活动的追踪(Activity Tracking)提供了很好的支持,EventAttribute特性的ActivityOptions属性正是用来做这方面设置的。 +该属性返回的 EventActivityOptions枚举具有如下选项:Disable用于关闭活动追踪特性,Recursive和Detachable分别表示是否允许活动以递归或者重叠的方式运行。 +我们将在后续部分详细介绍这个话题。 +```csharp +[Flags] +public enum EventActivityoptions +{ + None = 0, + Disable = 2, + Recursive = 4, + Detachable = 8 +} +``` +由上面介绍的内容可知,定义在EventSource派生类中的日志方法是通过调用基类的WriteEvent方法来发送日志事件的,但是对于一个直接调用公共构造函数创建的EventSource对象来说,这个受保护的 WriteEvent方法是无法直接被调用的,只能调用下面几个公共的 Write方法和Write方法来发送日志事件。 + +```csharp +public class EventSource:IDisposable +{ + public void Write(string eventName); + public void Write(string eventName, EventSourceOptions options); + public void Write(string eventName, T data); + public void Write(string eventName, EventSourceOptions options, T data); + public void Write(string eventName, ref EventSourceOptions options, ref T data); + public void Write(string eventName, ref EventSourceOptions options, ref Guid activityid, ref Guid relatedActivityId, ref T data); +} + +``` + +在调用Write方法和Write方法时需要设置事件的名称(必须)和其他相关设置(可选),还可以指定一个对象作为内容载荷。 +EventSource 相关的配置选项通过具有如下定义的EventSourceOptions结构来表示。 +我们可以利用EventSourceOptions设置事件等级、操作代码、关键字、标签和活动追踪的其他选项,在调用上述两个方法时也可以将EventSourceOptions作为参数。 + +```csharp +[StructLayout(LayoutKind.Sequential)] +public struct EventSourceOptions +{ + public EventLevel Level {get;set;} + public EventOpcode Opcode {get;set;} + public EventKeywords Keywords {get;set;} + public EventTags Tags {get;set;} + public EventActivityOptions ActivityOptions {get;set;} +} +``` +ETW 的两种格式(Manifest 和 Manifest Self-Describing)分别对应枚举类型EventSourceSettings的EtwManifestEventFormat选项和EtwSelfDescribingEventFormat选项,后者提供了Rich Event Payload支持。 +由于泛型的Write方法采用的正是对该特性的体现,所以通过公共构造函数创建的EventSource对象的Settings 属性会被自动设置为EtwSelfDescribingEventFormat。 +只有在EventSource对象被订阅的前提下,针对它发送日志事件才有意义,为了避免无谓操作造成的性能影响,我们在发送日志事件之前应该调用如下几个IsEnabled方法。 +它们可以确认 EventSource对象的日志等级、关键字或者输出渠道是否具有订阅者。 + +```csharp +public class EventSource: IDisposable +{ + public bool IsEnabled(); + Public bool IsEnabled(EventLevel level, EventKeywords keywords); + Public bool IsEnabled(EventLevel level, EventKeywords keywords, EventChannel channel); +} +``` +## EventListener +EventListener提供了一种在进程内(In-Process)订阅和处理日志事件的手段。 +EventListener对象能够接收由 EventSource分发的日志事件的前提预先进行了订阅的事件。 +EventListener向 EventSource就某种日志事件类型的订阅通过如下几个EnableEvents重载方法来完成。 +我们在调用这些方法时可以通过指定日志等级、关键字和命令参数的方式对分发的日志事件进行过滤。 +EventListener还定义了DisableEvents方法来解除订阅。 + +```csharp +public abstract class EventListener :IDisposable +{ + public void EnableEvents(EventSource eventSource, EventLevel level); + public void EnableEvents(EventSource eventSource, EventLevel level,EventKeywords matchAnyKeyword); + public void EnableEvents(EventSource eventSource, EventLevel level,EventKeywords matchAnyKeyword, IDictionary arguments); + public void DisableEvents(EventSource eventSource); +} +``` + +虽然 EventListener 需要通过调用EnableEvents方法显式地就感兴趣的日志事件向EventSource发起订阅,但是由于EventListener能够自动感知当前进程内任意一个EventSource对象的创建,所以订阅变得异常容易。 +EventListener类型定义了 OnEventSourceCreated 和 OnEventWritten 这两个受保护的虚方法,前者会在任何一个EventSource对象创建时被调用。我们通过重写这个方法完成对目标 EventSource的订阅。 +目标EventSource对象发出日志事件后,相关信息会被封装成一个 EventWrittenEventArgs对象作为参数调用EventListener 的OnEventWritten方法。我们通过重写 OnEventWritten方法完成日志事件的处理。 +实现在基类EventListener的这两个方法分别触发 EventSourceCreated事件和EventWritten事件,所以重写这两个方法时最好能够调用基类的同名方法。 + +```csharp +public class EventListener :IDisposable +{ + public event EventHandler EventSourceCreated; + public event EventHandler EventWritten; + protected internal virtual void OnEventSourceCreated(EventSource eventSource); + protected internal virtual void OnEventWritten(EventWrittenEventArgs eventData); +} +``` + +如下所示的代码片段是EventWrittenEventArgs类型的定义,我们不仅可以通过它获取包括内容载荷在内的用于描述当前日志事件的所有信息,还可以得到对应的EventSource对象。 +日志事件可以采用不同的形式来指定内容载荷,它们最终会转换成一个ReadOnlyCollection对象分发给作为订阅者的EventListener对象。 +除了表示载荷对象集合的Payload属性,EventWrittenEventArgs类型还提供了PayloadNames属性来表示每个载荷对象对应的名称。 + +```csharp +public class EventWrittenEventArgs : EventArgs +{ + public EventSource EventSource {get;} + public int EventId {get;} + public string EventName {get;} + public EventLevel Level {get;} + public string Message {get;} + public byte Version {get;} + public EventKeywords Keywords {get;} + public EventOpcode Opcode {get;} + public EventTask Tags {get;} + public EventChannel Channel {get;} + public Guid Task {get;} + public Guid ActivityId {get;} + + public ReadOnlyCollection Payload {get;} + public ReadOnlyCollection PayloadNames {get;} + +} +``` + +前文已经演示了 EventSource和 EventListener的简单用法,接下来演示一个更加完整的序。 +我们先以常量的形式预定义几个EventTask 对象和EventTags对象,前者表示操作执行所的应用层次,后者表示3种典型的关系数据库类型。 + +```csharp + +public class Tasks +{ + public const EventTask UI = (EventTask)1; + public const EventTask Business = (EventTask)2; + public const EventTask DA = (EventTask)3; +} + +public class Tags +{ + public const EventTags MSSQL = (EventTags)1; + public const EventTags Oracle = (EventTags)2; + public const EventTags Db2 = (EventTags)3; +} + +``` +我们依然沿用执行SQL 命令的应用场景,为此对之前定义的DatabaseSource类型进行一简单的修改。 +如下面的代码片段所示,我们在日志方法OnCommandExecute上标注EventAttribute特性,并对它的所有属性都进行了相应的设置,其中Task属性和Tags属性使的是上面定义的常量。 +值得注意的是,我们为Message属性设置了一个包含占位符的模板。OnCommandExecute方法在调用 WriteEvent方法发送日志事件之前,先利用IsEnabled方法确EventSource对象针对指定的等级和输出渠道已经被订阅。 +```csharp +[EventSource(Name ="Artech-Data-SqlClient") +public sealed class DatabaseSource : EventSource +{ + public static DatabaseSource Instance = new DatabaseSource(); + private DatabaseSource(){} + + [Event (1, Level = EventLevel.Informational, Keywords = EventKeywords.None, opcode = Eventopcode.Info, Task = Tasks.DA, Tags = Tags.MSSQL, Version = 1,Message ="Execute SQL command, Type: (0), Command Text:(1)")] + public void OnCommandExecute(CommandType commandType, string commandText) + { + if (IsEnabled(EventLevel.Informational, EventKeywords.All, EventChannel.Debug)) + { + WriteEvent(1, (int) commandType, commandText); + } + } + +} +``` +我们采用如下代码对作为日志事件订阅者的DatabaseSourceListener类型进行了重新定义。 +为了验证接收的日志事件的详细信息是否与OnCommandExecute方法中的订阅一致,我们在重写的 OnEventWritten方法中输出了EventWrittenEventArgs对象的所有属性。 + +```csharp + public class DatabaseSourceListener : EventListener + { + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name == "Artech-Data-SqlClient") + { + EnableEvents(eventSource, EventLevel.LogAlways); + } + } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + Console.WriteLine($"EventId:(eventData.EventId)"); + Console.WriteLine($"EventName:(eventData.EventName)"); + Console.WriteLine($"Channel:(eventData.Channel)"); + Console.WriteLine($"Keywords:(eventData.Keywords)"); + Console.WriteLine($"Level:(eventData.Level)"); + Console.WriteLine($"Message:(eventData.Message)"); + Console.WriteLine($"Opcode:(eventData.Opcodej"); + Console.WriteLine($"Tags:(eventData.Taqsj"); + Console.WriteLine($"Task: (eventData.Task)"); + Console.WriteLine($"Version:(eventData.Version)"); + Console.WriteLine($"Payload"); + + var index = 0; + if (eventData.PayloadNames != null) + { + foreach (var payloadName in eventData.PayloadNames) + { + Console.WriteLine($"\t{payloadName}:{eventData.Payload ? [index++]}"); + } + } + } + } +``` + +在如上所示的演示程序中,我们创建了一个DatabaseSourceListener对象。在提取单例形式的DatabaseSource对象后,调用它的OnCommandExecute方法发送了一个关于 SOL命令执行的日志事件。 + +``` csharp +using App; +using System,Data; +_ = new DatabaseSourceListener(); +DatabaseSource.Instance,OnCommandExecute(CommandType.Text, "SELECT * FROM T_USER"); + +``` + +程序运行之后,日志事件的详细信息会输出到控制台上。我们从输出结果可以发现 EventWrittenEventArgs的 Message属性返回的依然是没有做任何格式化的原始信息,作者认为这是值得改进的地方。 + +## 活动跟踪 +基于 TraceSource 的跟踪日志框架可以利用 CorrelationManager 构建逻辑调用链。我们可以将这个特性称为“针对活动的跟踪”(Activity Tracking)。 +表示一个逻辑操作的活动具有一个唯一的标识,其生命周期由开始事件和结束事件定义。 +由于一个逻辑操作可能由多个子操作协作完成,所以多个活动构成一个层次化的结构,逻辑调用链正是由当前活动的路径来体现的。 +对于作为日志事件订阅者的EventListener来说,它可以利用EventWrittenEventArgs对象得到描述订阅日志事件的所有信息。 +如果开启了针对活动的跟踪,则当前活动的标识也会包含其中,如下所示的代码片段中的ActivityId属性表示这个标识,而RelatedActivityId属性则表示“父操作”的活动ID。 + +```csharp +public class EventWrittenEventArgs : EventArgs +{ + public Guid ActivityId {get;} + public Guid RelatedActivityId {get;} +} + +``` + +由于一个活动的生命周期可以由开始事件和结束事件作为边界,所以可以通过发送两个关联的事件来定义一个表示逻辑操作的活动,以EventSource为核心的日志框架正是采用这种方式来实现针对活动的跟踪的。假设需要定义一个名为“Foobar”的活动,则可以利用 EventSource发送两个名称分别为“FoobarStart”和“FoobarStop”的事件。 +要构建一个完整的调用链,必须将表示前逻辑操作的活动流转信息保存下来。由于可能涉及异步调用,所以将当前活动标识保存在AsyncLocal对象中。当前活动流转信息的保存是通过如下派生于EventSource的TplEtwProvider类型实现的,Tpl表示“Task Parallel Library”。 +日志活动流转信息的输出与TraceOperationBegin和TraceOperationEnd这两个方法有关,它们具有相同的日志事件等级(Informational)和关键字(8L)。如果要利用一个自定义的EventListener来记录完整的调用链,就需要订阅这两个方法。 + +```csharp +[EventSource(Name="System.Threading.Tasks.TplEventSource",Guid="2e5dba47-a3d2-4d16-8ee0-6671ffdcd7b5")] +internal sealed class TplEtwProvider:EventSource +{ + [Event (14, Version=1, Level=EventLevel.Informational, Keywords=8L)] + public void TraceOperationBegin(int TaskID, string OperationName, long RelatedContext); + + [Event(15, Version=1, Level=EventLevel.Informational,Keywords=8L)] + public void TraceOperationEnd(int TaskID, AsyncCausalityStatus Status); + + //...... +} +``` + +接下来通过一个简单的实例来演示利用自定义的 EventSource和EventListener来完成针对活动的跟踪。 +假设一个完整的调用链由Foo、Bar、Baz和Qux这4个活动组成,为此我们定义如下 FoobarSource,并针对4个活动分别定义了4组对应的事件方法,其中“(Op)Start”方法和“fOpiStop”方法分别对应活动的开始事件与结束事件,前者的载荷信息包含活动开始的时间戳,后者的载荷信息包含操作耗时。 +```csharp + +[EventSource (Name"Foobar")] +public sealed class FoobarSource:EventSource +{ + public static readonly FoobarSource Instance = new(); + + [Event(1)] + public void FooStart(long timestamp) => WriteEvent(l, timestamp); + + [Event (2) ] + public void FooStop(double elapsed) => WriteEvent(2, elapsed); + + [Event (3) ] + public void BarStart(long timestamp) => WriteEvent(3, timestamp); + + [Event(4)] + public void BarStop(double elapsed) => WriteEvent(4, elapsed); + + [Event(5)] + public void BazStart(long timestamp) WriteEvent(5, timestamp); + + [Event(6)】 + public void BazStop(double elapsed) => WriteEvent(6, elapsed); + + [Event(7)] + public void QuxStart(long timestamp) =>WriteEvent(7, timestamp); + + [Event(8)] + public void Quxstop(double elapsed) => WriteEvent(8, elapsed); +} + +``` + +如下所示的FoobarListener会订阅上面的这些事件,并将接收的调用链信息保存在一个log.csv文件中。 +在重写的 OnEventSourceCreated方法中,除了根据EventSource的名称订阅由FoobarSource发出的8个事件,还需要订阅TplEtwProvider发出的用于保存活动流转信息的事件。 +本着尽量缩小订阅范围的原则,我们在调用 EnableEvents方法时采用日志等级和关键字对订阅事件进行了过滤。 +在重写的OnEventWritten方法中,我们将捕捉到的事件信息(名称、活动开始时间戳和耗时、ActivityId和RelatedActivityId)进行格式化后写入指定的log.csv文件中。 + +```csharp + public sealed class FoobarListener : EventListener + { + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name == "System.Threadina.Tasks.TplEventSource") + { + EnableEvents(eventSource, EventLevel.Informational, (EventKeywords)0x80); + } + + if (eventSource.Name == "Foobar") + { + EnableEvents(eventSource, EventLevel.LogAlways); + } + } + + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + if (eventData.EventSource.Name == "Foobar") + { + var timestamp = eventData.PayloadNames?[0] == "timestamp" ? eventData.Payload?[0] : ""; + var elapsed = eventData.PayloadNames?[0] == "elapsed" ? eventData.Payload?[0] : ""; + var relatedActivityId = eventData.RelatedActivityId == default ? "" : eventData.RelatedActivityId.ToString(); + var line = + @$"{eventData.EventName},{timestamp},{elapsed},{eventData.ActivityId},{relatedActivityId}"; + File.AppendAllLines("log.csv", new string[] { line }); + } + } + } + +``` + +如下所示的代码片段可以模拟由Foo、Bar、Baz和Qux这4个活动组成的调用链。 +这些活动的控制实现在InvokeAsyne方法中,该方法的参数 start和stop提供的委托对象分别用来发送活动的开始事件与结束事件,至于参数body返回的 Task对象则表示活动自身的操作。 +为了模拟活动耗时,我们需要等待一个随机的时间。 + +```csharp +using App; +using System.Diagnostics; + +var random = new Random(); +File.AppendAllLines("log.csv",new string[] {@"EventName, StartTime, Elapsed,ActivityId, RelatedActivityId"}); + +var listener = new FoobarListener(); +await FooAsync(); +Task FooAsync() => InvokeAsync( +FoobarSource.Instance.FooStart, stop: FoobarSource.Instance.FooStop, async () => +{ + await BarAsync(); + await QuxAsync(); +}); +Task BarAsync() => InvokeAsync(FoobarSource.Instance.BarStart, FoobarSource.Instance.BarStop, BazAsync); + +Task BazAsync() => InvokeAsync(FoobarSource.Instance.BazStart,FoobarSource.Instance.BazStop, () => Task.CompletedTask); + +Task QuxAsync() => InvokeAsync(FoobarSource.Instance.QuxStart,FoobarSource.Instance.QuxStop, () => Task.CompletedTask); +async Task InvokeAsync(Action start, Action stop, Func body) +{ + start(Stopwatch.GetTimestamp()); + var sw = Stopwatch.StartNew(); + await Task.Delay(random.Next(10, 100)); + await body(); + stop(sw.ElapsedMilliseconds); +} +``` + +4个活动分别实现在4个对应的方法中(FooAsync、BarAsync、BazAsync和QuxAsync),为了模拟基于Task的异步编程,我们让这4个方法统一返回一个Task对象。 + +在演示程序中调用了FooAsync方法,并在这之前创建了一个FoobarListener对象来订阅日事件,进而将格式化的事件信息写入指定的log.csv文件中。 +程序运行之后,我们会在log.csv件中看到8条对应的日志事件记录。 +开始事件和结束事件分别记录了活动的始时间戳与耗时,而Activityld和RelatedActivityld可以清晰地反映整个调用链的流转。 + + diff --git a/LogStudy.sln b/LogStudy.sln index 3f8382e..2428608 100644 --- a/LogStudy.sln +++ b/LogStudy.sln @@ -26,7 +26,9 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "LogStudy.DiagnosticLog", "L EndProject Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "LogStudy.EventLog.Next", "LogStudy.EventLog.Next\LogStudy.EventLog.Next.csproj", "{D77E4B1E-D839-446B-AB96-46CC5E07D36F}" EndProject -Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "LogStudy.TraceLog.Next", "LogStudy.TraceLog.Next\LogStudy.TraceLog.Next.csproj", "{5BC961D8-3DC8-4A18-A787-AA475865C801}" +Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "LogStudy.TraceLog.Next", "LogStudy.TraceLog.Next\LogStudy.TraceLog.Next.csproj", "{5BC961D8-3DC8-4A18-A787-AA475865C801}" +EndProject +Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "LogStudy.DiagnosticLog.Next", "LogStudy.DiagnosticLog.Next\LogStudy.DiagnosticLog.Next.csproj", "{0E6F6193-3075-4ABA-A4E5-07718BA8F69C}" EndProject Global GlobalSection(SolutionConfigurationPlatforms) = preSolution @@ -62,6 +64,10 @@ Global {5BC961D8-3DC8-4A18-A787-AA475865C801}.Debug|Any CPU.Build.0 = Debug|Any CPU {5BC961D8-3DC8-4A18-A787-AA475865C801}.Release|Any CPU.ActiveCfg = Release|Any CPU {5BC961D8-3DC8-4A18-A787-AA475865C801}.Release|Any CPU.Build.0 = Release|Any CPU + {0E6F6193-3075-4ABA-A4E5-07718BA8F69C}.Debug|Any CPU.ActiveCfg = Debug|Any CPU + {0E6F6193-3075-4ABA-A4E5-07718BA8F69C}.Debug|Any CPU.Build.0 = Debug|Any CPU + {0E6F6193-3075-4ABA-A4E5-07718BA8F69C}.Release|Any CPU.ActiveCfg = Release|Any CPU + {0E6F6193-3075-4ABA-A4E5-07718BA8F69C}.Release|Any CPU.Build.0 = Release|Any CPU EndGlobalSection GlobalSection(SolutionProperties) = preSolution HideSolutionNode = FALSE @@ -73,6 +79,7 @@ Global {73AC3F84-DC11-4F53-A729-0EA09E124E6E} = {D91AB187-F922-47DE-87ED-D3785F4E8D7B} {D77E4B1E-D839-446B-AB96-46CC5E07D36F} = {78E9B0D7-537A-4791-BE80-E2BA04D8A5AA} {5BC961D8-3DC8-4A18-A787-AA475865C801} = {353B9475-1064-473D-B3EE-CF3A9BBA4102} + {0E6F6193-3075-4ABA-A4E5-07718BA8F69C} = {D91AB187-F922-47DE-87ED-D3785F4E8D7B} EndGlobalSection GlobalSection(ExtensibilityGlobals) = postSolution SolutionGuid = {4D9A3A36-98D0-498C-B78A-2E5CFC5195AC}