Catatan
Akses ke halaman ini memerlukan otorisasi. Anda dapat mencoba masuk atau mengubah direktori.
Akses ke halaman ini memerlukan otorisasi. Anda dapat mencoba mengubah direktori.
Artikel ini berlaku untuk: ✔️ .NET Core 3.1 dan versi yang lebih baru ✔️ .NET Framework 4.5 dan versi yang lebih baru
Panduan ini menjelaskan ID Aktivitas, pengidentifikasi opsional yang dapat dicatat dengan setiap peristiwa yang dihasilkan menggunakan System.Diagnostics.Tracing.EventSource. Untuk pengenalan, lihat Memulai EventSource.
Tantangan pencatatan pekerjaan bersamaan
Dahulu kala, aplikasi khas mungkin sederhana dan berulir tunggal, yang membuat pengelogan mudah. Anda dapat menulis setiap langkah ke file log secara berurutan dan kemudian membaca log kembali persis dalam urutan ditulis untuk memahami apa yang terjadi. Jika aplikasi menangani permintaan, hanya satu permintaan yang ditangani pada satu waktu. Semua pesan log untuk permintaan A akan dicetak secara berurutan, lalu semua pesan untuk B, dan sebagainya. Saat aplikasi menjadi multi-utas, strategi tersebut tidak lagi berfungsi karena beberapa permintaan ditangani secara bersamaan. Namun jika setiap permintaan ditetapkan ke satu utas yang memprosesnya sepenuhnya, Anda dapat menyelesaikan masalah dengan merekam ID utas untuk setiap pesan log. Misalnya, aplikasi multi-utas mungkin mencatat:
Thread Id Message
--------- -------
12 BeginRequest A
12 Doing some work
190 BeginRequest B
12 uh-oh error happened
190 Doing some work
Dengan membaca ID utas, Anda tahu bahwa utas 12 memproses permintaan A dan utas 190 memproses permintaan B, oleh karena itu pesan 'kesalahanuh-oh terjadi' terkait permintaan A. Namun konkurensi aplikasi terus tumbuh semakin canggih. Sekarang umum digunakan async dan await sehingga satu permintaan dapat ditangani sebagian pada banyak utas yang berbeda sebelum pekerjaan selesai. ID utas tidak lagi cukup untuk menghubungkan semua pesan yang dihasilkan untuk satu permintaan. ID aktivitas menyelesaikan masalah ini. Mereka menyediakan pengidentifikasi granuler yang lebih canggih yang dapat melacak permintaan individual, atau bagian permintaan, terlepas dari apakah pekerjaan tersebut tersebar di berbagai utas.
Nota
Konsep ID Aktivitas yang disebut di sini tidak sama dengan System.Diagnostics.Tracing.Activity, meskipun penamaan serupa.
Melacak pekerjaan menggunakan ID Aktivitas
Anda dapat menjalankan kode di bawah ini untuk melihat Pelacakan aktivitas secara langsung.
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();
}
}
}
}
Saat dijalankan, kode ini mencetak output:
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
Nota
Ada masalah yang diketahui di mana debugger Visual Studio dapat menyebabkan ID Aktivitas yang tidak valid dibuat. Jangan jalankan sampel ini dalam debugger atau atur titik henti di awal Main dan evaluasi ekspresi 'System.Threading.Tasks.TplEventSource.Log.TasksSetActivityIds = false' di jendela langsung sebelum melanjutkan untuk mengatasi masalah tersebut.
Menggunakan ID Aktivitas, Anda dapat melihat bahwa semua pesan untuk item kerja A memiliki ID 00000011-... dan semua pesan untuk item kerja B memiliki ID 00000012-.... Kedua item kerja awalnya menjalankan beberapa tugas pada utas 21256, tetapi kemudian masing-masing melanjutkan tugas mereka pada utas threadpool yang terpisah, yaitu 11348 dan 14728, sehingga mencoba melacak permintaan hanya dengan ID utas tidak akan berhasil.
EventSource memiliki heuristik otomatis di mana menentukan peristiwa bernama _Something_Start diikuti segera oleh peristiwa lain bernama _Something_Stop dianggap sebagai awal dan penghentian unit kerja. Mencatat peristiwa awal untuk unit kerja baru membuat ID Aktivitas baru dan mencatat semua peristiwa pada utas yang sama dengan ID Aktivitas tersebut hingga peristiwa berhenti dicatat. ID juga secara otomatis mengikuti alur kontrol asinkron saat menggunakan async dan await. Meskipun kami menyarankan agar Anda menggunakan akhiran penamaan Start/Stop, Anda dapat memberi nama peristiwa apa pun yang Anda suka dengan secara eksplisit menganotasinya menggunakan EventAttribute.Opcode properti . Atur peristiwa pertama ke EventOpcode.Start dan yang kedua ke EventOpcode.Stop.
Permintaan log yang melakukan pekerjaan paralel
Terkadang satu permintaan mungkin melakukan berbagai bagian pekerjaannya secara paralel, dan Anda ingin mengelompokkan semua log peristiwa dan subbagian. Contoh di bawah ini mensimulasikan permintaan yang melakukan dua kueri database secara paralel lalu melakukan beberapa pemrosesan pada hasil setiap kueri. Anda ingin mengisolasi pekerjaan untuk setiap kueri, tetapi juga memahami kueri mana yang termasuk dalam permintaan yang sama ketika banyak permintaan bersamaan dapat berjalan. Ini dimodelkan sebagai pohon di mana setiap permintaan tingkat atas adalah akar dan kemudian subporsi pekerjaan adalah cabang. Setiap simpul di pohon mendapatkan ID Aktivitasnya sendiri, dan log pertama yang dicatat menggunakan ID Aktivitas anak yang baru mencatat bidang tambahan yang disebut ID Aktivitas Terkait untuk menunjukkan induknya.
Jalankan kode berikut:
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();
}
}
}
}
Contoh ini mencetak output seperti:
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
Contoh ini hanya menjalankan satu permintaan tingkat atas, yang diberi ID Aktivitas 00000011-.... Kemudian, setiap kejadian QueryStart dimulai cabang baru permintaan dengan ID Aktivitas masing-masing 00001011-... dan 00002011-.... Anda dapat mengidentifikasi ID ini sebagai turunan dari permintaan asli karena kedua peristiwa awal mencatat induk mereka di bidang ID Aktivitas Terkait.
Nota
Anda mungkin telah memperhatikan nilai numerik ID memiliki beberapa pola yang jelas antara induk dan anak dan tidak acak. Meskipun dapat membantu dalam melihat hubungan secara visual dalam kasus sederhana, sebaiknya alat tidak mengandalkan ini dan memperlakukan ID sebagai pengidentifikasi buram. Ketika tingkat bersarang tumbuh lebih dalam, pola byte akan berubah. Menggunakan bidang ID Aktivitas Terkait adalah cara terbaik untuk memastikan alat berfungsi dengan andal terlepas dari tingkat berlapis.
Sebab permintaan dengan pohon kompleks sub-item pekerjaan akan menghasilkan banyak ID Aktivitas yang berbeda, ID ini biasanya lebih baik diurai oleh alat daripada mencoba membangun kembali pohon tersebut secara manual. PerfView adalah salah satu alat yang tahu cara menghubungkan peristiwa yang dianotasi dengan ID ini.
Berkolaborasi dengan kami di GitHub
Sumber untuk konten ini dapat ditemukan di GitHub, yang juga dapat Anda gunakan untuk membuat dan meninjau masalah dan menarik permintaan. Untuk informasi selengkapnya, lihat panduan kontributor kami.
