İngilizce dilinde oku

Aracılığıyla paylaş

EventSource Etkinlik Kimlikleri

  • Makale

Bu makale şunlar için geçerlidir: ✔️ .NET Core 3.1 ve sonraki sürümleri✔️ .NET Framework 4.5 ve sonraki sürümleri

Bu kılavuzda, kullanılarak System.Diagnostics.Tracing.EventSourceoluşturulan her olayla günlüğe kaydedilebilen isteğe bağlı bir tanımlayıcı olan Etkinlik Kimlikleri açıklanmaktadır. Giriş için bkz . EventSource'u Kullanmaya Başlama.

Eşzamanlı çalışmayı günlüğe kaydetme zorluğu

Uzun zaman önce tipik bir uygulama basit ve tek iş parçacıklı olabilir ve bu da günlüğe kaydetmeyi kolaylaştırır. Her adımı sırayla bir günlük dosyasına yazabilir ve ardından günlüğü tam olarak yazıldığı sırayla okuyarak ne olduğunu anlayabilirsiniz. Uygulama istekleri işlediyse aynı anda yalnızca bir istek işlenir. A isteği için tüm günlük iletileri sırayla yazdırılır, ardından B için tüm iletiler vb. Uygulamalar çok iş parçacıklı hale geldiğinde, birden çok istek aynı anda işlendiğinden bu strateji artık çalışmaz. Ancak, her istek tamamen işleyen tek bir iş parçacığına atanırsa, her günlük iletisi için bir iş parçacığı kimliği kaydederek sorunu çözebilirsiniz. Örneğin, çok iş parçacıklı bir uygulama şunları günlüğe kaydedebilir:

txt 
Thread Id      Message
---------      -------
12             BeginRequest A
12             Doing some work
190            BeginRequest B
12             uh-oh error happened
190            Doing some work

İş parçacığı kimliklerini okuyarak, iş parçacığı 12'nin A isteğini işlediğini ve iş parçacığı 190'ın B isteğini işlediğini, dolayısıyla A isteğiyle ilgili 'uh-oh hatası oluştu' iletisinin olduğunu biliyorsunuz. Ancak uygulama eşzamanlılığı giderek daha karmaşık hale geldi. Artık yaygın olarak kullanılır async ve await böylece iş tamamlanmadan önce tek bir istek birçok farklı iş parçacığında kısmen işlenebilir. İş parçacığı kimlikleri artık tek bir istek için oluşturulan tüm iletileri ilişkilendirmek için yeterli değildir. Etkinlik kimlikleri bu sorunu çözer. Bunlar, çalışmanın farklı iş parçacıklarına yayılıp yayılmadığını fark etmeksizin tek tek istekleri veya isteklerin bölümlerini izleyebilen daha ayrıntılı bir tanımlayıcı sağlar.

Not

Burada başvuruda bulunılan Etkinlik Kimliği kavramı, benzer adlandırmaya rağmen System.Diagnostics.Tracing.Activity ile aynı değildir.

Etkinlik Kimliği kullanarak çalışmayı izleme

Etkinlik izlemenin nasıl çalıştığını görmek için aşağıdaki kodu çalıştırabilirsiniz.

C# 
using System.Diagnostics.Tracing;

public static class Program
{
    public static async Task Main(string[] args)
    {
        ConsoleWriterEventListener listener = new ConsoleWriterEventListener();

        Task a = ProcessWorkItem("A");
        Task b = ProcessWorkItem("B");
        await Task.WhenAll(a, b);
    }

    private static async Task ProcessWorkItem(string requestName)
    {
        DemoEventSource.Log.WorkStart(requestName);
        await HelperA();
        await HelperB();
        DemoEventSource.Log.WorkStop();
    }

    private static async Task HelperA()
    {
        DemoEventSource.Log.DebugMessage("HelperA");
        await Task.Delay(100); // pretend to do some work
    }

    private static async Task HelperB()
    {
        DemoEventSource.Log.DebugMessage("HelperB");
        await Task.Delay(100); // pretend to do some work
    }
}

[EventSource(Name ="Demo")]
class DemoEventSource : EventSource
{
    public static DemoEventSource Log = new DemoEventSource();

    [Event(1)]
    public void WorkStart(string requestName) => WriteEvent(1, requestName);
    [Event(2)]
    public void WorkStop() => WriteEvent(2);

    [Event(3)]
    public void DebugMessage(string message) => WriteEvent(3, message);
}

class ConsoleWriterEventListener : EventListener
{
    protected override void OnEventSourceCreated(EventSource eventSource)
    {
        if(eventSource.Name == "Demo")
        {
            Console.WriteLine("{0,-5} {1,-40} {2,-15} {3}", "TID", "Activity ID", "Event", "Arguments");
            EnableEvents(eventSource, EventLevel.Verbose);
        }
        else if(eventSource.Name == "System.Threading.Tasks.TplEventSource")
        {
            // Activity IDs aren't enabled by default.
            // Enabling Keyword 0x80 on the TplEventSource turns them on
            EnableEvents(eventSource, EventLevel.LogAlways, (EventKeywords)0x80);
        }
    }

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        lock (this)
        {
            Console.Write("{0,-5} {1,-40} {2,-15} ", eventData.OSThreadId, eventData.ActivityId, eventData.EventName);
            if (eventData.Payload.Count == 1)
            {
                Console.WriteLine(eventData.Payload[0]);
            }
            else
            {
                Console.WriteLine();
            }
        }
    }
}

Bu kod çalıştırıldığında çıktıyı yazdırır:

TID   Activity ID                              Event           Arguments
21256 00000011-0000-0000-0000-00006ab99d59     WorkStart       A
21256 00000011-0000-0000-0000-00006ab99d59     DebugMessage    HelperA
21256 00000012-0000-0000-0000-00006bb99d59     WorkStart       B
21256 00000012-0000-0000-0000-00006bb99d59     DebugMessage    HelperA
14728 00000011-0000-0000-0000-00006ab99d59     DebugMessage    HelperB
11348 00000012-0000-0000-0000-00006bb99d59     DebugMessage    HelperB
11348 00000012-0000-0000-0000-00006bb99d59     WorkStop
14728 00000011-0000-0000-0000-00006ab99d59     WorkStop

Not

Visual Studio hata ayıklayıcının geçersiz Etkinlik Kimliklerinin oluşturulmasına neden olabileceği bilinen bir sorun vardır. Bu örneği hata ayıklayıcının altında çalıştırmayın veya Main'ın başında bir kesme noktası ayarlamayın ve sorunu geçici olarak çözmeden önce anlık pencerede 'System.Threading.Tasks.TplEventSource.Log.TasksSetActivityIds = false' ifadesini değerlendirin.

Etkinlik Kimliklerini kullanarak, A iş öğesi için tüm iletilerin kimliği 00000011-... ve B iş öğesi için tüm iletilerin kimliği 00000012-...olduğunu görebilirsiniz. her iki iş öğesi de önce iş parçacığı 21256 üzerinde bazı çalışmalar yaptı, ancak her biri ayrı iş parçacığı havuzu iş parçacıklarında 11348 ve 14728 çalışmalarına devam etti, bu nedenle isteği yalnızca iş parçacığı kimlikleriyle izlemeye çalışmak işe yaramazdı.

EventSource, _Something_Start adlı bir olayı tanımlamanın ve hemen ardından _Something_Stop adlı başka bir olayın bir çalışma biriminin başlangıç ve durdurması olarak kabul edildiği otomatik bir buluşsal çözüme sahiptir. Yeni bir iş birimi için başlangıç olayını günlüğe kaydetmek yeni bir Etkinlik Kimliği oluşturur ve durdurma olayı günlüğe kaydedilene kadar bu Etkinlik Kimliği ile aynı iş parçacığındaki tüm olayları günlüğe kaydetmeye başlar. Kimlik ayrıca ve awaitkullanılırken otomatik olarak zaman uyumsuz denetim akışını izlerasync. Başlat/Durdur adlandırma soneklerini kullanmanızı önersek de, özelliğini kullanarak EventAttribute.Opcode açıkça açıklama ekleyerek olayları istediğiniz şekilde adlandırabilirsiniz. İlk olayı olarak EventOpcode.Start , ikincisini olarak EventOpcode.Stopayarlayın.

Paralel çalışma yapacak günlük istekleri

Bazen tek bir istek çalışmasının farklı bölümlerini paralel olarak yapabilir ve tüm günlük olaylarını ve alt bölümleri gruplandırmak isteyebilirsiniz. Aşağıdaki örnek, iki veritabanı sorgusunu paralel olarak çalıştıran ve ardından her sorgunun sonucu üzerinde işlem gerçekleştirmeye yönelik bir isteğin benzetimini yapar. Her sorgunun çalışmasını yalıtmak, ancak aynı zamanda birçok eşzamanlı istek çalıştırılabilirken hangi sorguların aynı isteğe ait olduğunu anlamak istiyorsunuz. Bu, her üst düzey isteğin bir kök olduğu ve sonra işin alt dallarının dal olduğu bir ağaç olarak modellenir. Ağaçtaki her düğüm kendi Etkinlik Kimliğini alır ve yeni alt Etkinlik Kimliği ile günlüğe kaydedilen ilk olay, üst öğesini tanımlamak için İlgili Etkinlik Kimliği adlı ek bir alanı günlüğe kaydeder.

Aşağıdaki kodu çalıştırın:

C# 
using System.Diagnostics.Tracing;

public static class Program
{
    public static async Task Main(string[] args)
    {
        ConsoleWriterEventListener listener = new ConsoleWriterEventListener();

        await ProcessWorkItem("A");
    }

    private static async Task ProcessWorkItem(string requestName)
    {
        DemoEventSource.Log.WorkStart(requestName);
        Task query1 = Query("SELECT bowls");
        Task query2 = Query("SELECT spoons");
        await Task.WhenAll(query1, query2);
        DemoEventSource.Log.WorkStop();
    }

    private static async Task Query(string query)
    {
        DemoEventSource.Log.QueryStart(query);
        await Task.Delay(100); // pretend to send a query
        DemoEventSource.Log.DebugMessage("processing query");
        await Task.Delay(100); // pretend to do some work
        DemoEventSource.Log.QueryStop();
    }
}

[EventSource(Name = "Demo")]
class DemoEventSource : EventSource
{
    public static DemoEventSource Log = new DemoEventSource();

    [Event(1)]
    public void WorkStart(string requestName) => WriteEvent(1, requestName);
    [Event(2)]
    public void WorkStop() => WriteEvent(2);
    [Event(3)]
    public void DebugMessage(string message) => WriteEvent(3, message);
    [Event(4)]
    public void QueryStart(string query) => WriteEvent(4, query);
    [Event(5)]
    public void QueryStop() => WriteEvent(5);
}

class ConsoleWriterEventListener : EventListener
{
    protected override void OnEventSourceCreated(EventSource eventSource)
    {
        if (eventSource.Name == "Demo")
        {
            Console.WriteLine("{0,-5} {1,-40} {2,-40} {3,-15} {4}", "TID", "Activity ID", "Related Activity ID", "Event", "Arguments");
            EnableEvents(eventSource, EventLevel.Verbose);
        }
        else if (eventSource.Name == "System.Threading.Tasks.TplEventSource")
        {
            // Activity IDs aren't enabled by default.
            // Enabling Keyword 0x80 on the TplEventSource turns them on
            EnableEvents(eventSource, EventLevel.LogAlways, (EventKeywords)0x80);
        }
    }

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        lock (this)
        {
            Console.Write("{0,-5} {1,-40} {2, -40} {3,-15} ", eventData.OSThreadId, eventData.ActivityId, eventData.RelatedActivityId, eventData.EventName);
            if (eventData.Payload.Count == 1)
            {
                Console.WriteLine(eventData.Payload[0]);
            }
            else
            {
                Console.WriteLine();
            }
        }
    }
}

Bu örnek aşağıdaki gibi bir çıktı yazdırır:

txt 
TID   Activity ID                              Related Activity ID                      Event           Arguments
34276 00000011-0000-0000-0000-000086af9d59     00000000-0000-0000-0000-000000000000     WorkStart       A
34276 00001011-0000-0000-0000-0000869f9d59     00000011-0000-0000-0000-000086af9d59     QueryStart      SELECT bowls
34276 00002011-0000-0000-0000-0000868f9d59     00000011-0000-0000-0000-000086af9d59     QueryStart      SELECT spoons
32684 00002011-0000-0000-0000-0000868f9d59     00000000-0000-0000-0000-000000000000     DebugMessage    processing query
18624 00001011-0000-0000-0000-0000869f9d59     00000000-0000-0000-0000-000000000000     DebugMessage    processing query
18624 00002011-0000-0000-0000-0000868f9d59     00000000-0000-0000-0000-000000000000     QueryStop
32684 00001011-0000-0000-0000-0000869f9d59     00000000-0000-0000-0000-000000000000     QueryStop
32684 00000011-0000-0000-0000-000086af9d59     00000000-0000-0000-0000-000000000000     WorkStop

Bu örnekte yalnızca bir üst düzey istek çalıştırıldı ve bu istek Etkinlik Kimliği 00000011-...olarak atandı. Ardından her QueryStart olay, etkinlik kimlikleri 00001011-... ve 00002011-... sırasıyla isteğin yeni bir dalını başlattı. Bu kimliklerin özgün isteğin alt öğeleri olduğunu belirleyebilirsiniz çünkü başlangıç olaylarının her ikisi de üst 00000011-... öğelerini İlgili Etkinlik Kimliği alanına kaydetmiş olur.

Not

Kimliklerin sayısal değerlerinin üst ve alt öğe arasında bazı net desenler olduğunu ve rastgele olmadığını fark etmiş olabilirsiniz. Basit durumlarda ilişkiyi görsel olarak saptamaya yardımcı olsa da, araçların buna güvenmemesi ve kimlikleri opak tanımlayıcılar olarak ele almaması en iyisidir. İç içe yerleştirme düzeyi daha derine indikçe bayt düzeni değişir. İç içe yerleştirme düzeyinden bağımsız olarak araçların güvenilir bir şekilde çalışmasını sağlamanın en iyi yolu İlgili Etkinlik Kimliği alanını kullanmaktır.

Alt çalışma öğelerinin karmaşık ağaçlarını içeren istekler birçok farklı Etkinlik Kimlikleri oluşturacağından, bu kimlikler genellikle ağacı el ile yeniden oluşturmaya çalışmak yerine araçlar tarafından ayrıştırılır. PerfView , bu kimliklerle açıklama ekleyen olayların nasıl ilişkilendirildiğini bilen bir araçtır.